lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache Jenkins Server <jenk...@builds.apache.org>
Subject [JENKINS] Lucene-Solr-NightlyTests-4.x - Build # 38 - Still Failing
Date Tue, 18 Sep 2012 18:29:26 GMT
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-4.x/38/

2 tests failed.
FAILED:  org.apache.solr.cloud.SyncSliceTest.testDistribSearch

Error Message:
There are still nodes recoverying

Stack Trace:
java.lang.AssertionError: There are still nodes recoverying
	at __randomizedtesting.SeedInfo.seed([9266E8D41AC43129:138066CC6D9B5115]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:154)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.waitForRecoveriesToFinish(AbstractFullDistribZkTestBase.java:560)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.waitForThingsToLevelOut(AbstractFullDistribZkTestBase.java:1135)
	at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:162)
	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:616)
	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:679)


FAILED:  org.apache.solr.cloud.BasicDistributedZk2Test.testDistribSearch

Error Message:
Shard still reported as live in zk

Stack Trace:
java.lang.AssertionError: Shard still reported as live in zk
	at __randomizedtesting.SeedInfo.seed([9266E8D41AC43129:138066CC6D9B5115]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.waitToSeeNotLive(AbstractFullDistribZkTestBase.java:1220)
	at org.apache.solr.cloud.BasicDistributedZk2Test.brindDownShardIndexSomeDocsAndRecover(BasicDistributedZk2Test.java:190)
	at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:83)
	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:616)
	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:679)




