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-Tests-4.x-Java6 - Build # 698 - Still Failing
Date Sun, 23 Sep 2012 11:23:41 GMT
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-Java6/698/

2 tests failed.
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([361BAFABA7533777:B7FD21B3D00C574B]: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)


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([361BAFABA7533777:B7FD21B3D00C574B]: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)




Build Log:
[...truncated 7178 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4:junit4]   2> 4 T1149 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1348398789908
[junit4:junit4]   2> 6 T1149 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 10 T1150 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4]   2> 10 T1150 oazs.NIOServerCnxn$Factory.<init> binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 11 T1150 oazsp.FileTxnSnapLog.save Snapshotting: 0
[junit4:junit4]   2> 107 T1149 oasc.ZkTestServer.run start zk server on port:49886
[junit4:junit4]   2> 107 T1149 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:49886 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@76effe43
[junit4:junit4]   2> 108 T1155 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:49886
[junit4:junit4]   2> 108 T1149 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 109 T1155 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:49886, initiating session
[junit4:junit4]   2> 109 T1151 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:49887
[junit4:junit4]   2> 110 T1151 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:49887
[junit4:junit4]   2> 110 T1153 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 114 T1153 oazs.NIOServerCnxn.finishSessionInit Established session 0x139f2d4b51b0000 with negotiated timeout 10000 for client /140.211.11.196:49887
[junit4:junit4]   2> 114 T1155 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:49886, sessionid = 0x139f2d4b51b0000, negotiated timeout = 10000
[junit4:junit4]   2> 114 T1156 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@76effe43 name:ZooKeeperConnection Watcher:127.0.0.1:49886 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 114 T1149 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 115 T1149 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 117 T1154 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x139f2d4b51b0000
[junit4:junit4]   2> 127 T1156 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 128 T1151 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:49887 which had sessionid 0x139f2d4b51b0000
[junit4:junit4]   2> 127 T1149 oaz.ZooKeeper.close Session: 0x139f2d4b51b0000 closed
[junit4:junit4]   2> 128 T1149 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:49886/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@22c26ee7
[junit4:junit4]   2> 129 T1157 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:49886
[junit4:junit4]   2> 129 T1149 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 130 T1157 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:49886, initiating session
[junit4:junit4]   2> 130 T1151 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:49888
[junit4:junit4]   2> 130 T1151 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:49888
[junit4:junit4]   2> 131 T1153 oazs.NIOServerCnxn.finishSessionInit Established session 0x139f2d4b51b0001 with negotiated timeout 10000 for client /140.211.11.196:49888
[junit4:junit4]   2> 131 T1157 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:49886, sessionid = 0x139f2d4b51b0001, negotiated timeout = 10000
[junit4:junit4]   2> 132 T1158 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@22c26ee7 name:ZooKeeperConnection Watcher:127.0.0.1:49886/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 132 T1149 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 132 T1149 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 136 T1149 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 138 T1149 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 145 T1149 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 148 T1149 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 149 T1149 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 161 T1149 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4]   2> 162 T1149 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 269 T1149 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 270 T1149 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 284 T1149 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4]   2> 284 T1149 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 293 T1149 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4]   2> 294 T1149 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 305 T1149 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4]   2> 305 T1149 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 313 T1149 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 314 T1149 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 325 T1149 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 326 T1149 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 339 T1149 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 340 T1149 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 353 T1149 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4]   2> 353 T1149 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 364 T1154 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x139f2d4b51b0001
[junit4:junit4]   2> 370 T1158 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 370 T1149 oaz.ZooKeeper.close Session: 0x139f2d4b51b0001 closed
[junit4:junit4]   2> 370 T1151 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:49888 which had sessionid 0x139f2d4b51b0001
[junit4:junit4]   2> 372 T1149 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 376 T1149 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:49889
[junit4:junit4]   2> 376 T1149 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 377 T1149 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 377 T1149 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 421 T1149 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 422 T1149 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 422 T1149 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 423 T1149 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/solr.xml
[junit4:junit4]   2> 423 T1149 oasc.CoreContainer.<init> New CoreContainer 926010535
[junit4:junit4]   2> 424 T1149 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 424 T1149 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 452 T1149 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 470 T1149 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:49886/solr
[junit4:junit4]   2> 470 T1149 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:49886/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@491c1978
[junit4:junit4]   2> 471 T1168 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:49886
[junit4:junit4]   2> 471 T1149 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 472 T1168 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:49886, initiating session
[junit4:junit4]   2> 472 T1151 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:49890
[junit4:junit4]   2> 473 T1151 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:49890
[junit4:junit4]   2> 475 T1153 oazs.NIOServerCnxn.finishSessionInit Established session 0x139f2d4b51b0002 with negotiated timeout 5000 for client /140.211.11.196:49890
[junit4:junit4]   2> 475 T1168 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:49886, sessionid = 0x139f2d4b51b0002, negotiated timeout = 5000
[junit4:junit4]   2> 475 T1169 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@491c1978 name:ZooKeeperConnection Watcher:127.0.0.1:49886/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 476 T1149 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 485 T1154 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139f2d4b51b0002 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 486 T1149 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 488 T1149 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49889_solr
[junit4:junit4]   2> 489 T1154 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139f2d4b51b0002 type:delete cxid:0x7 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:49889_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:49889_solr
[junit4:junit4]   2> 497 T1149 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49889_solr
[junit4:junit4]   2> 499 T1149 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 500 T1149 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 500 T1149 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 501 T1149 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 501 T1149 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 501 T1149 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 502 T1149 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 502 T1149 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 503 T1149 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 503 T1149 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 520 T1149 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 537 T1154 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139f2d4b51b0002 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> 545 T1149 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 554 T1149 oasc.Overseer.start Overseer (id=88368663095869442-127.0.0.1:49889_solr-n_0000000000) starting
[junit4:junit4]   2> 555 T1154 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139f2d4b51b0002 type:create cxid:0x1a zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 562 T1154 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139f2d4b51b0002 type:create cxid:0x1b zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 569 T1154 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139f2d4b51b0002 type:create cxid:0x1c zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 584 T1154 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139f2d4b51b0002 type:create cxid:0x1d zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 594 T1171 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 594 T1149 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 613 T1149 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 614 T1170 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 619 T1149 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1
[junit4:junit4]   2> 619 T1149 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 620 T1149 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 620 T1149 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 621 T1149 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4]   2> 623 T1149 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 623 T1149 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4]   2> 678 T1149 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4:junit4]   2> 773 T1149 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 875 T1149 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 886 T1149 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 1518 T1149 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 1526 T1149 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 1529 T1149 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 1538 T1149 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1542 T1149 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1545 T1149 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1546 T1149 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1547 T1149 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/control/data/
[junit4:junit4]   2> 1547 T1149 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6545d2
[junit4:junit4]   2> 1548 T1149 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/control/data/index/
[junit4:junit4]   2> 1549 T1149 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/control/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 1550 T1149 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/control/data/index forceNew:false
[junit4:junit4]   2> 1557 T1149 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2c394e3f; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 1557 T1149 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 1558 T1149 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 1559 T1149 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 1560 T1149 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 1560 T1149 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 1561 T1149 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 1561 T1149 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 1561 T1149 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 1562 T1149 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 1562 T1149 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 1563 T1149 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 1563 T1149 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 1563 T1149 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 1564 T1149 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 1564 T1149 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 1565 T1149 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 1565 T1149 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 1565 T1149 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 1566 T1149 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1566 T1149 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1567 T1149 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1567 T1149 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1567 T1149 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1568 T1149 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1568 T1149 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1569 T1149 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 1569 T1149 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 1572 T1149 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 1576 T1149 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 1576 T1149 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> 1580 T1149 oass.SolrIndexSearcher.<init> Opening Searcher@42a87dc0 main
[junit4:junit4]   2> 1581 T1149 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 1582 T1149 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 1582 T1149 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 1598 T1149 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 1658 T1172 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@42a87dc0 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 1661 T1154 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139f2d4b51b0002 type:create cxid:0x56 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer/queue Error:KeeperErrorCode = NoNode for /solr/overseer/queue
[junit4:junit4]   2> 1673 T1149 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 1674 T1149 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:49889/solr shardId:control_shard
[junit4:junit4]   2> 1675 T1149 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/control_shard/election
[junit4:junit4]   2> 1709 T1154 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139f2d4b51b0002 type:delete cxid:0x65 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/collections/control_collection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/control_collection/leaders
[junit4:junit4]   2> 1710 T1149 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 1711 T1154 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139f2d4b51b0002 type:create cxid:0x66 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2120 T1170 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2121 T1154 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139f2d4b51b0002 type:create cxid:0x6d zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer/queue-work Error:KeeperErrorCode = NoNode for /solr/overseer/queue-work
[junit4:junit4]   2> 2354 T1169 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 2714 T1149 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 2715 T1149 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 2715 T1149 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49889/solr/collection1/
[junit4:junit4]   2> 2716 T1149 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 2716 T1149 oasc.SyncStrategy.syncToMe http://127.0.0.1:49889/solr/collection1/ has no replicas
[junit4:junit4]   2> 2717 T1149 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49889/solr/collection1/
[junit4:junit4]   2> 2717 T1149 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/control_shard
[junit4:junit4]   2> 2734 T1154 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139f2d4b51b0002 type:create cxid:0x8b zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2867 T1170 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2881 T1169 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 2895 T1149 oasc.ZkController.register We are http://127.0.0.1:49889/solr/collection1/ and leader is http://127.0.0.1:49889/solr/collection1/
[junit4:junit4]   2> 2895 T1149 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49889/solr
[junit4:junit4]   2> 2896 T1149 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 2897 T1149 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2898 T1149 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1
[junit4:junit4]   2> 2899 T1149 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 2899 T1149 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 3074 T1149 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 3077 T1149 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:49893
[junit4:junit4]   2> 3078 T1149 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 3078 T1149 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty1-1348398792816
[junit4:junit4]   2> 3079 T1149 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty1-1348398792816/'
[junit4:junit4]   2> 3121 T1149 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 3121 T1149 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 3122 T1149 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty1-1348398792816
[junit4:junit4]   2> 3122 T1149 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty1-1348398792816/solr.xml
[junit4:junit4]   2> 3122 T1149 oasc.CoreContainer.<init> New CoreContainer 849874158
[junit4:junit4]   2> 3123 T1149 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty1-1348398792816/'
[junit4:junit4]   2> 3123 T1149 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty1-1348398792816/'
[junit4:junit4]   2> 3149 T1149 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 3164 T1149 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:49886/solr
[junit4:junit4]   2> 3165 T1149 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:49886/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@78bfe1f4
[junit4:junit4]   2> 3166 T1182 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:49886
[junit4:junit4]   2> 3166 T1149 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 3167 T1182 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:49886, initiating session
[junit4:junit4]   2> 3167 T1151 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:49894
[junit4:junit4]   2> 3167 T1151 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:49894
[junit4:junit4]   2> 3175 T1153 oazs.NIOServerCnxn.finishSessionInit Established session 0x139f2d4b51b0003 with negotiated timeout 5000 for client /140.211.11.196:49894
[junit4:junit4]   2> 3175 T1182 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:49886, sessionid = 0x139f2d4b51b0003, negotiated timeout = 5000
[junit4:junit4]   2> 3175 T1183 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@78bfe1f4 name:ZooKeeperConnection Watcher:127.0.0.1:49886/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3176 T1149 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 3176 T1154 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139f2d4b51b0003 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3183 T1154 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139f2d4b51b0003 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3191 T1149 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49893_solr
[junit4:junit4]   2> 3191 T1154 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139f2d4b51b0003 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:49893_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:49893_solr
[junit4:junit4]   2> 3197 T1149 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49893_solr
[junit4:junit4]   2> 3207 T1169 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 3208 T1149 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 3209 T1149 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 3209 T1149 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 3209 T1149 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 3210 T1149 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 3210 T1149 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 3211 T1149 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 3211 T1149 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 3212 T1149 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 3212 T1149 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 3229 T1149 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 3237 T1149 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty1-1348398792816/collection1
[junit4:junit4]   2> 3237 T1149 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 3238 T1149 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 3238 T1149 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 3239 T1149 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty1-1348398792816/collection1/'
[junit4:junit4]   2> 3241 T1149 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/solrtest-jetty1-1348398792816/collection1/lib/README' to classloader
[junit4:junit4]   2> 3242 T1149 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/solrtest-jetty1-1348398792816/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 3298 T1149 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4:junit4]   2> 3375 T1149 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 3385 T1170 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3398 T1169 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 3476 T1183 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 3476 T1149 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 3485 T1149 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 4067 T1149 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 4074 T1149 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 4077 T1149 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 4088 T1149 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 4092 T1149 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 4095 T1149 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 4096 T1149 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 4097 T1149 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty1-1348398792816/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty1/
[junit4:junit4]   2> 4097 T1149 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6545d2
[junit4:junit4]   2> 4099 T1149 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty1/index/
[junit4:junit4]   2> 4100 T1149 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 4100 T1149 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty1/index forceNew:false
[junit4:junit4]   2> 4114 T1149 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@1986793f; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 4114 T1149 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 4115 T1149 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 4117 T1149 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 4117 T1149 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 4117 T1149 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 4118 T1149 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 4118 T1149 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 4119 T1149 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 4119 T1149 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 4120 T1149 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 4120 T1149 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 4121 T1149 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 4121 T1149 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 4122 T1149 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 4122 T1149 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 4122 T1149 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 4123 T1149 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 4123 T1149 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 4124 T1149 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4124 T1149 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4125 T1149 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4125 T1149 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4125 T1149 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4126 T1149 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4126 T1149 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4127 T1149 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 4127 T1149 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 4130 T1149 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 4134 T1149 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 4135 T1149 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> 4138 T1149 oass.SolrIndexSearcher.<init> Opening Searcher@421d7ce3 main
[junit4:junit4]   2> 4139 T1149 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 4139 T1149 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 4140 T1149 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 4156 T1149 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 4237 T1184 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@421d7ce3 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 4404 T1170 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4418 T1183 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4418 T1169 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4744 T1149 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 4744 T1149 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:49893/solr shardId:shard1
[junit4:junit4]   2> 4745 T1149 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 4781 T1154 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139f2d4b51b0003 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> 4789 T1149 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 4789 T1154 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139f2d4b51b0003 type:create cxid:0x44 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4802 T1149 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 4802 T1149 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 4802 T1149 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49893/solr/collection1/
[junit4:junit4]   2> 4803 T1149 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 4803 T1149 oasc.SyncStrategy.syncToMe http://127.0.0.1:49893/solr/collection1/ has no replicas
[junit4:junit4]   2> 4803 T1149 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49893/solr/collection1/
[junit4:junit4]   2> 4803 T1149 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 4822 T1154 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139f2d4b51b0003 type:create cxid:0x4e zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4926 T1170 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4971 T1169 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4971 T1183 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4997 T1149 oasc.ZkController.register We are http://127.0.0.1:49893/solr/collection1/ and leader is http://127.0.0.1:49893/solr/collection1/
[junit4:junit4]   2> 4997 T1149 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49893/solr
[junit4:junit4]   2> 4997 T1149 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 4999 T1149 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4999 T1149 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1
[junit4:junit4]   2> 5000 T1149 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 5000 T1149 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 5122 T1149 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 5124 T1149 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:49895
[junit4:junit4]   2> 5125 T1149 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 5125 T1149 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty2-1348398794917
[junit4:junit4]   2> 5125 T1149 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty2-1348398794917/'
[junit4:junit4]   2> 5159 T1149 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 5159 T1149 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 5160 T1149 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty2-1348398794917
[junit4:junit4]   2> 5160 T1149 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty2-1348398794917/solr.xml
[junit4:junit4]   2> 5160 T1149 oasc.CoreContainer.<init> New CoreContainer 1103726303
[junit4:junit4]   2> 5161 T1149 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty2-1348398794917/'
[junit4:junit4]   2> 5161 T1149 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty2-1348398794917/'
[junit4:junit4]   2> 5177 T1149 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 5187 T1149 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:49886/solr
[junit4:junit4]   2> 5188 T1149 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:49886/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@4e57ca03
[junit4:junit4]   2> 5188 T1194 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:49886
[junit4:junit4]   2> 5188 T1149 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 5189 T1194 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:49886, initiating session
[junit4:junit4]   2> 5190 T1151 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:49896
[junit4:junit4]   2> 5190 T1151 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:49896
[junit4:junit4]   2> 5198 T1153 oazs.NIOServerCnxn.finishSessionInit Established session 0x139f2d4b51b0004 with negotiated timeout 5000 for client /140.211.11.196:49896
[junit4:junit4]   2> 5198 T1194 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:49886, sessionid = 0x139f2d4b51b0004, negotiated timeout = 5000
[junit4:junit4]   2> 5198 T1195 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4e57ca03 name:ZooKeeperConnection Watcher:127.0.0.1:49886/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 5198 T1149 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 5199 T1154 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139f2d4b51b0004 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 5212 T1154 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139f2d4b51b0004 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 5224 T1149 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49895_solr
[junit4:junit4]   2> 5225 T1154 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139f2d4b51b0004 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:49895_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:49895_solr
[junit4:junit4]   2> 5234 T1149 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49895_solr
[junit4:junit4]   2> 5241 T1169 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 5241 T1183 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 5242 T1149 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 5242 T1149 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 5242 T1149 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 5243 T1149 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 5243 T1149 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 5243 T1149 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 5244 T1149 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 5244 T1149 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 5244 T1149 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 5244 T1149 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 5258 T1149 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 5262 T1149 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty2-1348398794917/collection1
[junit4:junit4]   2> 5262 T1149 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 5262 T1149 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 5263 T1149 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 5263 T1149 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty2-1348398794917/collection1/'
[junit4:junit4]   2> 5264 T1149 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/solrtest-jetty2-1348398794917/collection1/lib/README' to classloader
[junit4:junit4]   2> 5265 T1149 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/solrtest-jetty2-1348398794917/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 5299 T1149 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4:junit4]   2> 5353 T1149 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 5453 T1149 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 5459 T1149 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 5478 T1170 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 5505 T1169 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5505 T1195 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5505 T1183 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6062 T1149 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 6071 T1149 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 6074 T1149 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 6083 T1149 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 6086 T1149 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 6090 T1149 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 6091 T1149 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 6092 T1149 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty2-1348398794917/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty2/
[junit4:junit4]   2> 6092 T1149 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6545d2
[junit4:junit4]   2> 6093 T1149 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty2/index/
[junit4:junit4]   2> 6094 T1149 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 6094 T1149 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty2/index forceNew:false
[junit4:junit4]   2> 6110 T1149 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@1ad405d8; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 6111 T1149 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 6112 T1149 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 6113 T1149 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 6114 T1149 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 6114 T1149 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 6114 T1149 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 6115 T1149 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 6115 T1149 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 6116 T1149 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 6116 T1149 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 6117 T1149 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 6117 T1149 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 6118 T1149 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 6118 T1149 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 6118 T1149 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 6119 T1149 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 6119 T1149 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 6120 T1149 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 6120 T1149 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6121 T1149 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6121 T1149 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6121 T1149 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6122 T1149 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6122 T1149 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6123 T1149 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6123 T1149 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 6124 T1149 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 6128 T1149 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 6133 T1149 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 6134 T1149 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> 6137 T1149 oass.SolrIndexSearcher.<init> Opening Searcher@3286a78b main
[junit4:junit4]   2> 6138 T1149 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 6139 T1149 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 6139 T1149 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 6160 T1149 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 6245 T1196 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3286a78b main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 6520 T1170 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6529 T1169 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6529 T1195 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6529 T1183 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6752 T1149 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 6752 T1149 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:49895/solr shardId:shard2
[junit4:junit4]   2> 6753 T1149 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4]   2> 6759 T1154 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139f2d4b51b0004 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> 6776 T1149 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 6777 T1154 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139f2d4b51b0004 type:create cxid:0x43 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 6779 T1149 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 6780 T1149 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 6780 T1149 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49895/solr/collection1/
[junit4:junit4]   2> 6781 T1149 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 6781 T1149 oasc.SyncStrategy.syncToMe http://127.0.0.1:49895/solr/collection1/ has no replicas
[junit4:junit4]   2> 6781 T1149 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49895/solr/collection1/
[junit4:junit4]   2> 6782 T1149 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4]   2> 6792 T1154 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139f2d4b51b0004 type:create cxid:0x4c zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7036 T1170 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7084 T1169 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7084 T1195 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7084 T1183 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7114 T1149 oasc.ZkController.register We are http://127.0.0.1:49895/solr/collection1/ and leader is http://127.0.0.1:49895/solr/collection1/
[junit4:junit4]   2> 7114 T1149 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49895/solr
[junit4:junit4]   2> 7115 T1149 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 7157 T1149 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7158 T1149 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1
[junit4:junit4]   2> 7158 T1149 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 7159 T1149 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 7318 T1149 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 7321 T1149 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:49898
[junit4:junit4]   2> 7321 T1149 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 7322 T1149 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty3-1348398797075
[junit4:junit4]   2> 7322 T1149 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty3-1348398797075/'
[junit4:junit4]   2> 7356 T1149 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 7356 T1149 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 7357 T1149 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty3-1348398797075
[junit4:junit4]   2> 7357 T1149 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty3-1348398797075/solr.xml
[junit4:junit4]   2> 7357 T1149 oasc.CoreContainer.<init> New CoreContainer 805681374
[junit4:junit4]   2> 7358 T1149 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty3-1348398797075/'
[junit4:junit4]   2> 7358 T1149 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty3-1348398797075/'
[junit4:junit4]   2> 7382 T1149 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 7397 T1149 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:49886/solr
[junit4:junit4]   2> 7398 T1149 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:49886/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@712a6bc7
[junit4:junit4]   2> 7399 T1206 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:49886
[junit4:junit4]   2> 7399 T1149 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 7400 T1206 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:49886, initiating session
[junit4:junit4]   2> 7400 T1151 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:49899
[junit4:junit4]   2> 7400 T1151 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:49899
[junit4:junit4]   2> 7406 T1153 oazs.NIOServerCnxn.finishSessionInit Established session 0x139f2d4b51b0005 with negotiated timeout 5000 for client /140.211.11.196:49899
[junit4:junit4]   2> 7406 T1206 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:49886, sessionid = 0x139f2d4b51b0005, negotiated timeout = 5000
[junit4:junit4]   2> 7406 T1207 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@712a6bc7 name:ZooKeeperConnection Watcher:127.0.0.1:49886/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 7407 T1149 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 7409 T1154 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139f2d4b51b0005 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7418 T1154 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139f2d4b51b0005 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7419 T1149 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49898_solr
[junit4:junit4]   2> 7420 T1154 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139f2d4b51b0005 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:49898_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:49898_solr
[junit4:junit4]   2> 7426 T1149 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49898_solr
[junit4:junit4]   2> 7428 T1195 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 7428 T1169 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 7428 T1183 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 7429 T1149 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 7429 T1149 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 7429 T1149 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 7430 T1149 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 7430 T1149 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 7431 T1149 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 7431 T1149 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 7432 T1149 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 7433 T1149 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 7433 T1149 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 7459 T1149 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 7468 T1149 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty3-1348398797075/collection1
[junit4:junit4]   2> 7469 T1149 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 7470 T1149 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 7471 T1149 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 7472 T1149 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty3-1348398797075/collection1/'
[junit4:junit4]   2> 7474 T1149 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/solrtest-jetty3-1348398797075/collection1/lib/README' to classloader
[junit4:junit4]   2> 7475 T1149 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/solrtest-jetty3-1348398797075/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 7553 T1149 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4:junit4]   2> 7634 T1149 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 7658 T1170 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7672 T1195 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7672 T1169 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7672 T1183 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7735 T1207 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7735 T1149 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 7743 T1149 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 8403 T1149 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 8415 T1149 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 8420 T1149 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 8491 T1149 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 8497 T1149 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 8501 T1149 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 8502 T1149 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 8503 T1149 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty3-1348398797075/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty3/
[junit4:junit4]   2> 8504 T1149 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6545d2
[junit4:junit4]   2> 8505 T1149 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty3/index/
[junit4:junit4]   2> 8506 T1149 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 8507 T1149 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty3/index forceNew:false
[junit4:junit4]   2> 8528 T1149 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty3/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@45e1feaf; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 8528 T1149 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 8529 T1149 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 8532 T1149 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 8532 T1149 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 8533 T1149 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 8533 T1149 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 8534 T1149 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 8535 T1149 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 8535 T1149 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 8536 T1149 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 8537 T1149 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 8538 T1149 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 8538 T1149 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 8539 T1149 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 8540 T1149 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 8540 T1149 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 8541 T1149 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 8541 T1149 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 8542 T1149 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8543 T1149 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8544 T1149 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8544 T1149 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8545 T1149 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8546 T1149 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8546 T1149 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8547 T1149 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 8548 T1149 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 8552 T1149 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 8556 T1149 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 8557 T1149 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> 8562 T1149 oass.SolrIndexSearcher.<init> Opening Searcher@d207f78 main
[junit4:junit4]   2> 8563 T1149 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 8563 T1149 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 8564 T1149 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 8581 T1149 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 8645 T1208 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@d207f78 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 8677 T1170 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8687 T1207 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8687 T1195 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8687 T1183 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8687 T1169 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9153 T1149 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 9153 T1149 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:49898/solr shardId:shard1
[junit4:junit4]   2> 9156 T1149 oasc.ZkController.register We are http://127.0.0.1:49898/solr/collection1/ and leader is http://127.0.0.1:49893/solr/collection1/
[junit4:junit4]   2> 9157 T1149 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49898/solr
[junit4:junit4]   2> 9157 T1149 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 9157 T1149 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C64 name=collection1 org.apache.solr.core.SolrCore@50ed98e6 url=http://127.0.0.1:49898/solr/collection1 node=127.0.0.1:49898_solr
[junit4:junit4]   2> 9158 T1209 C64 P49898 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 9159 T1149 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9159 T1209 C64 P49898 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 9160 T1149 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1
[junit4:junit4]   2> 9160 T1149 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 9160 T1209 C64 P49898 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:49893/solr/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 9161 T1209 C64 P49898 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:49898/solr START replicas=[http://127.0.0.1:49893/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 9161 T1149 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 9161 T1209 C64 P49898 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 9161 T1209 C64 P49898 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 9162 T1209 C64 P49898 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 9162 T1209 C64 P49898 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C65 name=collection1 org.apache.solr.core.SolrCore@1c589d49 url=http://127.0.0.1:49893/solr/collection1 node=127.0.0.1:49893_solr
[junit4:junit4]   2> 9172 T1175 C65 P49893 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=0 
[junit4:junit4]   2> 9197 T1170 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9219 T1195 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9219 T1207 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9219 T1183 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9219 T1169 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9334 T1149 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 9336 T1149 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:49903
[junit4:junit4]   2> 9337 T1149 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 9338 T1149 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty4-1348398799084
[junit4:junit4]   2> 9338 T1149 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty4-1348398799084/'
[junit4:junit4]   2> 9380 T1149 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 9380 T1149 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 9381 T1149 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty4-1348398799084
[junit4:junit4]   2> 9381 T1149 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty4-1348398799084/solr.xml
[junit4:junit4]   2> 9381 T1149 oasc.CoreContainer.<init> New CoreContainer 1978327804
[junit4:junit4]   2> 9382 T1149 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty4-1348398799084/'
[junit4:junit4]   2> 9382 T1149 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty4-1348398799084/'
[junit4:junit4]   2> 9407 T1149 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 9422 T1149 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:49886/solr
[junit4:junit4]   2> 9423 T1149 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:49886/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@47b77e9b
[junit4:junit4]   2> 9424 T1220 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:49886
[junit4:junit4]   2> 9424 T1149 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 9425 T1220 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:49886, initiating session
[junit4:junit4]   2> 9425 T1151 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:49904
[junit4:junit4]   2> 9425 T1151 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:49904
[junit4:junit4]   2> 9430 T1153 oazs.NIOServerCnxn.finishSessionInit Established session 0x139f2d4b51b0006 with negotiated timeout 5000 for client /140.211.11.196:49904
[junit4:junit4]   2> 9430 T1220 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:49886, sessionid = 0x139f2d4b51b0006, negotiated timeout = 5000
[junit4:junit4]   2> 9430 T1221 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@47b77e9b name:ZooKeeperConnection Watcher:127.0.0.1:49886/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 9430 T1149 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 9431 T1154 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139f2d4b51b0006 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 9438 T1154 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139f2d4b51b0006 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 9446 T1149 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49903_solr
[junit4:junit4]   2> 9447 T1154 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139f2d4b51b0006 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:49903_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:49903_solr
[junit4:junit4]   2> 9451 T1149 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49903_solr
[junit4:junit4]   2> 9460 T1195 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 9460 T1169 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 9460 T1183 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 9460 T1207 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 9461 T1149 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 9462 T1149 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 9462 T1149 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 9462 T1149 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 9463 T1149 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 9463 T1149 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 9464 T1149 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 9464 T1149 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 9464 T1149 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 9465 T1149 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 9483 T1149 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 9489 T1149 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty4-1348398799084/collection1
[junit4:junit4]   2> 9490 T1149 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 9490 T1149 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 9491 T1149 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 9492 T1149 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty4-1348398799084/collection1/'
[junit4:junit4]   2> 9493 T1149 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/solrtest-jetty4-1348398799084/collection1/lib/README' to classloader
[junit4:junit4]   2> 9494 T1149 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/solrtest-jetty4-1348398799084/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 9546 T1149 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_41
[junit4:junit4]   2> 9616 T1149 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 9717 T1149 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 9725 T1149 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 10385 T1149 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 10400 T1149 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 10404 T1149 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 10416 T1149 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 10421 T1149 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 10425 T1149 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 10427 T1149 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 10428 T1149 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty4-1348398799084/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty4/
[junit4:junit4]   2> 10428 T1149 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6545d2
[junit4:junit4]   2> 10429 T1149 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty4/index/
[junit4:junit4]   2> 10430 T1149 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 10431 T1149 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty4/index forceNew:false
[junit4:junit4]   2> 10450 T1149 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@d5d7396; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 10450 T1149 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 10451 T1149 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 10454 T1149 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 10455 T1149 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 10455 T1149 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 10456 T1149 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 10456 T1149 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 10457 T1149 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 10457 T1149 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 10458 T1149 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 10459 T1149 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 10460 T1149 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 10460 T1149 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 10461 T1149 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 10462 T1149 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 10462 T1149 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 10463 T1149 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 10463 T1149 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 10464 T1149 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10465 T1149 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10465 T1149 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10466 T1149 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10467 T1149 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10468 T1149 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10468 T1149 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10469 T1149 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 10470 T1149 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 10473 T1149 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 10478 T1149 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 10480 T1149 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> 10484 T1149 oass.SolrIndexSearcher.<init> Opening Searcher@1d15256d main
[junit4:junit4]   2> 10485 T1149 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 10486 T1149 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 10486 T1149 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 10504 T1149 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 10608 T1222 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1d15256d main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 10731 T1170 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 10770 T1183 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10770 T1169 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10770 T1221 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10770 T1195 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10770 T1207 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11126 T1149 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 11126 T1149 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:49903/solr shardId:shard2
[junit4:junit4]   2> 11130 T1149 oasc.ZkController.register We are http://127.0.0.1:49903/solr/collection1/ and leader is http://127.0.0.1:49895/solr/collection1/
[junit4:junit4]   2> 11130 T1149 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49903/solr
[junit4:junit4]   2> 11131 T1149 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 11131 T1149 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C66 name=collection1 org.apache.solr.core.SolrCore@289e637e url=http://127.0.0.1:49903/solr/collection1 node=127.0.0.1:49903_solr
[junit4:junit4]   2> 11132 T1223 C66 P49903 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 11133 T1223 C66 P49903 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 11132 T1149 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 11136 T1223 C66 P49903 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:49895/solr/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 11136 T1223 C66 P49903 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:49903/solr START replicas=[http://127.0.0.1:49895/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 11136 T1149 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1
[junit4:junit4]   2> 11136 T1223 C66 P49903 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 11136 T1149 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 11137 T1223 C66 P49903 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 11137 T1223 C66 P49903 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 11137 T1149 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 11137 T1223 C66 P49903 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C67 name=collection1 org.apache.solr.core.SolrCore@1e7ecd65 url=http://127.0.0.1:49895/solr/collection1 node=127.0.0.1:49895_solr
[junit4:junit4]   2> 11147 T1187 C67 P49895 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=1 
[junit4:junit4]   2> 11161 T1149 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:49886/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@74b9a768
[junit4:junit4]   2> 11163 T1225 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:49886
[junit4:junit4]   2> 11163 T1149 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 11163 T1225 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:49886, initiating session
[junit4:junit4]   2> 11164 T1151 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:49911
[junit4:junit4]   2> 11164 T1151 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:49911
[junit4:junit4]   2> 11172 T1153 oazs.NIOServerCnxn.finishSessionInit Established session 0x139f2d4b51b0007 with negotiated timeout 10000 for client /140.211.11.196:49911
[junit4:junit4]   2> 11173 T1225 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:49886, sessionid = 0x139f2d4b51b0007, negotiated timeout = 10000
[junit4:junit4]   2> 11173 T1226 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@74b9a768 name:ZooKeeperConnection Watcher:127.0.0.1:49886/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 11173 T1149 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 11174 T1149 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 11175 T1149 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   2> 11176 T1149 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 11186 T1149 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> ASYNC  NEW_CORE C68 name=collection1 org.apache.solr.core.SolrCore@4aac53a8 url=http://127.0.0.1:49889/solr/collection1 node=127.0.0.1:49889_solr
[junit4:junit4]   2> 11199 T1161 C68 P49889 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2c394e3f; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 11200 T1161 C68 P49889 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 11205 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[1 (1413898621260136448)]} 0 11
[junit4:junit4]   2> 11206 T1149 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:49886/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@4ddc7d76
[junit4:junit4]   2> 11207 T1227 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:49886
[junit4:junit4]   2> 11207 T1149 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 11207 T1227 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:49886, initiating session
[junit4:junit4]   2> 11208 T1151 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:49913
[junit4:junit4]   2> 11208 T1151 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:49913
[junit4:junit4]   2> 11210 T1153 oazs.NIOServerCnxn.finishSessionInit Established session 0x139f2d4b51b0008 with negotiated timeout 10000 for client /140.211.11.196:49913
[junit4:junit4]   2> 11210 T1227 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:49886, sessionid = 0x139f2d4b51b0008, negotiated timeout = 10000
[junit4:junit4]   2> 11210 T1228 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4ddc7d76 name:ZooKeeperConnection Watcher:127.0.0.1:49886/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 11210 T1149 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 11211 T1149 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 11221 T1177 C65 P49893 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@1986793f; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 11222 T1177 C65 P49893 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2>  C64_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:49898_solr, base_url=http://127.0.0.1:49898/solr}
[junit4:junit4]   2> 11241 T1199 C64 P49898 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty3/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@45e1feaf; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 11242 T1199 C64 P49898 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 11247 T1199 C64 P49898 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49893/solr/collection1/&wt=javabin&version=2} status=0 QTime=10 
[junit4:junit4]   2> 11247 T1177 C65 P49893 REQ /update {distrib.from=http://127.0.0.1:49895/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=31 
[junit4:junit4]   2> 11248 T1189 C67 P49895 /update {wt=javabin&version=2} {add=[1]} 0 34
[junit4:junit4]   2> 11249 T1149 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):1800
[junit4:junit4]   2> 11250 T1149 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 11274 T1170 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 11292 T1221 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11292 T1183 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11292 T1195 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11292 T1169 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11292 T1207 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11292 T1226 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11292 T1228 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12185 T1209 C64 P49898 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 12185 T1209 C64 P49898 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=tlog{file=./org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty3/tlog/tlog.0000000000000000000 refcount=1}}
[junit4:junit4]   2> 12185 T1209 C64 P49898 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:49893/solr/collection1/. core=collection1
[junit4:junit4]   2> 12185 T1209 C64 P49898 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 12201 T1178 C65 P49893 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 12251 T1149 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12424 T1178 C65 P49893 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@1986793f; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@1986793f; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0_Asserting_0.tim, _0_Lucene40_0.tim, _0.fnm, _0_Asserting_0.tip, _0_Memory_0.ram, _0_MockFixedIntBlock_0.pos, _0_nrm.cfs, _0_MockFixedIntBlock_0.tib, _0_Lucene40_0.prx, _0_Lucene40_0.tip, _0_Asserting_0.prx, _0_MockFixedIntBlock_0.frq, _0_Asserting_0.frq, _0_MockFixedIntBlock_0.pyl, _0_MockFixedIntBlock_0.skp, _0_Lucene40_0.frq, _0_MockFixedIntBlock_0.doc, _0_MockFixedIntBlock_0.tii, _0_nrm.cfe, segments_2, _0.fdx, _0.si, _0.fdt]
[junit4:junit4]   2> 12425 T1178 C65 P49893 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 12439 T1178 C65 P49893 oass.SolrIndexSearcher.<init> Opening Searcher@6fcbba0c main
[junit4:junit4]   2> 12440 T1178 C65 P49893 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 12442 T1184 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6fcbba0c main{StandardDirectoryReader(segments_2:3 _0(4.1):C1)}
[junit4:junit4]   2> 12442 T1178 C65 P49893 /update {waitSearcher=true&commit=true&commit_end_point=true&wt=javabin&softCommit=false&version=2} {commit=} 0 241
[junit4:junit4]   2> 12444 T1209 C64 P49898 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 12444 T1209 C64 P49898 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 12447 T1179 C65 P49893 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 12447 T1179 C65 P49893 REQ /replication {command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
[junit4:junit4]   2> 12448 T1209 C64 P49898 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4]   2> 12448 T1209 C64 P49898 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 12448 T1209 C64 P49898 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 12453 T1179 C65 P49893 REQ /replication {command=filelist&generation=2&wt=javabin&qt=/replication&version=2} status=0 QTime=3 
[junit4:junit4]   2> 12455 T1209 C64 P49898 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 23
[junit4:junit4]   2> 12463 T1209 C64 P49898 oash.SnapPuller.fetchLatestIndex Starting download to ./org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty3/index.20120923201322358 fullCopy=true
[junit4:junit4]   2> 12477 T1179 C65 P49893 REQ /replication {file=_0_Asserting_0.tim&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=5 
[junit4:junit4]   2> 12487 T1179 C65 P49893 REQ /replication {file=_0_Lucene40_0.tim&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12493 T1179 C65 P49893 REQ /replication {file=_0.fnm&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12497 T1179 C65 P49893 REQ /replication {file=_0_Asserting_0.tip&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12501 T1179 C65 P49893 REQ /replication {file=_0_Memory_0.ram&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12505 T1179 C65 P49893 REQ /replication {file=_0_MockFixedIntBlock_0.pos&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12509 T1179 C65 P49893 REQ /replication {file=_0_nrm.cfs&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12513 T1179 C65 P49893 REQ /replication {file=_0_Lucene40_0.prx&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12517 T1179 C65 P49893 REQ /replication {file=_0_MockFixedIntBlock_0.tib&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12521 T1179 C65 P49893 REQ /replication {file=_0_Lucene40_0.tip&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12525 T1179 C65 P49893 REQ /replication {file=_0_MockFixedIntBlock_0.frq&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12529 T1179 C65 P49893 REQ /replication {file=_0_Asserting_0.prx&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12533 T1179 C65 P49893 REQ /replication {file=_0_Asserting_0.frq&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12537 T1179 C65 P49893 REQ /replication {file=_0_MockFixedIntBlock_0.skp&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12538 T1209 C64 P49898 oash.SnapPuller$FileFetcher.fetchPackets WARNING No content recieved for file: {name=_0_MockFixedIntBlock_0.skp, lastmodified=1348398802000, size=0}
[junit4:junit4]   2> 12541 T1179 C65 P49893 REQ /replication {file=_0_MockFixedIntBlock_0.pyl&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12542 T1209 C64 P49898 oash.SnapPuller$FileFetcher.fetchPackets WARNING No content recieved for file: {name=_0_MockFixedIntBlock_0.pyl, lastmodified=1348398802000, size=0}
[junit4:junit4]   2> 12545 T1179 C65 P49893 REQ /replication {file=_0_Lucene40_0.frq&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12549 T1179 C65 P49893 REQ /replication {file=_0_MockFixedIntBlock_0.tii&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12553 T1179 C65 P49893 REQ /replication {file=_0_MockFixedIntBlock_0.doc&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12557 T1179 C65 P49893 REQ /replication {file=_0_nrm.cfe&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12561 T1179 C65 P49893 REQ /replication {file=segments_2&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12565 T1179 C65 P49893 REQ /replication {file=_0.fdx&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12569 T1179 C65 P49893 REQ /replication {file=_0.si&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12573 T1179 C65 P49893 REQ /replication {file=_0.fdt&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12574 T1209 C64 P49898 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 12592 T1209 C64 P49898 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20120923201322358
[junit4:junit4]   2> 12598 T1209 C64 P49898 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 12598 T1209 C64 P49898 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 12598 T1209 C64 P49898 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4]   2> 12602 T1209 C64 P49898 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=./org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty3/index/ new=./org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty3/index.20120923201322358
[junit4:junit4]   2> 12603 T1209 C64 P49898 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty3/index.20120923201322358 forceNew:true
[junit4:junit4]   2> 12613 T1209 C64 P49898 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty3/index.20120923201322358 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3a23fcd2; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0_Asserting_0.tim, _0_Lucene40_0.tim, _0.fnm, _0_Asserting_0.tip, _0_Memory_0.ram, _0_MockFixedIntBlock_0.pos, _0_nrm.cfs, _0_MockFixedIntBlock_0.tib, _0_Lucene40_0.prx, _0_Lucene40_0.tip, _0_Asserting_0.prx, _0_MockFixedIntBlock_0.frq, _0_Asserting_0.frq, _0_MockFixedIntBlock_0.skp, _0_MockFixedIntBlock_0.pyl, _0_Lucene40_0.frq, _0_MockFixedIntBlock_0.tii, _0_MockFixedIntBlock_0.doc, _0_nrm.cfe, segments_2, _0.fdx, _0.si, _0.fdt]
[junit4:junit4]   2> 12614 T1209 C64 P49898 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 12614 T1209 C64 P49898 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 12619 T1209 C64 P49898 oass.SolrIndexSearcher.<init> Opening Searcher@1aa5c9d main
[junit4:junit4]   2> 12621 T1208 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1aa5c9d main{StandardDirectoryReader(segments_2:3:nrt _0(4.1):C1)}
[junit4:junit4]   2> 12621 T1208 oasc.CachingDirectoryFactory.close Closing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty3/index
[junit4:junit4]   2> 12622 T1208 oash.SnapPuller$2.onClose removing old index directory ./org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty3/index
[junit4:junit4]   2> 12623 T1209 C64 P49898 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=false,waitSearcher=false,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 12624 T1209 C64 P49898 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 12625 T1209 C64 P49898 oasc.RecoveryStrategy.replay Replaying buffered documents. core=collection1
[junit4:junit4]   2> 12625 T1232 C64 P49898 oasu.UpdateLog$LogReplayer.doReplay WARNING Starting log replay tlog{file=./org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty3/tlog/tlog.0000000000000000000 refcount=2} active=true starting pos=432
[junit4:junit4]   2> 12625 T1232 C64 P49898 oasu.DirectUpdateHandler2.commit start commit{flags=2,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 12627 T1232 C64 P49898 oass.SolrIndexSearcher.<init> Opening Searcher@64424952 main
[junit4:junit4]   2> 12627 T1232 C64 P49898 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 12629 T1208 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@64424952 main{StandardDirectoryReader(segments_2:3:nrt _0(4.1):C1)}
[junit4:junit4]   2> 12629 T1232 C64 P49898 oasu.UpdateLog$LogReplayer.run WARNING Log replay finished. recoveryInfo=RecoveryInfo{adds=0 deletes=0 deleteByQuery=0 errors=0 positionOfStart=432}
[junit4:junit4]   2> 12629 T1209 C64 P49898 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 12631 T1209 C64 P49898 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 12804 T1170 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12825 T1207 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12825 T1228 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12825 T1169 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12825 T1226 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12825 T1195 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12825 T1183 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12825 T1221 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 13253 T1149 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2>  C66_STATE=coll:collection1 core:collection1 props:{shard=shard2, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:49903_solr, base_url=http://127.0.0.1:49903/solr}
[junit4:junit4]   2> 14164 T1223 C66 P49903 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 14164 T1223 C66 P49903 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 14164 T1223 C66 P49903 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:49895/solr/collection1/. core=collection1
[junit4:junit4]   2> 14165 T1223 C66 P49903 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 14181 T1190 C67 P49895 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 14188 T1190 C67 P49895 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@1ad405d8; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 14188 T1190 C67 P49895 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 14190 T1190 C67 P49895 oass.SolrIndexSearcher.<init> Opening Searcher@25536e21 main
[junit4:junit4]   2> 14191 T1190 C67 P49895 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 14192 T1196 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@25536e21 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 14193 T1190 C67 P49895 /update {waitSearcher=true&commit=true&commit_end_point=true&wt=javabin&softCommit=false&version=2} {commit=} 0 12
[junit4:junit4]   2> 14194 T1223 C66 P49903 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 14194 T1223 C66 P49903 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 14197 T1191 C67 P49895 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 14197 T1191 C67 P49895 REQ /replication {command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
[junit4:junit4]   2> 14203 T1223 C66 P49903 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@d5d7396; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 14203 T1223 C66 P49903 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 14204 T1223 C66 P49903 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 14219 T1223 C66 P49903 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@d5d7396; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@d5d7396; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 14220 T1223 C66 P49903 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 14223 T1223 C66 P49903 oass.SolrIndexSearcher.<init> Opening Searcher@9138297 main
[junit4:junit4]   2> 14223 T1223 C66 P49903 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 14225 T1222 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@9138297 main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 14225 T1223 C66 P49903 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 14225 T1223 C66 P49903 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 14228 T1223 C66 P49903 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 14255 T1149 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 14338 T1170 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 14364 T1221 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14364 T1226 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14364 T1207 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14364 T1195 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14364 T1228 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14364 T1169 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14364 T1183 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 15257 T1149 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 15260 T1161 C68 P49889 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 15339 T1161 C68 P49889 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2c394e3f; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348398789908/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2c394e3f; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0_Asserting_0.tim, _0_Lucene40_0.tim, _0.fnm, _0_Asserting_0.tip, _0_Memory_0.ram, _0_MockFixedIntBlock_0.pos, _0_nrm.cfs, _0_MockFixedIntBlock_0.tib, _0_Lucene40_0.prx, _0_Lucene40_0.tip, _0_Asserting_0.prx, _0_MockFixedIntBlock_0.frq, _0_Asserting_0.frq, _0_MockFixedIntBlock_0.pyl, _0_MockFixedIntBlock_0.skp, _0_Lucene40_0.frq, _0_MockFixedIntBlock_0.doc, _0_MockFixedIntBlock_0.tii, _0_nrm.cfe, segments_2, _0.fdx, _0.si, _0.fdt]
[junit4:junit4]   2> 15340 T1161 C68 P49889 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 15360 T1161 C68 P49889 oass.SolrIndexSearcher.<init> Opening Searcher@66331c28 main
[junit4:junit4]   2> 15361 T1161 C68 P49889 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 15362 T1172 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@66331c28 main{StandardDirectoryReader(segments_2:3 _0(4.1):C1)}
[junit4:junit4]   2> 15363 T1161 C68 P49889 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 103
[junit4:junit4]   2> 15366 T1180 C65 P49893 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 15380 T1180 C65 P49893 oass.SolrIndexSearcher.<init> Opening Searcher@41b21326 main
[junit4:junit4]   2> 15381 T1180 C65 P49893 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 15382 T1184 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@41b21326 main{StandardDirectoryReader(segments_2:3 _0(4.1):C1)}
[junit4:junit4]   2> 15383 T1180 C65 P49893 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:49898/solr/collection1/, StdNode: http://127.0.0.1:49895/solr/collection1/, StdNode: http://127.0.0.1:49903/solr/collection1/]
[junit4:junit4]   2>  C64_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:49898_solr, base_url=http://127.0.0.1:49898/solr}
[junit4:junit4]   2> 15386 T1199 C64 P49898 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 15386 T1192 C67 P49895 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 15389 T1199 C64 P49898 oass.SolrIndexSearcher.<init> Opening Searcher@bc3ae3 main
[junit4:junit4]   2> 15390 T1199 C64 P49898 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 15391 T1208 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@bc3ae3 main{StandardDirectoryReader(segments_2:3:nrt _0(4.1):C1)}
[junit4:junit4]   2> 15391 T1199 C64 P49898 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&expungeDeletes=false&softCommit=false&version=2} {commit=} 0 5
[junit4:junit4]   2> 15393 T1192 C67 P49895 oass.SolrIndexSearcher.<init> Opening Searcher@4065a018 main
[junit4:junit4]   2> 15393 T1192 C67 P49895 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 15395 T1196 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4065a018 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 15395 T1192 C67 P49895 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&expungeDeletes=false&softCommit=false&version=2} {commit=} 0 10
[junit4:junit4]   2>  C66_STATE=coll:collection1 core:collection1 props:{shard=shard2, roles=null, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:49903_solr, base_url=http://127.0.0.1:49903/solr}
[junit4:junit4]   2> 15399 T1213 C66 P49903 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 15403 T1213 C66 P49903 oass.SolrIndexSearcher.<init> Opening Searcher@68a53237 main
[junit4:junit4]   2> 15404 T1213 C66 P49903 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 15405 T1222 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@68a53237 main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 15405 T1213 C66 P49903 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&expungeDeletes=false&softCommit=false&version=2} {commit=} 0 6
[junit4:junit4]   2> 15406 T1180 C65 P49893 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 41
[junit4:junit4]   2> 15412 T1162 C68 P49889 REQ /select {fl=id,score&shard.url=127.0.0.1:49889/solr/collection1/&NOW=1348398805312&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 15417 T1162 C68 P49889 REQ /select {shard.url=127.0.0.1:49889/solr/collection1/&NOW=1348398805312&q=*:*&ids=1&distrib=false&isShard=true&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15418 T1161 C68 P49889 REQ /select {wt=javabin&q=*:*&version=2} hits=1 status=0 QTime=9 
[junit4:junit4]   2> 15418 T1149 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:49886/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@2d9d4f83
[junit4:junit4]   2> 15419 T1236 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:49886
[junit4:junit4]   2> 15419 T1149 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 15420 T1236 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:49886, initiating session
[junit4:junit4]   2> 15420 T1151 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:49926
[junit4:junit4]   2> 15421 T1151 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:49926
[junit4:junit4]   2> 15429 T1153 oazs.NIOServerCnxn.finishSessionInit Established session 0x139f2d4b51b0009 with negotiated timeout 10000 for client /140.211.11.196:49926
[junit4:junit4]   2> 15429 T1236 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:49886, sessionid = 0x139f2d4b51b0009, negotiated timeout = 10000
[junit4:junit4]   2> 15430 T1237 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2d9d4f83 name:ZooKeeperConnection Watcher:127.0.0.1:49886/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 15430 T1149 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 15430 T1149 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 15432 T1154 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x139f2d4b51b0009
[junit4:junit4]   2> 15438 T1237 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 15437 T1149 oaz.ZooKeeper.close Session: 0x139f2d4b51b0009 closed
[junit4:junit4]   2> 15438 T1151 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:49926 which had sessionid 0x139f2d4b51b0009
[junit4:junit4]   2> 15440 T1181 C65 P49893 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 15443 T1193 C67 P49895 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 15449 T1200 C64 P49898 REQ /select {fl=id,score&shard.url=127.0.0.1:49893/solr/collection1/|127.0.0.1:49898/solr/collection1/&NOW=1348398805349&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 15449 T1188 C67 P49895 REQ /select {fl=id,score&shard.url=127.0.0.1:49895/solr/collection1/|127.0.0.1:49903/solr/collection1/&NOW=1348398805349&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 15453 T1200 C64 P49898 REQ /select {shard.url=127.0.0.1:49893/solr/collection1/|127.0.0.1:49898/solr/collection1/&NOW=1348398805349&q=*:*&ids=1&distrib=false&isShard=true&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15453 T1189 C67 P49895 REQ /select {wt=javabin&q=*:*&version=2} hits=1 status=0 QTime=7 
[junit4:junit4]   2> 15461 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[2 (1413898625729167360)]} 0 4
[junit4:junit4]   2> 15478 T1213 C66 P49903 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49895/solr/collection1/&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 15479 T1192 C67 P49895 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=12 
[junit4:junit4]   2> 15479 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[2]} 0 15
[junit4:junit4]   2> 15484 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[3 (1413898625755381760)]} 0 2
[junit4:junit4]   2> 15495 T1213 C66 P49903 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49895/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15495 T1192 C67 P49895 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 15496 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[3]} 0 9
[junit4:junit4]   2> 15501 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[4 (1413898625773207552)]} 0 2
[junit4:junit4]   2> 15516 T1199 C64 P49898 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 15517 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[4 (1413898625778450432)]} 0 13
[junit4:junit4]   2> 15522 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[5 (1413898625795227648)]} 0 2
[junit4:junit4]   2> 15534 T1213 C66 P49903 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49895/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15535 T1192 C67 P49895 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 15535 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[5]} 0 10
[junit4:junit4]   2> 15540 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[6 (1413898625815150592)]} 0 2
[junit4:junit4]   2> 15553 T1213 C66 P49903 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49895/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15554 T1192 C67 P49895 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=8 
[junit4:junit4]   2> 15555 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[6]} 0 12
[junit4:junit4]   2> 15560 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[7 (1413898625835073536)]} 0 2
[junit4:junit4]   2> 15579 T1213 C66 P49903 REQ /update {distrib.from=http://127.0.0.1:49895/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15580 T1189 C67 P49895 /update {wt=javabin&version=2} {add=[7 (1413898625840316416)]} 0 17
[junit4:junit4]   2> 15585 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[8 (1413898625861287936)]} 0 2
[junit4:junit4]   2> 15596 T1199 C64 P49898 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49893/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15596 T1177 C65 P49893 REQ /update {distrib.from=http://127.0.0.1:49895/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 15597 T1189 C67 P49895 /update {wt=javabin&version=2} {add=[8]} 0 10
[junit4:junit4]   2> 15602 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[9 (1413898625879113728)]} 0 2
[junit4:junit4]   2> 15612 T1213 C66 P49903 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49895/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15612 T1192 C67 P49895 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 15613 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[9]} 0 9
[junit4:junit4]   2> 15617 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[10 (1413898625895890944)]} 0 1
[junit4:junit4]   2> 15628 T1199 C64 P49898 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49893/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15628 T1177 C65 P49893 REQ /update {distrib.from=http://127.0.0.1:49895/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 15629 T1189 C67 P49895 /update {wt=javabin&version=2} {add=[10]} 0 9
[junit4:junit4]   2> 15649 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[11 (1413898625912668160)]} 0 17
[junit4:junit4]   2> 15658 T1199 C64 P49898 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15658 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[11 (1413898625933639680)]} 0 6
[junit4:junit4]   2> 15664 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[12 (1413898625943076864)]} 0 3
[junit4:junit4]   2> 15673 T1199 C64 P49898 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15673 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[12 (1413898625949368320)]} 0 6
[junit4:junit4]   2> 15678 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[13 (1413898625958805504)]} 0 2
[junit4:junit4]   2> 15686 T1199 C64 P49898 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15687 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[13 (1413898625962999808)]} 0 7
[junit4:junit4]   2> 15692 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[14 (1413898625973485568)]} 0 2
[junit4:junit4]   2> 15700 T1199 C64 P49898 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15700 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[14 (1413898625977679872)]} 0 6
[junit4:junit4]   2> 15704 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[15 (1413898625987117056)]} 0 1
[junit4:junit4]   2> 15716 T1199 C64 P49898 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49893/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15717 T1177 C65 P49893 REQ /update {distrib.from=http://127.0.0.1:49895/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 15717 T1189 C67 P49895 /update {wt=javabin&version=2} {add=[15]} 0 10
[junit4:junit4]   2> 15722 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[16 (1413898626004942848)]} 0 2
[junit4:junit4]   2> 15730 T1199 C64 P49898 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15731 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[16 (1413898626009137152)]} 0 7
[junit4:junit4]   2> 15737 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[17 (1413898626020671488)]} 0 3
[junit4:junit4]   2> 15749 T1213 C66 P49903 REQ /update {distrib.from=http://127.0.0.1:49895/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 15750 T1189 C67 P49895 /update {wt=javabin&version=2} {add=[17 (1413898626026962944)]} 0 10
[junit4:junit4]   2> 15754 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[100 (1413898626039545856)]} 0 1
[junit4:junit4]   2> 15802 T1199 C64 P49898 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=18 
[junit4:junit4]   2> 15803 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[100 (1413898626043740160)]} 0 46
[junit4:junit4]   2> 15808 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[101 (1413898626095120384)]} 0 2
[junit4:junit4]   2> 15823 T1199 C64 P49898 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49893/solr/collection1/&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 15824 T1177 C65 P49893 REQ /update {distrib.from=http://127.0.0.1:49895/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=10 
[junit4:junit4]   2> 15825 T1189 C67 P49895 /update {wt=javabin&version=2} {add=[101]} 0 14
[junit4:junit4]   2> 15829 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[102 (1413898626118189056)]} 0 1
[junit4:junit4]   2> 15841 T1199 C64 P49898 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49893/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15841 T1177 C65 P49893 REQ /update {distrib.from=http://127.0.0.1:49895/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 15842 T1189 C67 P49895 /update {wt=javabin&version=2} {add=[102]} 0 10
[junit4:junit4]   2> 15863 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[103 (1413898626137063424)]} 0 18
[junit4:junit4]   2> 15874 T1213 C66 P49903 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49895/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15875 T1192 C67 P49895 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 15876 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[103]} 0 10
[junit4:junit4]   2> 15882 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[104 (1413898626171666432)]} 0 3
[junit4:junit4]   2> 15892 T1213 C66 P49903 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49895/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15892 T1192 C67 P49895 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 15893 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[104]} 0 9
[junit4:junit4]   2> 15897 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[105 (1413898626189492224)]} 0 1
[junit4:junit4]   2> 15943 T1213 C66 P49903 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49895/solr/collection1/&wt=javabin&version=2} status=0 QTime=20 
[junit4:junit4]   2> 15944 T1192 C67 P49895 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=41 
[junit4:junit4]   2> 15944 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[105]} 0 44
[junit4:junit4]   2> 15950 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[106 (1413898626244018176)]} 0 2
[junit4:junit4]   2> 15964 T1213 C66 P49903 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49895/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15965 T1192 C67 P49895 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=9 
[junit4:junit4]   2> 15966 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[106]} 0 12
[junit4:junit4]   2> 15970 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[107 (1413898626266038272)]} 0 1
[junit4:junit4]   2> 15982 T1199 C64 P49898 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49893/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15982 T1177 C65 P49893 REQ /update {distrib.from=http://127.0.0.1:49895/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 15983 T1189 C67 P49895 /update {wt=javabin&version=2} {add=[107]} 0 10
[junit4:junit4]   2> 15987 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[108 (1413898626283864064)]} 0 1
[junit4:junit4]   2> 15995 T1199 C64 P49898 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15996 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[108 (1413898626288058368)]} 0 6
[junit4:junit4]   2> 16000 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[109 (1413898626297495552)]} 0 1
[junit4:junit4]   2> 16008 T1199 C64 P49898 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 16009 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[109 (1413898626301689856)]} 0 6
[junit4:junit4]   2> 16012 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[110 (1413898626310078464)]} 0 1
[junit4:junit4]   2> 16020 T1199 C64 P49898 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16020 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[110 (1413898626314272768)]} 0 5
[junit4:junit4]   2> 16024 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[111 (1413898626322661376)]} 0 1
[junit4:junit4]   2> 16033 T1199 C64 P49898 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 16034 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[111 (1413898626326855680)]} 0 7
[junit4:junit4]   2> 16038 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[112 (1413898626337341440)]} 0 1
[junit4:junit4]   2> 16048 T1213 C66 P49903 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49895/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16049 T1192 C67 P49895 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 16049 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[112]} 0 8
[junit4:junit4]   2> 16066 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[113 (1413898626353070080)]} 0 14
[junit4:junit4]   2> 16077 T1199 C64 P49898 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49893/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 16077 T1177 C65 P49893 REQ /update {distrib.from=http://127.0.0.1:49895/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 16078 T1189 C67 P49895 /update {wt=javabin&version=2} {add=[113]} 0 9
[junit4:junit4]   2> 16083 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[114 (1413898626383478784)]} 0 2
[junit4:junit4]   2> 16091 T1199 C64 P49898 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 16091 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[114 (1413898626388721664)]} 0 5
[junit4:junit4]   2> 16095 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[115 (1413898626397110272)]} 0 1
[junit4:junit4]   2> 16103 T1213 C66 P49903 REQ /update {distrib.from=http://127.0.0.1:49895/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16104 T1189 C67 P49895 /update {wt=javabin&version=2} {add=[115 (1413898626401304576)]} 0 6
[junit4:junit4]   2> 16108 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[116 (1413898626410741760)]} 0 1
[junit4:junit4]   2> 16119 T1213 C66 P49903 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49895/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16120 T1192 C67 P49895 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 16121 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[116]} 0 10
[junit4:junit4]   2> 16124 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[117 (1413898626427518976)]} 0 1
[junit4:junit4]   2> 16134 T1213 C66 P49903 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49895/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16135 T1192 C67 P49895 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 16136 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[117]} 0 9
[junit4:junit4]   2> 16140 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[118 (1413898626444296192)]} 0 1
[junit4:junit4]   2> 16180 T1199 C64 P49898 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49893/solr/collection1/&wt=javabin&version=2} status=0 QTime=14 
[junit4:junit4]   2> 16181 T1177 C65 P49893 REQ /update {distrib.from=http://127.0.0.1:49895/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=35 
[junit4:junit4]   2> 16182 T1189 C67 P49895 /update {wt=javabin&version=2} {add=[118]} 0 39
[junit4:junit4]   2> 16187 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[119 (1413898626492530688)]} 0 2
[junit4:junit4]   2> 16194 T1213 C66 P49903 REQ /update {distrib.from=http://127.0.0.1:49895/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16195 T1189 C67 P49895 /update {wt=javabin&version=2} {add=[119 (1413898626496724992)]} 0 6
[junit4:junit4]   2> 16199 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[120 (1413898626506162176)]} 0 1
[junit4:junit4]   2> 16210 T1213 C66 P49903 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49895/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16211 T1192 C67 P49895 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 16211 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[120]} 0 9
[junit4:junit4]   2> 16215 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[121 (1413898626522939392)]} 0 1
[junit4:junit4]   2> 16225 T1213 C66 P49903 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49895/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16226 T1192 C67 P49895 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 16226 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[121]} 0 8
[junit4:junit4]   2> 16230 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[122 (1413898626538668032)]} 0 1
[junit4:junit4]   2> 16239 T1199 C64 P49898 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 16240 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[122 (1413898626542862336)]} 0 7
[junit4:junit4]   2> 16257 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[123 (1413898626553348096)]} 0 14
[junit4:junit4]   2> 16265 T1199 C64 P49898 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16266 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[123 (1413898626571173888)]} 0 6
[junit4:junit4]   2> 16271 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[124 (1413898626580611072)]} 0 2
[junit4:junit4]   2> 16281 T1199 C64 P49898 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49893/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16282 T1177 C65 P49893 REQ /update {distrib.from=http://127.0.0.1:49895/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 16283 T1189 C67 P49895 /update {wt=javabin&version=2} {add=[124]} 0 9
[junit4:junit4]   2> 16286 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[125 (1413898626597388288)]} 0 1
[junit4:junit4]   2> 16293 T1199 C64 P49898 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16294 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[125 (1413898626601582592)]} 0 5
[junit4:junit4]   2> 16298 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[126 (1413898626609971200)]} 0 1
[junit4:junit4]   2> 16306 T1213 C66 P49903 REQ /update {distrib.from=http://127.0.0.1:49895/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16307 T1189 C67 P49895 /update {wt=javabin&version=2} {add=[126 (1413898626614165504)]} 0 6
[junit4:junit4]   2> 16311 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[127 (1413898626623602688)]} 0 1
[junit4:junit4]   2> 16346 T1213 C66 P49903 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49895/solr/collection1/&wt=javabin&version=2} status=0 QTime=13 
[junit4:junit4]   2> 16347 T1192 C67 P49895 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=31 
[junit4:junit4]   2> 16348 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[127]} 0 34
[junit4:junit4]   2> 16352 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[128 (1413898626666594304)]} 0 1
[junit4:junit4]   2> 16365 T1213 C66 P49903 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49895/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 16366 T1192 C67 P49895 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=8 
[junit4:junit4]   2> 16366 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[128]} 0 11
[junit4:junit4]   2> 16370 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[129 (1413898626685468672)]} 0 1
[junit4:junit4]   2> 16378 T1199 C64 P49898 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16379 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[129 (1413898626689662976)]} 0 6
[junit4:junit4]   2> 16383 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[130 (1413898626699100160)]} 0 1
[junit4:junit4]   2> 16391 T1213 C66 P49903 REQ /update {distrib.from=http://127.0.0.1:49895/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16392 T1189 C67 P49895 /update {wt=javabin&version=2} {add=[130 (1413898626703294464)]} 0 6
[junit4:junit4]   2> 16396 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[131 (1413898626712731648)]} 0 1
[junit4:junit4]   2> 16405 T1213 C66 P49903 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49895/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16406 T1192 C67 P49895 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 16406 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[131]} 0 7
[junit4:junit4]   2> 16410 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[132 (1413898626727411712)]} 0 1
[junit4:junit4]   2> 16418 T1199 C64 P49898 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16419 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[132 (1413898626731606016)]} 0 6
[junit4:junit4]   2> 16437 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[133 (1413898626742091776)]} 0 15
[junit4:junit4]   2> 16446 T1199 C64 P49898 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 16446 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[133 (1413898626759917568)]} 0 6
[junit4:junit4]   2> 16452 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[134 (1413898626769354752)]} 0 3
[junit4:junit4]   2> 16459 T1213 C66 P49903 REQ /update {distrib.from=http://127.0.0.1:49895/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16460 T1189 C67 P49895 /update {wt=javabin&version=2} {add=[134 (1413898626774597632)]} 0 6
[junit4:junit4]   2> 16465 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[135 (1413898626785083392)]} 0 2
[junit4:junit4]   2> 16474 T1199 C64 P49898 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49893/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16475 T1177 C65 P49893 REQ /update {distrib.from=http://127.0.0.1:49895/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 16476 T1189 C67 P49895 /update {wt=javabin&version=2} {add=[135]} 0 9
[junit4:junit4]   2> 16481 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[136 (1413898626801860608)]} 0 1
[junit4:junit4]   2> 16491 T1213 C66 P49903 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49895/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16492 T1192 C67 P49895 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 16492 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[136]} 0 8
[junit4:junit4]   2> 16496 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[137 (1413898626817589248)]} 0 1
[junit4:junit4]   2> 16505 T1213 C66 P49903 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49895/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16506 T1192 C67 P49895 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 16506 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[137]} 0 7
[junit4:junit4]   2> 16510 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[138 (1413898626832269312)]} 0 1
[junit4:junit4]   2> 16519 T1199 C64 P49898 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49893/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16520 T1177 C65 P49893 REQ /update {distrib.from=http://127.0.0.1:49895/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 16521 T1189 C67 P49895 /update {wt=javabin&version=2} {add=[138]} 0 7
[junit4:junit4]   2> 16524 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[139 (1413898626846949376)]} 0 1
[junit4:junit4]   2> 16533 T1213 C66 P49903 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49895/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16534 T1192 C67 P49895 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 16534 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[139]} 0 7
[junit4:junit4]   2> 16538 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[140 (1413898626861629440)]} 0 1
[junit4:junit4]   2> 16545 T1213 C66 P49903 REQ /update {distrib.from=http://127.0.0.1:49895/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16546 T1189 C67 P49895 /update {wt=javabin&version=2} {add=[140 (1413898626865823744)]} 0 5
[junit4:junit4]   2> 16550 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[141 (1413898626874212352)]} 0 1
[junit4:junit4]   2> 16559 T1213 C66 P49903 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49895/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16560 T1192 C67 P49895 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 16560 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[141]} 0 7
[junit4:junit4]   2> 16564 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[142 (1413898626888892416)]} 0 1
[junit4:junit4]   2> 16603 T1213 C66 P49903 REQ /update {distrib.from=http://127.0.0.1:49895/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=18 
[junit4:junit4]   2> 16603 T1189 C67 P49895 /update {wt=javabin&version=2} {add=[142 (1413898626893086720)]} 0 36
[junit4:junit4]   2> 16624 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[143 (1413898626933981184)]} 0 18
[junit4:junit4]   2> 16633 T1213 C66 P49903 REQ /update {distrib.from=http://127.0.0.1:49895/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 16634 T1189 C67 P49895 /update {wt=javabin&version=2} {add=[143 (1413898626954952704)]} 0 8
[junit4:junit4]   2> 16639 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[144 (1413898626966487040)]} 0 2
[junit4:junit4]   2> 16646 T1213 C66 P49903 REQ /update {distrib.from=http://127.0.0.1:49895/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16647 T1189 C67 P49895 /update {wt=javabin&version=2} {add=[144 (1413898626971729920)]} 0 5
[junit4:junit4]   2> 16651 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[145 (1413898626980118528)]} 0 1
[junit4:junit4]   2> 16659 T1213 C66 P49903 REQ /update {distrib.from=http://127.0.0.1:49895/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16660 T1189 C67 P49895 /update {wt=javabin&version=2} {add=[145 (1413898626984312832)]} 0 6
[junit4:junit4]   2> 16664 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[146 (1413898626993750016)]} 0 1
[junit4:junit4]   2> 16704 T1199 C64 P49898 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=14 
[junit4:junit4]   2> 16705 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[146 (1413898626998992896)]} 0 38
[junit4:junit4]   2> 16710 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[147 (1413898627040935936)]} 0 2
[junit4:junit4]   2> 16719 T1213 C66 P49903 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49895/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16720 T1192 C67 P49895 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 16720 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[147]} 0 8
[junit4:junit4]   2> 16724 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[148 (1413898627056664576)]} 0 1
[junit4:junit4]   2> 16738 T1199 C64 P49898 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49893/solr/collection1/&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 16739 T1177 C65 P49893 REQ /update {distrib.from=http://127.0.0.1:49895/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=9 
[junit4:junit4]   2> 16740 T1189 C67 P49895 /update {wt=javabin&version=2} {add=[148]} 0 13
[junit4:junit4]   2> 16744 T1161 C68 P49889 /update {wt=javabin&version=2} {add=[149 (1413898627077636096)]} 0 1
[junit4:junit4]   2> 16755 T1213 C66 P49903 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49895/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16756 T1192 C67 P49895 REQ /update {distrib.from=http://127.0.0.1:49893/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 16757 T1180 C65 P49893 /update {wt=javabin&version=2} {add=[149]} 0 10
[junit4:junit4]   2> 16758 T1149 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):1800
[junit4:junit4]   2> 16759 T1149 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 16761 T1161 C68 P49889 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 17775 T1161 C68 P49889 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.clo

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

2> 145343 T2294 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4:junit4]   2> 145501 T2294 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=SyncSliceTest -Dtests.method=testDistribSearch -Dtests.seed=361BAFABA7533777 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ko -Dtests.timezone=Europe/Vatican -Dtests.file.encoding=UTF-8
[junit4:junit4] FAILURE  146s J0 | SyncSliceTest.testDistribSearch <<<
[junit4:junit4]    > Throwable #1: java.lang.AssertionError: There are still nodes recoverying
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([361BAFABA7533777:B7FD21B3D00C574B]: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> 145533 T2294 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4]   2> NOTE: test params are: codec=Lucene3x, sim=DefaultSimilarity, locale=ko, timezone=Europe/Vatican
[junit4:junit4]   2> NOTE: FreeBSD 9.0-RELEASE amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=1,free=199216592,total=298844160
[junit4:junit4]   2> NOTE: All tests run in this JVM: [SolrCoreCheckLockOnStartupTest, AlternateDirectoryTest, DirectSolrConnectionTest, BadComponentTest, TestStressReorder, SpellCheckCollatorTest, TestLMDirichletSimilarityFactory, LeaderElectionIntegrationTest, DefaultValueUpdateProcessorTest, TestXIncludeConfig, TestFastLRUCache, TestPseudoReturnFields, DistanceFunctionTest, CurrencyFieldTest, TestRandomFaceting, JSONWriterTest, SpatialFilterTest, BinaryUpdateRequestHandlerTest, TestLFUCache, NotRequiredUniqueKeyTest, SimpleFacetsTest, TestFastOutputStream, FieldAnalysisRequestHandlerTest, TestGroupingSearch, CircularListTest, SystemInfoHandlerTest, IndexBasedSpellCheckerTest, TestQuerySenderNoQuery, TestFastWriter, SolrCmdDistributorTest, CopyFieldTest, UniqFieldsUpdateProcessorFactoryTest, TestConfig, TestIndexSearcher, DistributedTermsComponentTest, ClusterStateTest, NoCacheHeaderTest, TestJoin, DateFieldTest, CSVRequestHandlerTest, ZkControllerTest, TestPerFieldSimilarity, MinimalSchemaTest, LoggingHandlerTest, TestSolrJ, PluginInfoTest, SuggesterFSTTest, TestElisionMultitermQuery, TestSystemIdResolver, SimplePostToolTest, TestSolr4Spatial, BasicDistributedZkTest, QueryElevationComponentTest, HighlighterConfigTest, TestBinaryResponseWriter, RecoveryZkTest, SpellCheckComponentTest, TestReplicationHandler, DistributedSpellCheckComponentTest, TestRealTimeGet, TestDistributedSearch, FileBasedSpellCheckerTest, SortByFunctionTest, SignatureUpdateProcessorFactoryTest, SampleTest, CoreAdminHandlerTest, TestFunctionQuery, TestTrie, SolrRequestParserTest, CacheHeaderTest, QueryEqualityTest, TestWordDelimiterFilterFactory, TestCSVResponseWriter, MBeansHandlerTest, DisMaxRequestHandlerTest, IndexSchemaTest, TermsComponentTest, XsltUpdateRequestHandlerTest, TestQueryTypes, JsonLoaderTest, DirectUpdateHandlerOptimizeTest, TestSolrQueryParser, TestValueSourceCache, TestReversedWildcardFilterFactory, RequestHandlersTest, SuggesterTest, TestFoldingMultitermQuery, TestLuceneMatchVersion, UpdateRequestProcessorFactoryTest, FieldMutatingUpdateProcessorTest, SOLR749Test, TestQuerySenderListener, SolrIndexConfigTest, TestNumberUtils, TestJmxMonitoredMap, EchoParamsTest, SpellPossibilityIteratorTest, TestLMJelinekMercerSimilarityFactory, TestIBSimilarityFactory, TimeZoneUtilsTest, URLClassifyProcessorTest, DOMUtilTest, PreAnalyzedFieldTest, PathHierarchyTokenizerFactoryTest, TestCharFilters, SyncSliceTest]
[junit4:junit4] Completed on J0 in 145.56s, 1 test, 1 failure <<< FAILURES!

[...truncated 11 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:32: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build.xml:179: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/module-build.xml:63: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/common-build.xml:1141: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/common-build.xml:814: There were test failures: 231 suites, 954 tests, 2 failures, 21 ignored (3 assumptions)

Total time: 30 minutes 26 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