Build Log:
[...truncated 7423 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4:junit4]   2> 3 T1390 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1347991809383
[junit4:junit4]   2> 4 T1390 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 6 T1391 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4]   2> 6 T1391 oazs.NIOServerCnxn$Factory.<init> binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 7 T1391 oazsp.FileTxnSnapLog.save Snapshotting: 0
[junit4:junit4]   2> 105 T1390 oasc.ZkTestServer.run start zk server on port:20077
[junit4:junit4]   2> 105 T1390 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:20077 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@3527d2cb
[junit4:junit4]   2> 106 T1396 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:20077
[junit4:junit4]   2> 106 T1390 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 106 T1396 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:20077, initiating session
[junit4:junit4]   2> 107 T1392 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:20078
[junit4:junit4]   2> 107 T1392 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:20078
[junit4:junit4]   2> 107 T1394 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 112 T1394 oazs.NIOServerCnxn.finishSessionInit Established session 0x139da92ad6c0000 with negotiated timeout 10000 for client /140.211.11.196:20078
[junit4:junit4]   2> 112 T1396 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:20077, sessionid = 0x139da92ad6c0000, negotiated timeout = 10000
[junit4:junit4]   2> 112 T1397 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3527d2cb name:ZooKeeperConnection Watcher:127.0.0.1:20077 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 112 T1390 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 112 T1390 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 123 T1395 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x139da92ad6c0000
[junit4:junit4]   2> 124 T1397 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 124 T1390 oaz.ZooKeeper.close Session: 0x139da92ad6c0000 closed
[junit4:junit4]   2> 124 T1392 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:20078 which had sessionid 0x139da92ad6c0000
[junit4:junit4]   2> 124 T1390 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:20077/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@618693d1
[junit4:junit4]   2> 125 T1398 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:20077
[junit4:junit4]   2> 125 T1390 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 125 T1398 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:20077, initiating session
[junit4:junit4]   2> 125 T1392 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:20079
[junit4:junit4]   2> 125 T1392 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:20079
[junit4:junit4]   2> 127 T1394 oazs.NIOServerCnxn.finishSessionInit Established session 0x139da92ad6c0001 with negotiated timeout 10000 for client /140.211.11.196:20079
[junit4:junit4]   2> 127 T1398 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:20077, sessionid = 0x139da92ad6c0001, negotiated timeout = 10000
[junit4:junit4]   2> 127 T1399 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@618693d1 name:ZooKeeperConnection Watcher:127.0.0.1:20077/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 127 T1390 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 127 T1390 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 135 T1390 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 137 T1390 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 145 T1390 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 148 T1390 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 148 T1390 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 160 T1390 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4]   2> 161 T1390 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 264 T1390 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 264 T1390 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 267 T1390 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4]   2> 267 T1390 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 280 T1390 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4]   2> 280 T1390 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 282 T1390 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4]   2> 282 T1390 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 284 T1390 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 285 T1390 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 292 T1390 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 292 T1390 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 294 T1390 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 295 T1390 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 297 T1390 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4]   2> 297 T1390 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 304 T1395 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x139da92ad6c0001
[junit4:junit4]   2> 305 T1399 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 305 T1390 oaz.ZooKeeper.close Session: 0x139da92ad6c0001 closed
[junit4:junit4]   2> 305 T1392 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:20079 which had sessionid 0x139da92ad6c0001
[junit4:junit4]   2> 306 T1390 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 314 T1390 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:?????
[junit4:junit4]   2> 315 T1390 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 315 T1390 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 315 T1390 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 347 T1390 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 375 T1390 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 375 T1390 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 375 T1390 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/solr.xml
[junit4:junit4]   2> 376 T1390 oasc.CoreContainer.<init> New CoreContainer 1504808685
[junit4:junit4]   2> 376 T1390 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 376 T1390 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 394 T1390 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 404 T1390 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:20077/solr
[junit4:junit4]   2> 404 T1390 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:20077/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@22ba4310
[junit4:junit4]   2> 405 T1409 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:20077
[junit4:junit4]   2> 405 T1390 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 406 T1409 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:20077, initiating session
[junit4:junit4]   2> 406 T1392 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:20081
[junit4:junit4]   2> 407 T1392 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:20081
[junit4:junit4]   2> 408 T1394 oazs.NIOServerCnxn.finishSessionInit Established session 0x139da92ad6c0002 with negotiated timeout 5000 for client /140.211.11.196:20081
[junit4:junit4]   2> 408 T1409 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:20077, sessionid = 0x139da92ad6c0002, negotiated timeout = 5000
[junit4:junit4]   2> 408 T1410 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@22ba4310 name:ZooKeeperConnection Watcher:127.0.0.1:20077/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 408 T1390 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 410 T1395 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139da92ad6c0002 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 418 T1390 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 419 T1390 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:20080_solr
[junit4:junit4]   2> 420 T1395 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139da92ad6c0002 type:delete cxid:0x7 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:20080_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:20080_solr
[junit4:junit4]   2> 426 T1390 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:20080_solr
[junit4:junit4]   2> 428 T1390 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 428 T1390 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 428 T1390 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 428 T1390 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 429 T1390 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 429 T1390 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 429 T1390 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 430 T1390 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 430 T1390 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 430 T1390 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 439 T1390 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 444 T1395 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139da92ad6c0002 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> 455 T1390 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 457 T1390 oasc.Overseer.start Overseer (id=88341991220051970-127.0.0.1:20080_solr-n_0000000000) starting
[junit4:junit4]   2> 457 T1395 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139da92ad6c0002 type:create cxid:0x1a zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 458 T1395 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139da92ad6c0002 type:create cxid:0x1b zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 460 T1395 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139da92ad6c0002 type:create cxid:0x1c zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 468 T1395 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139da92ad6c0002 type:create cxid:0x1d zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 469 T1412 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 469 T1390 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 472 T1390 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 473 T1411 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 476 T1390 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1
[junit4:junit4]   2> 476 T1390 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 476 T1390 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 477 T1390 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 478 T1390 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4]   2> 478 T1390 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 479 T1390 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4]   2> 512 T1390 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_40
[junit4:junit4]   2> 558 T1390 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 659 T1390 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 663 T1390 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 1069 T1390 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 1077 T1390 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 1080 T1390 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 1088 T1390 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1092 T1390 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1095 T1390 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1096 T1390 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1097 T1390 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/control/data/
[junit4:junit4]   2> 1098 T1390 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2180b22e
[junit4:junit4]   2> 1120 T1390 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/control/data/index/
[junit4:junit4]   2> 1121 T1390 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/control/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 1121 T1390 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/control/data/index forceNew:false
[junit4:junit4]   2> 1153 T1390 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/control/data/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 1154 T1390 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 1156 T1390 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 1159 T1390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 1159 T1390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 1160 T1390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 1161 T1390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 1162 T1390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 1163 T1390 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 1163 T1390 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 1165 T1390 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 1165 T1390 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 1166 T1390 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 1167 T1390 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 1168 T1390 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 1169 T1390 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 1169 T1390 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 1170 T1390 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 1171 T1390 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 1172 T1390 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1173 T1390 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1174 T1390 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1174 T1390 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1175 T1390 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1176 T1390 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1177 T1390 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1177 T1390 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 1178 T1390 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 1182 T1390 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 1187 T1390 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 1188 T1390 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> 1192 T1390 oass.SolrIndexSearcher.<init> Opening Searcher@595188bf main
[junit4:junit4]   2> 1193 T1390 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 1194 T1390 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 1194 T1390 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 1202 T1390 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 1259 T1413 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@595188bf main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 1265 T1395 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139da92ad6c0002 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> 1276 T1390 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 1277 T1390 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:20080/solr shardId:control_shard
[junit4:junit4]   2> 1278 T1390 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/control_shard/election
[junit4:junit4]   2> 1291 T1395 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139da92ad6c0002 type:delete cxid:0x62 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/collections/control_collection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/control_collection/leaders
[junit4:junit4]   2> 1292 T1390 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 1292 T1395 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139da92ad6c0002 type:create cxid:0x63 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 1481 T1411 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 1482 T1395 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139da92ad6c0002 type:create cxid:0x6a zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer/queue-work Error:KeeperErrorCode = NoNode for /solr/overseer/queue-work
[junit4:junit4]   2> 1497 T1410 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 1803 T1390 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 1804 T1390 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 1804 T1390 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:20080/solr/collection1/
[junit4:junit4]   2> 1805 T1390 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 1805 T1390 oasc.SyncStrategy.syncToMe http://127.0.0.1:20080/solr/collection1/ has no replicas
[junit4:junit4]   2> 1805 T1390 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:20080/solr/collection1/
[junit4:junit4]   2> 1806 T1390 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/control_shard
[junit4:junit4]   2> 1822 T1395 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139da92ad6c0002 type:create cxid:0x88 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2010 T1411 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2022 T1410 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 2033 T1390 oasc.ZkController.register We are http://127.0.0.1:20080/solr/collection1/ and leader is http://127.0.0.1:20080/solr/collection1/
[junit4:junit4]   2> 2033 T1390 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:20080/solr
[junit4:junit4]   2> 2034 T1390 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 2035 T1390 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2036 T1390 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1
[junit4:junit4]   2> 2037 T1390 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 2037 T1390 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 2196 T1390 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 2199 T1390 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:?????
[junit4:junit4]   2> 2200 T1390 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 2201 T1390 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty1-1347991811431
[junit4:junit4]   2> 2201 T1390 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty1-1347991811431/'
[junit4:junit4]   2> 2235 T1390 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 2236 T1390 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 2236 T1390 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty1-1347991811431
[junit4:junit4]   2> 2237 T1390 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty1-1347991811431/solr.xml
[junit4:junit4]   2> 2237 T1390 oasc.CoreContainer.<init> New CoreContainer 1582326970
[junit4:junit4]   2> 2238 T1390 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty1-1347991811431/'
[junit4:junit4]   2> 2238 T1390 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty1-1347991811431/'
[junit4:junit4]   2> 2262 T1390 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 2276 T1390 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:20077/solr
[junit4:junit4]   2> 2277 T1390 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:20077/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@6064dd87
[junit4:junit4]   2> 2278 T1423 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:20077
[junit4:junit4]   2> 2278 T1390 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 2279 T1423 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:20077, initiating session
[junit4:junit4]   2> 2279 T1392 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:20084
[junit4:junit4]   2> 2279 T1392 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:20084
[junit4:junit4]   2> 2281 T1394 oazs.NIOServerCnxn.finishSessionInit Established session 0x139da92ad6c0003 with negotiated timeout 5000 for client /140.211.11.196:20084
[junit4:junit4]   2> 2282 T1423 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:20077, sessionid = 0x139da92ad6c0003, negotiated timeout = 5000
[junit4:junit4]   2> 2282 T1424 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6064dd87 name:ZooKeeperConnection Watcher:127.0.0.1:20077/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 2282 T1390 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 2283 T1395 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139da92ad6c0003 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2284 T1395 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139da92ad6c0003 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2286 T1390 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:20083_solr
[junit4:junit4]   2> 2286 T1395 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139da92ad6c0003 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:20083_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:20083_solr
[junit4:junit4]   2> 2301 T1390 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:20083_solr
[junit4:junit4]   2> 2303 T1410 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 2303 T1390 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 2304 T1390 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 2304 T1390 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 2304 T1390 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 2304 T1390 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 2305 T1390 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 2305 T1390 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 2305 T1390 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 2306 T1390 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 2306 T1390 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 2317 T1390 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 2322 T1390 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty1-1347991811431/collection1
[junit4:junit4]   2> 2322 T1390 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 2322 T1390 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 2323 T1390 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 2323 T1390 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty1-1347991811431/collection1/'
[junit4:junit4]   2> 2324 T1390 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solrtest-jetty1-1347991811431/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 2325 T1390 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solrtest-jetty1-1347991811431/collection1/lib/README' to classloader
[junit4:junit4]   2> 2361 T1390 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_40
[junit4:junit4]   2> 2407 T1390 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 2508 T1390 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 2512 T1390 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 2526 T1411 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2531 T1424 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 2531 T1410 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 2960 T1390 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 2972 T1390 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 2977 T1390 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 2987 T1390 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 2992 T1390 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 2996 T1390 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 2997 T1390 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 2998 T1390 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty1-1347991811431/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty1/
[junit4:junit4]   2> 2999 T1390 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2180b22e
[junit4:junit4]   2> 3000 T1390 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty1/index/
[junit4:junit4]   2> 3001 T1390 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 3002 T1390 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty1/index forceNew:false
[junit4:junit4]   2> 3008 T1390 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty1/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 3009 T1390 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 3009 T1390 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 3012 T1390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 3012 T1390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 3013 T1390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 3013 T1390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 3014 T1390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 3015 T1390 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 3015 T1390 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 3016 T1390 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 3017 T1390 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 3018 T1390 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 3018 T1390 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 3019 T1390 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 3020 T1390 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 3020 T1390 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 3021 T1390 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 3021 T1390 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 3022 T1390 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3023 T1390 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3023 T1390 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3024 T1390 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3025 T1390 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3026 T1390 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3026 T1390 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3027 T1390 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 3028 T1390 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 3031 T1390 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 3036 T1390 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 3037 T1390 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> 3041 T1390 oass.SolrIndexSearcher.<init> Opening Searcher@36662d65 main
[junit4:junit4]   2> 3043 T1390 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 3043 T1390 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 3044 T1390 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 3052 T1390 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 3105 T1425 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@36662d65 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 3544 T1411 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3564 T1410 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 3564 T1424 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 3613 T1390 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 3613 T1390 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:20083/solr shardId:shard1
[junit4:junit4]   2> 3614 T1390 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 3630 T1395 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139da92ad6c0003 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> 3631 T1390 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 3631 T1395 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139da92ad6c0003 type:create cxid:0x44 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3633 T1390 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 3633 T1390 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 3634 T1390 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:20083/solr/collection1/
[junit4:junit4]   2> 3634 T1390 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 3634 T1390 oasc.SyncStrategy.syncToMe http://127.0.0.1:20083/solr/collection1/ has no replicas
[junit4:junit4]   2> 3635 T1390 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:20083/solr/collection1/
[junit4:junit4]   2> 3635 T1390 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 3638 T1395 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139da92ad6c0003 type:create cxid:0x4e zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4067 T1411 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4086 T1410 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4086 T1424 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4098 T1390 oasc.ZkController.register We are http://127.0.0.1:20083/solr/collection1/ and leader is http://127.0.0.1:20083/solr/collection1/
[junit4:junit4]   2> 4098 T1390 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:20083/solr
[junit4:junit4]   2> 4099 T1390 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 4100 T1390 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4101 T1390 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1
[junit4:junit4]   2> 4101 T1390 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 4102 T1390 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 4263 T1390 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 4266 T1390 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:?????
[junit4:junit4]   2> 4267 T1390 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 4267 T1390 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty2-1347991813496
[junit4:junit4]   2> 4268 T1390 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty2-1347991813496/'
[junit4:junit4]   2> 4303 T1390 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 4303 T1390 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 4304 T1390 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty2-1347991813496
[junit4:junit4]   2> 4304 T1390 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty2-1347991813496/solr.xml
[junit4:junit4]   2> 4304 T1390 oasc.CoreContainer.<init> New CoreContainer 1774977004
[junit4:junit4]   2> 4305 T1390 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty2-1347991813496/'
[junit4:junit4]   2> 4305 T1390 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty2-1347991813496/'
[junit4:junit4]   2> 4330 T1390 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 4345 T1390 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:20077/solr
[junit4:junit4]   2> 4345 T1390 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:20077/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@e39f6f1
[junit4:junit4]   2> 4346 T1435 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:20077
[junit4:junit4]   2> 4346 T1390 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 4347 T1435 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:20077, initiating session
[junit4:junit4]   2> 4347 T1392 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:20087
[junit4:junit4]   2> 4348 T1392 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:20087
[junit4:junit4]   2> 4350 T1394 oazs.NIOServerCnxn.finishSessionInit Established session 0x139da92ad6c0004 with negotiated timeout 5000 for client /140.211.11.196:20087
[junit4:junit4]   2> 4350 T1435 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:20077, sessionid = 0x139da92ad6c0004, negotiated timeout = 5000
[junit4:junit4]   2> 4350 T1436 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e39f6f1 name:ZooKeeperConnection Watcher:127.0.0.1:20077/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 4350 T1390 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 4351 T1395 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139da92ad6c0004 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4352 T1395 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139da92ad6c0004 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4365 T1390 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:20086_solr
[junit4:junit4]   2> 4366 T1395 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139da92ad6c0004 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:20086_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:20086_solr
[junit4:junit4]   2> 4367 T1390 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:20086_solr
[junit4:junit4]   2> 4369 T1424 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 4369 T1410 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 4369 T1390 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 4370 T1390 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 4370 T1390 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 4370 T1390 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 4371 T1390 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 4371 T1390 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 4372 T1390 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 4372 T1390 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 4373 T1390 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 4373 T1390 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 4389 T1390 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 4395 T1390 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty2-1347991813496/collection1
[junit4:junit4]   2> 4395 T1390 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 4396 T1390 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 4396 T1390 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 4398 T1390 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty2-1347991813496/collection1/'
[junit4:junit4]   2> 4399 T1390 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solrtest-jetty2-1347991813496/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 4400 T1390 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solrtest-jetty2-1347991813496/collection1/lib/README' to classloader
[junit4:junit4]   2> 4447 T1390 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_40
[junit4:junit4]   2> 4515 T1390 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 4590 T1411 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4602 T1410 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4602 T1424 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4616 T1436 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4616 T1390 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 4626 T1390 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 5103 T1390 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 5111 T1390 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 5113 T1390 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 5122 T1390 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 5126 T1390 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 5129 T1390 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 5130 T1390 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 5131 T1390 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty2-1347991813496/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty2/
[junit4:junit4]   2> 5131 T1390 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2180b22e
[junit4:junit4]   2> 5132 T1390 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty2/index/
[junit4:junit4]   2> 5132 T1390 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 5133 T1390 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty2/index forceNew:false
[junit4:junit4]   2> 5138 T1390 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty2/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 5138 T1390 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 5139 T1390 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 5141 T1390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 5141 T1390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 5141 T1390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 5142 T1390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 5142 T1390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 5142 T1390 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 5143 T1390 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 5143 T1390 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 5144 T1390 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 5144 T1390 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 5145 T1390 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 5145 T1390 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 5146 T1390 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 5146 T1390 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 5146 T1390 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 5147 T1390 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 5147 T1390 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5148 T1390 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5148 T1390 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5149 T1390 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5149 T1390 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5150 T1390 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5150 T1390 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5151 T1390 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 5151 T1390 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 5154 T1390 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 5160 T1390 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 5161 T1390 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> 5164 T1390 oass.SolrIndexSearcher.<init> Opening Searcher@446d853d main
[junit4:junit4]   2> 5165 T1390 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 5165 T1390 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 5165 T1390 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 5171 T1390 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 5220 T1437 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@446d853d main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 5608 T1411 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 5621 T1410 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5621 T1436 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5621 T1424 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5725 T1390 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 5725 T1390 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:20086/solr shardId:shard2
[junit4:junit4]   2> 5726 T1390 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4]   2> 5741 T1395 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139da92ad6c0004 type:delete cxid:0x42 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/collections/collection1/leaders/shard2 Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders/shard2
[junit4:junit4]   2> 5741 T1390 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 5742 T1395 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139da92ad6c0004 type:create cxid:0x43 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 5743 T1390 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 5743 T1390 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 5744 T1390 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:20086/solr/collection1/
[junit4:junit4]   2> 5744 T1390 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 5744 T1390 oasc.SyncStrategy.syncToMe http://127.0.0.1:20086/solr/collection1/ has no replicas
[junit4:junit4]   2> 5745 T1390 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:20086/solr/collection1/
[junit4:junit4]   2> 5745 T1390 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4]   2> 5747 T1395 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139da92ad6c0004 type:create cxid:0x4c zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 6124 T1411 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6139 T1410 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6139 T1436 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6139 T1424 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6156 T1390 oasc.ZkController.register We are http://127.0.0.1:20086/solr/collection1/ and leader is http://127.0.0.1:20086/solr/collection1/
[junit4:junit4]   2> 6156 T1390 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:20086/solr
[junit4:junit4]   2> 6156 T1390 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 6158 T1390 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6158 T1390 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1
[junit4:junit4]   2> 6159 T1390 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 6159 T1390 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 6268 T1390 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 6271 T1390 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:?????
[junit4:junit4]   2> 6271 T1390 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 6271 T1390 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty3-1347991815549
[junit4:junit4]   2> 6272 T1390 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty3-1347991815549/'
[junit4:junit4]   2> 6295 T1390 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 6295 T1390 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 6295 T1390 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty3-1347991815549
[junit4:junit4]   2> 6296 T1390 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty3-1347991815549/solr.xml
[junit4:junit4]   2> 6296 T1390 oasc.CoreContainer.<init> New CoreContainer 885625531
[junit4:junit4]   2> 6296 T1390 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty3-1347991815549/'
[junit4:junit4]   2> 6297 T1390 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty3-1347991815549/'
[junit4:junit4]   2> 6313 T1390 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 6323 T1390 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:20077/solr
[junit4:junit4]   2> 6324 T1390 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:20077/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@3c450bb2
[junit4:junit4]   2> 6324 T1447 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:20077
[junit4:junit4]   2> 6324 T1390 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 6326 T1447 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:20077, initiating session
[junit4:junit4]   2> 6326 T1392 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:20091
[junit4:junit4]   2> 6326 T1392 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:20091
[junit4:junit4]   2> 6328 T1394 oazs.NIOServerCnxn.finishSessionInit Established session 0x139da92ad6c0005 with negotiated timeout 5000 for client /140.211.11.196:20091
[junit4:junit4]   2> 6328 T1447 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:20077, sessionid = 0x139da92ad6c0005, negotiated timeout = 5000
[junit4:junit4]   2> 6328 T1448 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3c450bb2 name:ZooKeeperConnection Watcher:127.0.0.1:20077/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 6328 T1390 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 6329 T1395 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139da92ad6c0005 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 6343 T1395 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139da92ad6c0005 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 6344 T1390 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:20090_solr
[junit4:junit4]   2> 6344 T1395 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139da92ad6c0005 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:20090_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:20090_solr
[junit4:junit4]   2> 6345 T1390 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:20090_solr
[junit4:junit4]   2> 6347 T1410 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 6347 T1424 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 6347 T1436 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 6348 T1390 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 6348 T1390 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 6348 T1390 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 6348 T1390 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 6349 T1390 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 6349 T1390 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 6349 T1390 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 6349 T1390 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 6350 T1390 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 6350 T1390 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 6363 T1390 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 6367 T1390 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty3-1347991815549/collection1
[junit4:junit4]   2> 6367 T1390 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 6368 T1390 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 6368 T1390 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 6369 T1390 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty3-1347991815549/collection1/'
[junit4:junit4]   2> 6370 T1390 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solrtest-jetty3-1347991815549/collection1/lib/README' to classloader
[junit4:junit4]   2> 6370 T1390 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solrtest-jetty3-1347991815549/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 6403 T1390 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_40
[junit4:junit4]   2> 6449 T1390 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 6550 T1390 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 6554 T1390 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 6652 T1411 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6666 T1410 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6666 T1448 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6666 T1436 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6666 T1424 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6964 T1390 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 6972 T1390 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 6975 T1390 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 6984 T1390 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 6988 T1390 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 6991 T1390 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 6992 T1390 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 6993 T1390 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty3-1347991815549/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty3/
[junit4:junit4]   2> 6993 T1390 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2180b22e
[junit4:junit4]   2> 6994 T1390 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty3/index/
[junit4:junit4]   2> 6994 T1390 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 6995 T1390 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty3/index forceNew:false
[junit4:junit4]   2> 7000 T1390 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty3/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 7000 T1390 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 7001 T1390 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 7002 T1390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 7003 T1390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 7003 T1390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 7003 T1390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 7004 T1390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 7004 T1390 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 7004 T1390 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 7005 T1390 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 7005 T1390 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 7006 T1390 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 7006 T1390 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 7007 T1390 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 7007 T1390 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 7008 T1390 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 7008 T1390 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 7008 T1390 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 7009 T1390 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7009 T1390 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7010 T1390 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7010 T1390 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7011 T1390 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7011 T1390 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7012 T1390 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7012 T1390 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 7013 T1390 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 7015 T1390 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 7018 T1390 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 7019 T1390 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> 7022 T1390 oass.SolrIndexSearcher.<init> Opening Searcher@60c07608 main
[junit4:junit4]   2> 7023 T1390 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 7023 T1390 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 7024 T1390 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 7029 T1390 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 7081 T1449 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@60c07608 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 7169 T1411 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7179 T1424 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7179 T1448 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7179 T1410 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7179 T1436 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7586 T1390 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 7586 T1390 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:20090/solr shardId:shard1
[junit4:junit4]   2> 7589 T1390 oasc.ZkController.register We are http://127.0.0.1:20090/solr/collection1/ and leader is http://127.0.0.1:20083/solr/collection1/
[junit4:junit4]   2> 7589 T1390 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:20090/solr
[junit4:junit4]   2> 7589 T1390 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 7590 T1390 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C145 name=collection1 org.apache.solr.core.SolrCore@6fecda63 url=http://127.0.0.1:20090/solr/collection1 node=127.0.0.1:20090_solr
[junit4:junit4]   2> 7591 T1450 C145 P20090 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 7591 T1390 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7591 T1450 C145 P20090 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 7592 T1390 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1
[junit4:junit4]   2> 7592 T1390 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 7592 T1390 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 7604 T1450 C145 P20090 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:20083/solr/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 7604 T1450 C145 P20090 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:20090/solr START replicas=[http://127.0.0.1:20083/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 7605 T1450 C145 P20090 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 7607 T1450 C145 P20090 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 7607 T1450 C145 P20090 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 7607 T1450 C145 P20090 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C146 name=collection1 org.apache.solr.core.SolrCore@3bcf72c7 url=http://127.0.0.1:20083/solr/collection1 node=127.0.0.1:20083_solr
[junit4:junit4]   2> 7617 T1416 C146 P20083 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=1 
[junit4:junit4]   2> 7682 T1411 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7695 T1410 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7695 T1424 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7695 T1448 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7695 T1436 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7744 T1390 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 7747 T1390 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:?????
[junit4:junit4]   2> 7747 T1390 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 7748 T1390 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty4-1347991816981
[junit4:junit4]   2> 7748 T1390 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty4-1347991816981/'
[junit4:junit4]   2> 7783 T1390 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 7783 T1390 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 7784 T1390 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty4-1347991816981
[junit4:junit4]   2> 7784 T1390 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty4-1347991816981/solr.xml
[junit4:junit4]   2> 7784 T1390 oasc.CoreContainer.<init> New CoreContainer 943509870
[junit4:junit4]   2> 7785 T1390 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty4-1347991816981/'
[junit4:junit4]   2> 7785 T1390 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty4-1347991816981/'
[junit4:junit4]   2> 7810 T1390 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 7825 T1390 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:20077/solr
[junit4:junit4]   2> 7826 T1390 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:20077/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@320dce4f
[junit4:junit4]   2> 7827 T1461 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:20077
[junit4:junit4]   2> 7827 T1390 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 7828 T1461 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:20077, initiating session
[junit4:junit4]   2> 7828 T1392 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:20095
[junit4:junit4]   2> 7828 T1392 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:20095
[junit4:junit4]   2> 7830 T1394 oazs.NIOServerCnxn.finishSessionInit Established session 0x139da92ad6c0006 with negotiated timeout 5000 for client /140.211.11.196:20095
[junit4:junit4]   2> 7830 T1461 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:20077, sessionid = 0x139da92ad6c0006, negotiated timeout = 5000
[junit4:junit4]   2> 7830 T1462 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@320dce4f name:ZooKeeperConnection Watcher:127.0.0.1:20077/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 7830 T1390 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 7831 T1395 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139da92ad6c0006 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7832 T1395 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139da92ad6c0006 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7834 T1390 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:20094_solr
[junit4:junit4]   2> 7835 T1395 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139da92ad6c0006 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:20094_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:20094_solr
[junit4:junit4]   2> 7842 T1390 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:20094_solr
[junit4:junit4]   2> 7844 T1410 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 7844 T1448 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 7844 T1436 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 7844 T1424 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 7845 T1390 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 7845 T1390 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 7846 T1390 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 7846 T1390 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 7847 T1390 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 7847 T1390 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 7847 T1390 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 7848 T1390 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 7848 T1390 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 7849 T1390 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 7865 T1390 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 7871 T1390 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty4-1347991816981/collection1
[junit4:junit4]   2> 7872 T1390 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 7872 T1390 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 7873 T1390 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 7874 T1390 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty4-1347991816981/collection1/'
[junit4:junit4]   2> 7876 T1390 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solrtest-jetty4-1347991816981/collection1/lib/README' to classloader
[junit4:junit4]   2> 7876 T1390 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solrtest-jetty4-1347991816981/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 7928 T1390 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_40
[junit4:junit4]   2> 8000 T1390 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 8101 T1390 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 8108 T1390 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 8738 T1390 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 8749 T1390 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 8754 T1390 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 8764 T1390 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 8769 T1390 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 8774 T1390 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 8775 T1390 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 8776 T1390 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty4-1347991816981/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty4/
[junit4:junit4]   2> 8776 T1390 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2180b22e
[junit4:junit4]   2> 8777 T1390 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty4/index/
[junit4:junit4]   2> 8778 T1390 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 8779 T1390 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty4/index forceNew:false
[junit4:junit4]   2> 8789 T1390 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty4/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 8790 T1390 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 8791 T1390 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 8793 T1390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 8794 T1390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 8794 T1390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 8795 T1390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 8796 T1390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 8796 T1390 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 8797 T1390 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 8797 T1390 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 8798 T1390 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 8799 T1390 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 8800 T1390 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 8800 T1390 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 8801 T1390 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 8801 T1390 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 8802 T1390 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 8803 T1390 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 8803 T1390 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8804 T1390 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8805 T1390 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8806 T1390 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8806 T1390 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8807 T1390 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8808 T1390 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8808 T1390 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 8809 T1390 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 8813 T1390 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 8818 T1390 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 8819 T1390 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> 8823 T1390 oass.SolrIndexSearcher.<init> Opening Searcher@6279c67f main
[junit4:junit4]   2> 8824 T1390 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 8825 T1390 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 8825 T1390 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 8833 T1390 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 8887 T1463 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6279c67f main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 9203 T1411 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9216 T1462 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9216 T1410 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9216 T1436 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9216 T1448 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9216 T1424 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9395 T1390 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 9395 T1390 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:20094/solr shardId:shard2
[junit4:junit4]   2> 9398 T1390 oasc.ZkController.register We are http://127.0.0.1:20094/solr/collection1/ and leader is http://127.0.0.1:20086/solr/collection1/
[junit4:junit4]   2> 9399 T1390 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:20094/solr
[junit4:junit4]   2> 9400 T1390 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 9400 T1390 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C147 name=collection1 org.apache.solr.core.SolrCore@529b9757 url=http://127.0.0.1:20094/solr/collection1 node=127.0.0.1:20094_solr
[junit4:junit4]   2> 9401 T1464 C147 P20094 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 9402 T1464 C147 P20094 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 9401 T1390 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9403 T1464 C147 P20094 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:20086/solr/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 9403 T1464 C147 P20094 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:20094/solr START replicas=[http://127.0.0.1:20086/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 9403 T1390 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1
[junit4:junit4]   2> 9403 T1464 C147 P20094 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 9404 T1464 C147 P20094 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 9404 T1390 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 9404 T1464 C147 P20094 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 9405 T1464 C147 P20094 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 9405 T1390 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C148 name=collection1 org.apache.solr.core.SolrCore@53c8fbc5 url=http://127.0.0.1:20086/solr/collection1 node=127.0.0.1:20086_solr
[junit4:junit4]   2> 9417 T1428 C148 P20086 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=1 
[junit4:junit4]   2> 9422 T1390 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:20077/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@7927fcde
[junit4:junit4]   2> 9423 T1466 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:20077
[junit4:junit4]   2> 9423 T1390 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 9424 T1466 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:20077, initiating session
[junit4:junit4]   2> 9424 T1392 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:20098
[junit4:junit4]   2> 9424 T1392 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:20098
[junit4:junit4]   2> 9425 T1394 oazs.NIOServerCnxn.finishSessionInit Established session 0x139da92ad6c0007 with negotiated timeout 10000 for client /140.211.11.196:20098
[junit4:junit4]   2> 9425 T1466 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:20077, sessionid = 0x139da92ad6c0007, negotiated timeout = 10000
[junit4:junit4]   2> 9426 T1467 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7927fcde name:ZooKeeperConnection Watcher:127.0.0.1:20077/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 9426 T1390 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 9426 T1390 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 9428 T1390 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   2> 9428 T1390 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 9438 T1390 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> ASYNC  NEW_CORE C149 name=collection1 org.apache.solr.core.SolrCore@1c2ba649 url=http://127.0.0.1:20080/solr/collection1 node=127.0.0.1:20080_solr
[junit4:junit4]   2> 9448 T1402 C149 P20080 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/control/data/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 9449 T1402 C149 P20080 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 9452 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[1 (1413471869416243200)]} 0 8
[junit4:junit4]   2> 9453 T1390 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:20077/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@318603db
[junit4:junit4]   2> 9454 T1468 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:20077
[junit4:junit4]   2> 9454 T1390 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 9455 T1468 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:20077, initiating session
[junit4:junit4]   2> 9455 T1392 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:20100
[junit4:junit4]   2> 9455 T1392 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:20100
[junit4:junit4]   2> 9457 T1394 oazs.NIOServerCnxn.finishSessionInit Established session 0x139da92ad6c0008 with negotiated timeout 10000 for client /140.211.11.196:20100
[junit4:junit4]   2> 9457 T1468 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:20077, sessionid = 0x139da92ad6c0008, negotiated timeout = 10000
[junit4:junit4]   2> 9457 T1469 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@318603db name:ZooKeeperConnection Watcher:127.0.0.1:20077/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 9457 T1390 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 9458 T1390 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 9465 T1418 C146 P20083 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty1/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 9466 T1418 C146 P20083 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2>  C145_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:20090_solr, base_url=http://127.0.0.1:20090/solr}
[junit4:junit4]   2> 9482 T1440 C145 P20090 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty3/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 9483 T1440 C145 P20090 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 9488 T1440 C145 P20090 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=10 
[junit4:junit4]   2> 9489 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[1 (1413471869433020416)]} 0 28
[junit4:junit4]   2> 9490 T1390 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):3600
[junit4:junit4]   2> 9490 T1390 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9720 T1411 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9733 T1448 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9733 T1424 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9733 T1410 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9733 T1436 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9733 T1462 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9733 T1467 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9733 T1469 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10492 T1390 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 10620 T1450 C145 P20090 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 10620 T1450 C145 P20090 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=tlog{file=./org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty3/tlog/tlog.0000000000000000000 refcount=1}}
[junit4:junit4]   2> 10620 T1450 C145 P20090 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:20083/solr/collection1/. core=collection1
[junit4:junit4]   2> 10620 T1450 C145 P20090 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 10628 T1419 C146 P20083 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 10740 T1419 C146 P20083 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty1/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty1/index,segFN=segments_2,generation=2,filenames=[_0_MockVariableIntBlock_0.doc, _0_MockVariableIntBlock_0.skp, _0_Pulsing40_0.prx, _0_Pulsing40_0.frq, _0_MockVariableIntBlock_0.pyl, _0_MockVariableIntBlock_0.tib, _0_MockVariableIntBlock_0.pos, _0_Pulsing40_0.tip, _0.si, _0_MockVariableIntBlock_0.tii, _0.fnm, _0_Pulsing40_0.tim, _0_Memory_0.ram, _0_nrm.cfs, _0_MockRandom_0.skp, _0_MockRandom_0.tip, _0_MockRandom_0.frq, _0_MockRandom_0.sd, _0_MockRandom_0.doc, _0_MockRandom_0.pos, _0_MockVariableIntBlock_0.frq, _0_nrm.cfe, segments_2, _0.fdx, _0_MockRandom_0.pyl, _0_MockRandom_0.tim, _0.fdt]
[junit4:junit4]   2> 10741 T1419 C146 P20083 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 10756 T1419 C146 P20083 oass.SolrIndexSearcher.<init> Opening Searcher@5ad52fed main
[junit4:junit4]   2> 10757 T1419 C146 P20083 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 10758 T1425 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5ad52fed main{StandardDirectoryReader(segments_2:3 _0(4.0.0.2):C1)}
[junit4:junit4]   2> 10758 T1419 C146 P20083 /update {waitSearcher=true&commit=true&commit_end_point=true&wt=javabin&softCommit=false&version=2} {commit=} 0 130
[junit4:junit4]   2> 10759 T1450 C145 P20090 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 10759 T1450 C145 P20090 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 10762 T1420 C146 P20083 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 10762 T1420 C146 P20083 REQ /replication {command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10763 T1450 C145 P20090 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4]   2> 10763 T1450 C145 P20090 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 10763 T1450 C145 P20090 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 10768 T1420 C146 P20083 REQ /replication {command=filelist&generation=2&wt=javabin&qt=/replication&version=2} status=0 QTime=3 
[junit4:junit4]   2> 10769 T1450 C145 P20090 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 27
[junit4:junit4]   2> 10777 T1450 C145 P20090 oash.SnapPuller.fetchLatestIndex Starting download to ./org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty3/index.20120918141020150 fullCopy=true
[junit4:junit4]   2> 10790 T1420 C146 P20083 REQ /replication {file=_0_MockVariableIntBlock_0.doc&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=5 
[junit4:junit4]   2> 10802 T1420 C146 P20083 REQ /replication {file=_0_MockVariableIntBlock_0.skp&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 10804 T1450 C145 P20090 oash.SnapPuller$FileFetcher.fetchPackets WARNING No content recieved for file: {name=_0_MockVariableIntBlock_0.skp, lastmodified=1347991820000, size=0}
[junit4:junit4]   2> 10807 T1420 C146 P20083 REQ /replication {file=_0_Pulsing40_0.prx&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 10811 T1420 C146 P20083 REQ /replication {file=_0_Pulsing40_0.frq&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 10815 T1420 C146 P20083 REQ /replication {file=_0_MockVariableIntBlock_0.pyl&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 10816 T1450 C145 P20090 oash.SnapPuller$FileFetcher.fetchPackets WARNING No content recieved for file: {name=_0_MockVariableIntBlock_0.pyl, lastmodified=1347991820000, size=0}
[junit4:junit4]   2> 10820 T1420 C146 P20083 REQ /replication {file=_0_MockVariableIntBlock_0.tib&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 10824 T1420 C146 P20083 REQ /replication {file=_0_Pulsing40_0.tip&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 10828 T1420 C146 P20083 REQ /replication {file=_0_MockVariableIntBlock_0.pos&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 10832 T1420 C146 P20083 REQ /replication {file=_0.si&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 10836 T1420 C146 P20083 REQ /replication {file=_0_MockVariableIntBlock_0.tii&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 10840 T1420 C146 P20083 REQ /replication {file=_0_Pulsing40_0.tim&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 10844 T1420 C146 P20083 REQ /replication {file=_0.fnm&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 10848 T1420 C146 P20083 REQ /replication {file=_0_Memory_0.ram&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 10852 T1420 C146 P20083 REQ /replication {file=_0_nrm.cfs&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 10856 T1420 C146 P20083 REQ /replication {file=_0_MockRandom_0.skp&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 10857 T1450 C145 P20090 oash.SnapPuller$FileFetcher.fetchPackets WARNING No content recieved for file: {name=_0_MockRandom_0.skp, lastmodified=1347991820000, size=0}
[junit4:junit4]   2> 10861 T1420 C146 P20083 REQ /replication {file=_0_MockRandom_0.sd&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 10865 T1420 C146 P20083 REQ /replication {file=_0_MockRandom_0.frq&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 10869 T1420 C146 P20083 REQ /replication {file=_0_MockRandom_0.tip&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 10873 T1420 C146 P20083 REQ /replication {file=_0_MockRandom_0.doc&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 10877 T1420 C146 P20083 REQ /replication {file=_0_nrm.cfe&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 10881 T1420 C146 P20083 REQ /replication {file=_0_MockVariableIntBlock_0.frq&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 10885 T1420 C146 P20083 REQ /replication {file=_0_MockRandom_0.pos&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 10889 T1420 C146 P20083 REQ /replication {file=segments_2&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 10893 T1420 C146 P20083 REQ /replication {file=_0.fdx&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 10897 T1420 C146 P20083 REQ /replication {file=_0_MockRandom_0.pyl&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 10898 T1450 C145 P20090 oash.SnapPuller$FileFetcher.fetchPackets WARNING No content recieved for file: {name=_0_MockRandom_0.pyl, lastmodified=1347991820000, size=0}
[junit4:junit4]   2> 10902 T1420 C146 P20083 REQ /replication {file=_0_MockRandom_0.tim&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 10906 T1420 C146 P20083 REQ /replication {file=_0.fdt&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 10907 T1450 C145 P20090 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 10908 T1450 C145 P20090 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20120918141020150
[junit4:junit4]   2> 10919 T1450 C145 P20090 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 10920 T1450 C145 P20090 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 10920 T1450 C145 P20090 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4]   2> 10925 T1450 C145 P20090 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=./org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty3/index/ new=./org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty3/index.20120918141020150
[junit4:junit4]   2> 10926 T1450 C145 P20090 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty3/index.20120918141020150 forceNew:true
[junit4:junit4]   2> 10938 T1450 C145 P20090 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty3/index.20120918141020150,segFN=segments_2,generation=2,filenames=[_0_MockVariableIntBlock_0.doc, _0_MockVariableIntBlock_0.skp, _0_Pulsing40_0.prx, _0_Pulsing40_0.frq, _0_MockVariableIntBlock_0.pyl, _0_MockVariableIntBlock_0.tib, _0_Pulsing40_0.tip, _0_MockVariableIntBlock_0.pos, _0.si, _0_MockVariableIntBlock_0.tii, _0_Pulsing40_0.tim, _0.fnm, _0_Memory_0.ram, _0_nrm.cfs, _0_MockRandom_0.skp, _0_MockRandom_0.tip, _0_MockRandom_0.frq, _0_MockRandom_0.sd, _0_MockRandom_0.doc, _0_MockRandom_0.pos, _0_MockVariableIntBlock_0.frq, _0_nrm.cfe, segments_2, _0.fdx, _0_MockRandom_0.pyl, _0_MockRandom_0.tim, _0.fdt]
[junit4:junit4]   2> 10938 T1450 C145 P20090 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 10938 T1450 C145 P20090 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 10943 T1450 C145 P20090 oass.SolrIndexSearcher.<init> Opening Searcher@2d893cba main
[junit4:junit4]   2> 10945 T1449 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2d893cba main{StandardDirectoryReader(segments_2:3:nrt _0(4.0.0.2):C1)}
[junit4:junit4]   2> 10945 T1449 oasc.CachingDirectoryFactory.close Closing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty3/index
[junit4:junit4]   2> 10946 T1449 oash.SnapPuller$2.onClose removing old index directory ./org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty3/index
[junit4:junit4]   2> 10947 T1450 C145 P20090 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=false,waitSearcher=false,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 10948 T1450 C145 P20090 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 10948 T1450 C145 P20090 oasc.RecoveryStrategy.replay Replaying buffered documents. core=collection1
[junit4:junit4]   2> 10948 T1472 C145 P20090 oasu.UpdateLog$LogReplayer.doReplay WARNING Starting log replay tlog{file=./org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty3/tlog/tlog.0000000000000000000 refcount=2} active=true starting pos=432
[junit4:junit4]   2> 10949 T1472 C145 P20090 oasu.DirectUpdateHandler2.commit start commit{flags=2,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 10950 T1472 C145 P20090 oass.SolrIndexSearcher.<init> Opening Searcher@1940d1f6 main
[junit4:junit4]   2> 10950 T1472 C145 P20090 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 10952 T1449 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1940d1f6 main{StandardDirectoryReader(segments_2:3:nrt _0(4.0.0.2):C1)}
[junit4:junit4]   2> 10952 T1472 C145 P20090 oasu.UpdateLog$LogReplayer.run WARNING Log replay finished. recoveryInfo=RecoveryInfo{adds=0 deletes=0 deleteByQuery=0 errors=0 positionOfStart=432}
[junit4:junit4]   2> 10952 T1450 C145 P20090 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 10954 T1450 C145 P20090 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 11239 T1411 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 11251 T1448 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11251 T1424 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11251 T1467 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11251 T1469 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11251 T1436 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11251 T1410 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11251 T1462 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11494 T1390 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2>  C147_STATE=coll:collection1 core:collection1 props:{shard=shard2, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:20094_solr, base_url=http://127.0.0.1:20094/solr}
[junit4:junit4]   2> 12425 T1464 C147 P20094 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 12425 T1464 C147 P20094 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 12425 T1464 C147 P20094 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:20086/solr/collection1/. core=collection1
[junit4:junit4]   2> 12425 T1464 C147 P20094 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 12441 T1430 C148 P20086 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 12444 T1430 C148 P20086 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty2/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 12445 T1430 C148 P20086 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 12446 T1430 C148 P20086 oass.SolrIndexSearcher.<init> Opening Searcher@3e8bb77b main
[junit4:junit4]   2> 12446 T1430 C148 P20086 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 12447 T1437 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3e8bb77b main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 12448 T1430 C148 P20086 /update {waitSearcher=true&commit=true&commit_end_point=true&wt=javabin&softCommit=false&version=2} {commit=} 0 7
[junit4:junit4]   2> 12449 T1464 C147 P20094 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 12449 T1464 C147 P20094 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 12450 T1431 C148 P20086 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 12451 T1431 C148 P20086 REQ /replication {command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
[junit4:junit4]   2> 12455 T1464 C147 P20094 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty4/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 12455 T1464 C147 P20094 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 12456 T1464 C147 P20094 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 12459 T1464 C147 P20094 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty4/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/jetty4/index,segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 12459 T1464 C147 P20094 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 12463 T1464 C147 P20094 oass.SolrIndexSearcher.<init> Opening Searcher@ef99e17 main
[junit4:junit4]   2> 12463 T1464 C147 P20094 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 12464 T1463 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@ef99e17 main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 12465 T1464 C147 P20094 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 12465 T1464 C147 P20094 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 12471 T1464 C147 P20094 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 12496 T1390 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12758 T1411 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12762 T1448 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12762 T1462 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12762 T1467 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12762 T1469 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12762 T1436 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12762 T1424 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12762 T1410 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 13498 T1390 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 13501 T1402 C149 P20080 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 13587 T1402 C149 P20080 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/control/data/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/control/data/index,segFN=segments_2,generation=2,filenames=[_0_MockRandom_0.tib, _0.fnm, _0_Pulsing40_0.tim, _0_Memory_0.ram, _0_MockVariableIntBlock_0.doc, _0_MockRandom_0.prx, _0_nrm.cfs, _0_MockVariableIntBlock_0.skp, _0_Pulsing40_0.prx, _0_Pulsing40_0.frq, _0_MockVariableIntBlock_0.pyl, _0_MockRandom_0.frq, _0_MockRandom_0.sd, _0_MockVariableIntBlock_0.tib, _0_MockVariableIntBlock_0.frq, _0_nrm.cfe, _0_Pulsing40_0.tip, _0_MockRandom_0.tii, _0_MockVariableIntBlock_0.pos, segments_2, _0.fdx, _0.si, _0.fdt, _0_MockVariableIntBlock_0.tii]
[junit4:junit4]   2> 13587 T1402 C149 P20080 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 13598 T1402 C149 P20080 oass.SolrIndexSearcher.<init> Opening Searcher@203e4015 main
[junit4:junit4]   2> 13599 T1402 C149 P20080 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 13600 T1413 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@203e4015 main{StandardDirectoryReader(segments_2:3 _0(4.0.0.2):C1)}
[junit4:junit4]   2> 13600 T1402 C149 P20080 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 99
[junit4:junit4]   2> 13602 T1432 C148 P20086 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 13605 T1432 C148 P20086 oass.SolrIndexSearcher.<init> Opening Searcher@1a50cabc main
[junit4:junit4]   2> 13605 T1432 C148 P20086 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 13607 T1437 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1a50cabc main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 13607 T1432 C148 P20086 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:20083/solr/collection1/, StdNode: http://127.0.0.1:20090/solr/collection1/, StdNode: http://127.0.0.1:20094/solr/collection1/]
[junit4:junit4]   2> 13609 T1421 C146 P20083 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2>  C145_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:20090_solr, base_url=http://127.0.0.1:20090/solr}
[junit4:junit4]   2> 13612 T1440 C145 P20090 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 13614 T1440 C145 P20090 oass.SolrIndexSearcher.<init> Opening Searcher@431e34c7 main
[junit4:junit4]   2> 13615 T1440 C145 P20090 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 13617 T1449 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@431e34c7 main{StandardDirectoryReader(segments_2:3:nrt _0(4.0.0.2):C1)}
[junit4:junit4]   2> 13617 T1440 C145 P20090 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&expungeDeletes=false&softCommit=false&version=2} {commit=} 0 6
[junit4:junit4]   2> 13620 T1421 C146 P20083 oass.SolrIndexSearcher.<init> Opening Searcher@1e92e158 main
[junit4:junit4]   2> 13621 T1421 C146 P20083 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 13626 T1425 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1e92e158 main{StandardDirectoryReader(segments_2:3 _0(4.0.0.2):C1)}
[junit4:junit4]   2>  C147_STATE=coll:collection1 core:collection1 props:{shard=shard2, roles=null, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:20094_solr, base_url=http://127.0.0.1:20094/solr}
[junit4:junit4]   2> 13626 T1454 C147 P20094 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 13627 T1421 C146 P20083 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&expungeDeletes=false&softCommit=false&version=2} {commit=} 0 18
[junit4:junit4]   2> 13630 T1454 C147 P20094 oass.SolrIndexSearcher.<init> Opening Searcher@59efd601 main
[junit4:junit4]   2> 13630 T1454 C147 P20094 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 13632 T1463 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@59efd601 main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 13632 T1454 C147 P20094 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&expungeDeletes=false&softCommit=false&version=2} {commit=} 0 6
[junit4:junit4]   2> 13633 T1432 C148 P20086 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 31
[junit4:junit4]   2> 13638 T1403 C149 P20080 REQ /select {fl=id,score&shard.url=127.0.0.1:20080/solr/collection1/&NOW=1347991823015&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 13641 T1403 C149 P20080 REQ /select {shard.url=127.0.0.1:20080/solr/collection1/&NOW=1347991823015&q=*:*&ids=1&distrib=false&isShard=true&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 13642 T1402 C149 P20080 REQ /select {wt=javabin&q=*:*&version=2} hits=1 status=0 QTime=7 
[junit4:junit4]   2> 13643 T1390 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:20077/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@50b58f5
[junit4:junit4]   2> 13644 T1477 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:20077
[junit4:junit4]   2> 13644 T1390 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 13644 T1477 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:20077, initiating session
[junit4:junit4]   2> 13644 T1392 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:20113
[junit4:junit4]   2> 13644 T1392 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:20113
[junit4:junit4]   2> 13646 T1394 oazs.NIOServerCnxn.finishSessionInit Established session 0x139da92ad6c0009 with negotiated timeout 10000 for client /140.211.11.196:20113
[junit4:junit4]   2> 13646 T1477 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:20077, sessionid = 0x139da92ad6c0009, negotiated timeout = 10000
[junit4:junit4]   2> 13647 T1478 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@50b58f5 name:ZooKeeperConnection Watcher:127.0.0.1:20077/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 13647 T1390 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 13648 T1390 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 13649 T1395 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x139da92ad6c0009
[junit4:junit4]   2> 13657 T1478 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 13657 T1392 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:20113 which had sessionid 0x139da92ad6c0009
[junit4:junit4]   2> 13657 T1390 oaz.ZooKeeper.close Session: 0x139da92ad6c0009 closed
[junit4:junit4]   2> 13659 T1422 C146 P20083 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 13661 T1433 C148 P20086 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 13665 T1417 C146 P20083 REQ /select {fl=id,score&shard.url=127.0.0.1:20083/solr/collection1/|127.0.0.1:20090/solr/collection1/&NOW=1347991823042&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 13665 T1456 C147 P20094 REQ /select {fl=id,score&shard.url=127.0.0.1:20086/solr/collection1/|127.0.0.1:20094/solr/collection1/&NOW=1347991823042&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 13668 T1417 C146 P20083 REQ /select {shard.url=127.0.0.1:20083/solr/collection1/|127.0.0.1:20090/solr/collection1/&NOW=1347991823042&q=*:*&ids=1&distrib=false&isShard=true&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 13669 T1455 C147 P20094 REQ /select {wt=javabin&q=*:*&version=2} hits=1 status=0 QTime=7 
[junit4:junit4]   2> 13675 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[2 (1413471873848573952)]} 0 3
[junit4:junit4]   2> 13690 T1454 C147 P20094 REQ /update {distrib.from=http://127.0.0.1:20086/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 13690 T1432 C148 P20086 /update {wt=javabin&version=2} {add=[2 (1413471873855913984)]} 0 12
[junit4:junit4]   2> 13695 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[3 (1413471873870594048)]} 0 2
[junit4:junit4]   2> 13703 T1454 C147 P20094 REQ /update {distrib.from=http://127.0.0.1:20086/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 13703 T1432 C148 P20086 /update {wt=javabin&version=2} {add=[3 (1413471873875836928)]} 0 6
[junit4:junit4]   2> 13707 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[4 (1413471873884225536)]} 0 1
[junit4:junit4]   2> 13722 T1440 C145 P20090 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 13722 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[4 (1413471873889468416)]} 0 12
[junit4:junit4]   2> 13727 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[5 (1413471873904148480)]} 0 2
[junit4:junit4]   2> 13736 T1454 C147 P20094 REQ /update {distrib.from=http://127.0.0.1:20086/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 13736 T1432 C148 P20086 /update {wt=javabin&version=2} {add=[5 (1413471873909391360)]} 0 7
[junit4:junit4]   2> 13740 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[6 (1413471873918828544)]} 0 1
[junit4:junit4]   2> 13749 T1454 C147 P20094 REQ /update {distrib.from=http://127.0.0.1:20086/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 13750 T1432 C148 P20086 /update {wt=javabin&version=2} {add=[6 (1413471873924071424)]} 0 7
[junit4:junit4]   2> 13755 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[7 (1413471873933508608)]} 0 2
[junit4:junit4]   2> 13766 T1454 C147 P20094 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:20086/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 13766 T1434 C148 P20086 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 13767 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[7]} 0 10
[junit4:junit4]   2> 13772 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[8 (1413471873951334400)]} 0 2
[junit4:junit4]   2> 13782 T1440 C145 P20090 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 13782 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[8 (1413471873956577280)]} 0 8
[junit4:junit4]   2> 13787 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[9 (1413471873968111616)]} 0 2
[junit4:junit4]   2> 13797 T1454 C147 P20094 REQ /update {distrib.from=http://127.0.0.1:20086/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 13798 T1432 C148 P20086 /update {wt=javabin&version=2} {add=[9 (1413471873973354496)]} 0 8
[junit4:junit4]   2> 13803 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[10 (1413471873983840256)]} 0 2
[junit4:junit4]   2> 13815 T1440 C145 P20090 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:20083/solr/collection1/&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 13815 T1421 C146 P20083 REQ /update {distrib.from=http://127.0.0.1:20086/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 13816 T1432 C148 P20086 /update {wt=javabin&version=2} {add=[10]} 0 11
[junit4:junit4]   2> 13849 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[11 (1413471874003763200)]} 0 30
[junit4:junit4]   2> 13859 T1440 C145 P20090 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 13860 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[11 (1413471874038366208)]} 0 8
[junit4:junit4]   2> 13866 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[12 (1413471874048851968)]} 0 3
[junit4:junit4]   2> 13879 T1440 C145 P20090 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:20083/solr/collection1/&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 13879 T1421 C146 P20083 REQ /update {distrib.from=http://127.0.0.1:20086/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 13880 T1432 C148 P20086 /update {wt=javabin&version=2} {add=[12]} 0 11
[junit4:junit4]   2> 13885 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[13 (1413471874069823488)]} 0 2
[junit4:junit4]   2> 13897 T1440 C145 P20090 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:20083/solr/collection1/&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 13898 T1421 C146 P20083 REQ /update {distrib.from=http://127.0.0.1:20086/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=8 
[junit4:junit4]   2> 13898 T1432 C148 P20086 /update {wt=javabin&version=2} {add=[13]} 0 11
[junit4:junit4]   2> 13903 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[14 (1413471874088697856)]} 0 2
[junit4:junit4]   2> 13911 T1440 C145 P20090 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 13912 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[14 (1413471874093940736)]} 0 7
[junit4:junit4]   2> 13916 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[15 (1413471874103377920)]} 0 1
[junit4:junit4]   2> 13925 T1440 C145 P20090 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 13926 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[15 (1413471874108620800)]} 0 7
[junit4:junit4]   2> 13929 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[16 (1413471874117009408)]} 0 1
[junit4:junit4]   2> 13941 T1440 C145 P20090 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:20083/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 13942 T1421 C146 P20083 REQ /update {distrib.from=http://127.0.0.1:20086/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 13943 T1432 C148 P20086 /update {wt=javabin&version=2} {add=[16]} 0 11
[junit4:junit4]   2> 13950 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[17 (1413471874136932352)]} 0 4
[junit4:junit4]   2> 13968 T1454 C147 P20094 REQ /update {distrib.from=http://127.0.0.1:20086/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 13968 T1432 C148 P20086 /update {wt=javabin&version=2} {add=[17 (1413471874146369536)]} 0 15
[junit4:junit4]   2> 13974 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[100 (1413471874164195328)]} 0 2
[junit4:junit4]   2> 14037 T1440 C145 P20090 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=27 
[junit4:junit4]   2> 14038 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[100 (1413471874168389632)]} 0 61
[junit4:junit4]   2> 14044 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[101 (1413471874236547072)]} 0 3
[junit4:junit4]   2> 14056 T1440 C145 P20090 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 14056 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[101 (1413471874241789952)]} 0 10
[junit4:junit4]   2> 14062 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[102 (1413471874256470016)]} 0 2
[junit4:junit4]   2> 14072 T1440 C145 P20090 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 14073 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[102 (1413471874261712896)]} 0 8
[junit4:junit4]   2> 14104 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[103 (1413471874273247232)]} 0 28
[junit4:junit4]   2> 14116 T1454 C147 P20094 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:20086/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 14117 T1434 C148 P20086 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 14118 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[103]} 0 11
[junit4:junit4]   2> 14125 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[104 (1413471874320433152)]} 0 4
[junit4:junit4]   2> 14134 T1454 C147 P20094 REQ /update {distrib.from=http://127.0.0.1:20086/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 14135 T1432 C148 P20086 /update {wt=javabin&version=2} {add=[104 (1413471874326724608)]} 0 7
[junit4:junit4]   2> 14140 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[105 (1413471874337210368)]} 0 2
[junit4:junit4]   2> 14205 T1454 C147 P20094 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:20086/solr/collection1/&wt=javabin&version=2} status=0 QTime=29 
[junit4:junit4]   2> 14206 T1434 C148 P20086 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=60 
[junit4:junit4]   2> 14206 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[105]} 0 63
[junit4:junit4]   2> 14211 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[106 (1413471874412707840)]} 0 2
[junit4:junit4]   2> 14228 T1454 C147 P20094 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:20086/solr/collection1/&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 14229 T1434 C148 P20086 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=11 
[junit4:junit4]   2> 14230 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[106]} 0 15
[junit4:junit4]   2> 14235 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[107 (1413471874437873664)]} 0 2
[junit4:junit4]   2> 14247 T1440 C145 P20090 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:20083/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 14248 T1421 C146 P20083 REQ /update {distrib.from=http://127.0.0.1:20086/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 14248 T1432 C148 P20086 /update {wt=javabin&version=2} {add=[107]} 0 10
[junit4:junit4]   2> 14254 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[108 (1413471874456748032)]} 0 2
[junit4:junit4]   2> 14266 T1440 C145 P20090 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:20083/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 14267 T1421 C146 P20083 REQ /update {distrib.from=http://127.0.0.1:20086/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 14267 T1432 C148 P20086 /update {wt=javabin&version=2} {add=[108]} 0 10
[junit4:junit4]   2> 14272 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[109 (1413471874475622400)]} 0 2
[junit4:junit4]   2> 14284 T1440 C145 P20090 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:20083/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 14285 T1421 C146 P20083 REQ /update {distrib.from=http://127.0.0.1:20086/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 14285 T1432 C148 P20086 /update {wt=javabin&version=2} {add=[109]} 0 10
[junit4:junit4]   2> 14290 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[110 (1413471874494496768)]} 0 2
[junit4:junit4]   2> 14303 T1440 C145 P20090 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:20083/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 14304 T1421 C146 P20083 REQ /update {distrib.from=http://127.0.0.1:20086/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=8 
[junit4:junit4]   2> 14304 T1432 C148 P20086 /update {wt=javabin&version=2} {add=[110]} 0 11
[junit4:junit4]   2> 14309 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[111 (1413471874514419712)]} 0 2
[junit4:junit4]   2> 14318 T1440 C145 P20090 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 14318 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[111 (1413471874519662592)]} 0 6
[junit4:junit4]   2> 14323 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[112 (1413471874530148352)]} 0 2
[junit4:junit4]   2> 14332 T1454 C147 P20094 REQ /update {distrib.from=http://127.0.0.1:20086/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 14332 T1432 C148 P20086 /update {wt=javabin&version=2} {add=[112 (1413471874534342656)]} 0 6
[junit4:junit4]   2> 14358 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[113 (1413471874544828416)]} 0 23
[junit4:junit4]   2> 14367 T1440 C145 P20090 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14368 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[113 (1413471874572091392)]} 0 6
[junit4:junit4]   2> 14372 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[114 (1413471874580480000)]} 0 2
[junit4:junit4]   2> 14379 T1440 C145 P20090 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14380 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[114 (1413471874585722880)]} 0 5
[junit4:junit4]   2> 14384 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[115 (1413471874594111488)]} 0 1
[junit4:junit4]   2> 14391 T1454 C147 P20094 REQ /update {distrib.from=http://127.0.0.1:20086/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14392 T1432 C148 P20086 /update {wt=javabin&version=2} {add=[115 (1413471874598305792)]} 0 5
[junit4:junit4]   2> 14395 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[116 (1413471874605645824)]} 0 1
[junit4:junit4]   2> 14406 T1454 C147 P20094 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:20086/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14407 T1434 C148 P20086 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 14408 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[116]} 0 10
[junit4:junit4]   2> 14411 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[117 (1413471874622423040)]} 0 1
[junit4:junit4]   2> 14421 T1454 C147 P20094 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:20086/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14422 T1434 C148 P20086 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 14422 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[117]} 0 8
[junit4:junit4]   2> 14427 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[118 (1413471874639200256)]} 0 2
[junit4:junit4]   2> 14459 T1440 C145 P20090 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=14 
[junit4:junit4]   2> 14460 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[118 (1413471874642345984)]} 0 31
[junit4:junit4]   2> 14464 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[119 (1413471874677997568)]} 0 1
[junit4:junit4]   2> 14471 T1454 C147 P20094 REQ /update {distrib.from=http://127.0.0.1:20086/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14471 T1432 C148 P20086 /update {wt=javabin&version=2} {add=[119 (1413471874682191872)]} 0 4
[junit4:junit4]   2> 14475 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[120 (1413471874689531904)]} 0 1
[junit4:junit4]   2> 14485 T1454 C147 P20094 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:20086/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14486 T1434 C148 P20086 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 14486 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[120]} 0 8
[junit4:junit4]   2> 14490 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[121 (1413471874705260544)]} 0 1
[junit4:junit4]   2> 14500 T1454 C147 P20094 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:20086/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14501 T1434 C148 P20086 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 14501 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[121]} 0 8
[junit4:junit4]   2> 14505 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[122 (1413471874720989184)]} 0 1
[junit4:junit4]   2> 14514 T1440 C145 P20090 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 14514 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[122 (1413471874725183488)]} 0 6
[junit4:junit4]   2> 14532 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[123 (1413471874734620672)]} 0 15
[junit4:junit4]   2> 14542 T1440 C145 P20090 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:20083/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14543 T1421 C146 P20083 REQ /update {distrib.from=http://127.0.0.1:20086/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 14543 T1432 C148 P20086 /update {wt=javabin&version=2} {add=[123]} 0 9
[junit4:junit4]   2> 14548 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[124 (1413471874765029376)]} 0 2
[junit4:junit4]   2> 14555 T1440 C145 P20090 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14556 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[124 (1413471874770272256)]} 0 5
[junit4:junit4]   2> 14559 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[125 (1413471874777612288)]} 0 1
[junit4:junit4]   2> 14567 T1440 C145 P20090 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14568 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[125 (1413471874781806592)]} 0 6
[junit4:junit4]   2> 14571 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[126 (1413471874790195200)]} 0 1
[junit4:junit4]   2> 14579 T1454 C147 P20094 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:20086/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14579 T1434 C148 P20086 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 14580 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[126]} 0 7
[junit4:junit4]   2> 14584 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[127 (1413471874803826688)]} 0 1
[junit4:junit4]   2> 14618 T1454 C147 P20094 REQ /update {distrib.from=http://127.0.0.1:20086/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=15 
[junit4:junit4]   2> 14619 T1432 C148 P20086 /update {wt=javabin&version=2} {add=[127 (1413471874808020992)]} 0 32
[junit4:junit4]   2> 14623 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[128 (1413471874844721152)]} 0 1
[junit4:junit4]   2> 14633 T1454 C147 P20094 REQ /update {distrib.from=http://127.0.0.1:20086/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 14633 T1432 C148 P20086 /update {wt=javabin&version=2} {add=[128 (1413471874848915456)]} 0 7
[junit4:junit4]   2> 14637 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[129 (1413471874859401216)]} 0 1
[junit4:junit4]   2> 14646 T1440 C145 P20090 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:20083/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14647 T1421 C146 P20083 REQ /update {distrib.from=http://127.0.0.1:20086/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 14647 T1432 C148 P20086 /update {wt=javabin&version=2} {add=[129]} 0 7
[junit4:junit4]   2> 14651 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[130 (1413471874874081280)]} 0 1
[junit4:junit4]   2> 14659 T1454 C147 P20094 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:20086/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14659 T1434 C148 P20086 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 14660 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[130]} 0 7
[junit4:junit4]   2> 14664 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[131 (1413471874887712768)]} 0 1
[junit4:junit4]   2> 14673 T1454 C147 P20094 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:20086/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14674 T1434 C148 P20086 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 14674 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[131]} 0 7
[junit4:junit4]   2> 14678 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[132 (1413471874902392832)]} 0 1
[junit4:junit4]   2> 14684 T1440 C145 P20090 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14685 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[132 (1413471874905538560)]} 0 5
[junit4:junit4]   2> 14703 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[133 (1413471874912878592)]} 0 16
[junit4:junit4]   2> 14712 T1440 C145 P20090 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:20083/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14713 T1421 C146 P20083 REQ /update {distrib.from=http://127.0.0.1:20086/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 14713 T1432 C148 P20086 /update {wt=javabin&version=2} {add=[133]} 0 7
[junit4:junit4]   2> 14718 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[134 (1413471874943287296)]} 0 2
[junit4:junit4]   2> 14725 T1454 C147 P20094 REQ /update {distrib.from=http://127.0.0.1:20086/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14726 T1432 C148 P20086 /update {wt=javabin&version=2} {add=[134 (1413471874948530176)]} 0 5
[junit4:junit4]   2> 14729 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[135 (1413471874955870208)]} 0 1
[junit4:junit4]   2> 14738 T1440 C145 P20090 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:20083/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14738 T1421 C146 P20083 REQ /update {distrib.from=http://127.0.0.1:20086/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 14739 T1432 C148 P20086 /update {wt=javabin&version=2} {add=[135]} 0 7
[junit4:junit4]   2> 14742 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[136 (1413471874969501696)]} 0 1
[junit4:junit4]   2> 14750 T1454 C147 P20094 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:20086/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14750 T1434 C148 P20086 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 14751 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[136]} 0 7
[junit4:junit4]   2> 14755 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[137 (1413471874983133184)]} 0 1
[junit4:junit4]   2> 14761 T1454 C147 P20094 REQ /update {distrib.from=http://127.0.0.1:20086/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14762 T1432 C148 P20086 /update {wt=javabin&version=2} {add=[137 (1413471874986278912)]} 0 5
[junit4:junit4]   2> 14765 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[138 (1413471874993618944)]} 0 1
[junit4:junit4]   2> 14774 T1440 C145 P20090 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:20083/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14774 T1421 C146 P20083 REQ /update {distrib.from=http://127.0.0.1:20086/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 14775 T1432 C148 P20086 /update {wt=javabin&version=2} {add=[138]} 0 7
[junit4:junit4]   2> 14779 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[139 (1413471875008299008)]} 0 1
[junit4:junit4]   2> 14787 T1454 C147 P20094 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:20086/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14787 T1434 C148 P20086 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 14788 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[139]} 0 7
[junit4:junit4]   2> 14792 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[140 (1413471875021930496)]} 0 1
[junit4:junit4]   2> 14801 T1454 C147 P20094 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:20086/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14801 T1434 C148 P20086 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 14802 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[140]} 0 7
[junit4:junit4]   2> 14805 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[141 (1413471875035561984)]} 0 1
[junit4:junit4]   2> 14813 T1454 C147 P20094 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:20086/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14813 T1434 C148 P20086 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 14814 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[141]} 0 7
[junit4:junit4]   2> 14817 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[142 (1413471875048144896)]} 0 1
[junit4:junit4]   2> 14852 T1454 C147 P20094 REQ /update {distrib.from=http://127.0.0.1:20086/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=15 
[junit4:junit4]   2> 14853 T1432 C148 P20086 /update {wt=javabin&version=2} {add=[142 (1413471875051290624)]} 0 34
[junit4:junit4]   2> 14870 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[143 (1413471875090087936)]} 0 14
[junit4:junit4]   2> 14883 T1454 C147 P20094 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:20086/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 14884 T1434 C148 P20086 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=8 
[junit4:junit4]   2> 14884 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[143]} 0 11
[junit4:junit4]   2> 14889 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[144 (1413471875122593792)]} 0 2
[junit4:junit4]   2> 14899 T1454 C147 P20094 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:20086/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14899 T1434 C148 P20086 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 14900 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[144]} 0 8
[junit4:junit4]   2> 14903 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[145 (1413471875138322432)]} 0 1
[junit4:junit4]   2> 14910 T1454 C147 P20094 REQ /update {distrib.from=http://127.0.0.1:20086/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14910 T1432 C148 P20086 /update {wt=javabin&version=2} {add=[145 (1413471875142516736)]} 0 4
[junit4:junit4]   2> 14914 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[146 (1413471875149856768)]} 0 1
[junit4:junit4]   2> 14950 T1440 C145 P20090 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=16 
[junit4:junit4]   2> 14950 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[146 (1413471875154051072)]} 0 33
[junit4:junit4]   2> 14954 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[147 (1413471875191799808)]} 0 1
[junit4:junit4]   2> 14963 T1454 C147 P20094 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:20086/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14964 T1434 C148 P20086 REQ /update {distrib.from=http://127.0.0.1:20083/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 14964 T1418 C146 P20083 /update {wt=javabin&version=2} {add=[147]} 0 7
[junit4:junit4]   2> 14968 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[148 (1413471875206479872)]} 0 1
[junit4:junit4]   2> 14980 T1440 C145 P20090 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:20083/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 14981 T1421 C146 P20083 REQ /update {distrib.from=http://127.0.0.1:20086/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=8 
[junit4:junit4]   2> 14982 T1432 C148 P20086 /update {wt=javabin&version=2} {add=[148]} 0 11
[junit4:junit4]   2> 14985 T1402 C149 P20080 /update {wt=javabin&version=2} {add=[149 (1413471875224305664)]} 0 1
[junit4:junit4]   2> 14991 T1454 C147 P20094 REQ /update {distrib.from=http://127.0.0.1:20086/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14991 T1432 C148 P20086 /update {wt=javabin&version=2} {add=[149 (1413471875227451392)]} 0 4
[junit4:junit4]   2> 14992 T1390 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):3600
[junit4:junit4]   2> 14993 T1390 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 14995 T1402 C149 P20080 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 15613 T1402 C149 P20080 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/control/data/index,segFN=segments_2,generation=2,filenames=[_0_MockRandom_0.tib, _0.fnm, _0_Pulsing40_0.tim, _0_Memory_0.ram, _0_MockVariableIntBlock_0.doc, _0_MockRandom_0.prx, _0_nrm.cfs, _0_MockVariableIntBlock_0.skp, _0_Pulsing40_0.prx, _0_Pulsing40_0.frq, _0_MockVariableIntBlock_0.pyl, _0_MockRandom_0.frq, _0_MockRandom_0.sd, _0_MockVariableIntBlock_0.tib, _0_MockVariableIntBlock_0.frq, _0_nrm.cfe, _0_Pulsing40_0.tip, _0_MockRandom_0.tii, _0_MockVariableIntBlock_0.pos, segments_2, _0.fdx, _0.si, _0.fdt, _0_MockVariableIntBlock_0.tii]
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347991809383/control/data/index,segFN=segments_3,generation=3,filenames=[_5_nrm.cfe, _5_Memory_0.ram, _3_MockRandom_0.prx, _3_MockVariableIntBlock_0.frq, _0_MockRandom_0.prx, _7.si, _3.fdt, _4_MockVariableIntBlock_0.tii, _1_MockRandom_0.pos, _0_Pulsing40_0.frq, _7_Memory_0.ram, _7.fnm, _5_MockVariableIntBlock_0.tii, _5_MockRandom_0.pyl, _5_Pulsing40_0.tip, _6_MockVariableIntBlock_0.tii, _5_Pulsing40_0.tim, _5_MockRandom_0.pos, _1_MockRandom_0.tiv, _6_MockVariableIntBlock_0.tib, _0_Pulsing40_0.tim, _1_MockVariableIntBlock_0.tii, _0_Memory_0.ram, _4_MockVariableIntBlock_0.doc, _2.fdt, _3_Pulsing40_0.tip, _7.fdx, _1_MockRandom_0.sd, _7_MockVariableIntBlock_0.frq, _2.fdx, _7.fdt, _3_Pulsing40_0.tim, _1_MockVariableIntBlock_0.tib, _7_MockRandom_0.prx, _1.fdx, _0_MockRandom_0.frq, _7_Pulsing40_0.frq, _4_MockRandom_0.pr

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

per.close Session: 0x139daa1ad030009 closed
[junit4:junit4]   2> 164331 T3234 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4:junit4]   2> 164770 T3234 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4]   2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
[junit4:junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=SyncSliceTest -Dtests.method=testDistribSearch -Dtests.seed=9266E8D41AC43129 -Dtests.multiplier=3 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/hudson/lucene-data/enwiki.random.lines.txt -Dtests.locale=sv -Dtests.timezone=America/Rosario -Dtests.file.encoding=ISO-8859-1
[junit4:junit4] FAILURE  165s J1 | SyncSliceTest.testDistribSearch <<<
[junit4:junit4]    > Throwable #1: java.lang.AssertionError: There are still nodes recoverying
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([9266E8D41AC43129:138066CC6D9B5115]:0)
[junit4:junit4]    > 	at org.junit.Assert.fail(Assert.java:93)
[junit4:junit4]    > 	at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:154)
[junit4:junit4]    > 	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.waitForRecoveriesToFinish(AbstractFullDistribZkTestBase.java:560)
[junit4:junit4]    > 	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.waitForThingsToLevelOut(AbstractFullDistribZkTestBase.java:1135)
[junit4:junit4]    > 	at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:162)
[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:616)
[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:679)
[junit4:junit4]   2> 164826 T3234 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4]   2> NOTE: test params are: codec=Lucene40: {range_facet_l=PostingsFormat(name=Memory doPackFST= true), text=PostingsFormat(name=MockRandom), _version_=PostingsFormat(name=NestedPulsing), rnd_b=MockFixedIntBlock(blockSize=1162), intDefault=PostingsFormat(name=NestedPulsing), id=MockFixedIntBlock(blockSize=1162), timestamp=PostingsFormat(name=Memory doPackFST= true), a_t=PostingsFormat(name=Memory doPackFST= true), range_facet_sl=MockFixedIntBlock(blockSize=1162), range_facet_si=PostingsFormat(name=Memory doPackFST= true), other_tl1=PostingsFormat(name=NestedPulsing), multiDefault=PostingsFormat(name=Memory doPackFST= true), a_si=PostingsFormat(name=NestedPulsing)}, sim=DefaultSimilarity, locale=sv, timezone=America/Rosario
[junit4:junit4]   2> NOTE: FreeBSD 9.0-RELEASE amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=1,free=164701584,total=328073216
[junit4:junit4]   2> NOTE: All tests run in this JVM: [HighlighterTest, TestRecovery, TestReversedWildcardFilterFactory, TestCodecSupport, TestValueSourceCache, TestUpdate, DOMUtilTest, BadIndexSchemaTest, TestSurroundQueryParser, BasicFunctionalityTest, OpenExchangeRatesOrgProviderTest, StatelessScriptUpdateProcessorFactoryTest, DocumentBuilderTest, PolyFieldTest, StatsComponentTest, PrimitiveFieldTypeTest, OverseerTest, UUIDFieldTest, RAMDirectoryFactoryTest, ClusterStateUpdateTest, TestWriterPerf, ZkSolrClientTest, DirectUpdateHandlerTest, DistributedQueryElevationComponentTest, TestRealTimeGet, TestReload, TestFoldingMultitermQuery, TestPropInject, TestSolrDeletionPolicy2, TestMergePolicyConfig, URLClassifyProcessorTest, FullSolrCloudDistribCmdsTest, TestPluginEnable, TestQueryUtils, QueryParsingTest, TestCSVLoader, PeerSyncTest, LeaderElectionTest, LukeRequestHandlerTest, TestRemoteStreaming, StandardRequestHandlerTest, SolrIndexConfigTest, BasicDistributedZk2Test, TestDistributedSearch, XsltUpdateRequestHandlerTest, DocumentAnalysisRequestHandlerTest, SpellingQueryConverterTest, TestTrie, TestReplicationHandler, TestUtils, TestSolrDeletionPolicy1, TestDFRSimilarityFactory, TestPhraseSuggestions, IndexReaderFactoryTest, BasicDistributedZkTest, NumericFieldsTest, MultiTermTest, TestJmxMonitoredMap, TestBM25SimilarityFactory, TimeZoneUtilsTest, FileUtilsTest, TestSolrXMLSerializer, TestLRUCache, SystemInfoHandlerTest, ZkNodePropsTest, AnalysisAfterCoreReloadTest, SyncSliceTest]
[junit4:junit4] Completed on J1 in 164.86s, 1 test, 1 failure <<< FAILURES!

[...truncated 16 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:32: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build.xml:146: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/module-build.xml:63: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/common-build.xml:1136: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/common-build.xml:810: There were test failures: 230 suites, 951 tests, 2 failures, 7 ignored (2 assumptions)

Total time: 74 minutes 34 seconds
Build step 'Invoke Ant' marked build as failure
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message