lucene-dev mailing list archives

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

1 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([7F08B142E73C5655:FEEE3F5A90633669]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.waitToSeeNotLive(AbstractFullDistribZkTestBase.java:1220)
	at org.apache.solr.cloud.BasicDistributedZk2Test.brindDownShardIndexSomeDocsAndRecover(BasicDistributedZk2Test.java:190)
	at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:83)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:695)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:616)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:679)




Build Log:
[...truncated 7744 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4:junit4]   2> 3 T3557 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1348244841327
[junit4:junit4]   2> 4 T3557 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 8 T3558 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4]   2> 9 T3558 oazs.NIOServerCnxn$Factory.<init> binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 10 T3558 oazsp.FileTxnSnapLog.save Snapshotting: 0
[junit4:junit4]   2> 105 T3557 oasc.ZkTestServer.run start zk server on port:55943
[junit4:junit4]   2> 105 T3557 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:55943 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@736adbfd
[junit4:junit4]   2> 106 T3563 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:55943
[junit4:junit4]   2> 106 T3557 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 107 T3563 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:55943, initiating session
[junit4:junit4]   2> 107 T3559 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:38042
[junit4:junit4]   2> 107 T3559 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:38042
[junit4:junit4]   2> 108 T3561 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 111 T3561 oazs.NIOServerCnxn.finishSessionInit Established session 0x139e9a7a3760000 with negotiated timeout 10000 for client /140.211.11.196:38042
[junit4:junit4]   2> 111 T3563 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:55943, sessionid = 0x139e9a7a3760000, negotiated timeout = 10000
[junit4:junit4]   2> 111 T3564 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@736adbfd name:ZooKeeperConnection Watcher:127.0.0.1:55943 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 111 T3557 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 111 T3557 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 126 T3562 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x139e9a7a3760000
[junit4:junit4]   2> 127 T3564 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 128 T3559 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:38042 which had sessionid 0x139e9a7a3760000
[junit4:junit4]   2> 127 T3557 oaz.ZooKeeper.close Session: 0x139e9a7a3760000 closed
[junit4:junit4]   2> 128 T3557 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:55943/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@15a2584e
[junit4:junit4]   2> 128 T3565 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:55943
[junit4:junit4]   2> 128 T3557 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 129 T3565 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:55943, initiating session
[junit4:junit4]   2> 129 T3559 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:28393
[junit4:junit4]   2> 130 T3559 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:28393
[junit4:junit4]   2> 131 T3561 oazs.NIOServerCnxn.finishSessionInit Established session 0x139e9a7a3760001 with negotiated timeout 10000 for client /140.211.11.196:28393
[junit4:junit4]   2> 131 T3565 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:55943, sessionid = 0x139e9a7a3760001, negotiated timeout = 10000
[junit4:junit4]   2> 131 T3566 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15a2584e name:ZooKeeperConnection Watcher:127.0.0.1:55943/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 132 T3557 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 132 T3557 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 142 T3557 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 143 T3557 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 149 T3557 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 151 T3557 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 152 T3557 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 163 T3557 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4]   2> 164 T3557 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 268 T3557 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 269 T3557 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 291 T3557 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4]   2> 291 T3557 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 294 T3557 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4]   2> 294 T3557 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 296 T3557 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4]   2> 297 T3557 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 323 T3557 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 323 T3557 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 326 T3557 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 326 T3557 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 360 T3557 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 361 T3557 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 365 T3557 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4]   2> 366 T3557 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 428 T3562 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x139e9a7a3760001
[junit4:junit4]   2> 429 T3566 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 429 T3559 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:28393 which had sessionid 0x139e9a7a3760001
[junit4:junit4]   2> 429 T3557 oaz.ZooKeeper.close Session: 0x139e9a7a3760001 closed
[junit4:junit4]   2> 432 T3557 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 434 T3557 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:34524
[junit4:junit4]   2> 435 T3557 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 435 T3557 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 436 T3557 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 475 T3557 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 476 T3557 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 476 T3557 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 477 T3557 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/solr.xml
[junit4:junit4]   2> 477 T3557 oasc.CoreContainer.<init> New CoreContainer 1277725882
[junit4:junit4]   2> 478 T3557 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 478 T3557 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 504 T3557 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 520 T3557 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:55943/solr
[junit4:junit4]   2> 520 T3557 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:55943/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@2f8f278e
[junit4:junit4]   2> 521 T3576 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:55943
[junit4:junit4]   2> 521 T3557 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 524 T3576 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:55943, initiating session
[junit4:junit4]   2> 524 T3559 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:43356
[junit4:junit4]   2> 524 T3559 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:43356
[junit4:junit4]   2> 532 T3561 oazs.NIOServerCnxn.finishSessionInit Established session 0x139e9a7a3760002 with negotiated timeout 5000 for client /140.211.11.196:43356
[junit4:junit4]   2> 532 T3576 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:55943, sessionid = 0x139e9a7a3760002, negotiated timeout = 5000
[junit4:junit4]   2> 532 T3577 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2f8f278e name:ZooKeeperConnection Watcher:127.0.0.1:55943/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 532 T3557 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 534 T3562 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e9a7a3760002 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 543 T3557 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 545 T3557 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34524_solr
[junit4:junit4]   2> 546 T3562 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e9a7a3760002 type:delete cxid:0x7 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:34524_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:34524_solr
[junit4:junit4]   2> 553 T3557 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:34524_solr
[junit4:junit4]   2> 555 T3557 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 555 T3557 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 556 T3557 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 556 T3557 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 556 T3557 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 557 T3557 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 557 T3557 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 558 T3557 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 558 T3557 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 559 T3557 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 575 T3557 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 579 T3562 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e9a7a3760002 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> 592 T3557 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 594 T3557 oasc.Overseer.start Overseer (id=88358573921665026-127.0.0.1:34524_solr-n_0000000000) starting
[junit4:junit4]   2> 594 T3562 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e9a7a3760002 type:create cxid:0x1a zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 600 T3562 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e9a7a3760002 type:create cxid:0x1b zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 601 T3562 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e9a7a3760002 type:create cxid:0x1c zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 608 T3562 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e9a7a3760002 type:create cxid:0x1d zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 612 T3579 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 612 T3557 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 622 T3557 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 624 T3578 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 628 T3557 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1
[junit4:junit4]   2> 629 T3557 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 629 T3557 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 630 T3557 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 631 T3557 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4]   2> 632 T3557 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 633 T3557 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4]   2> 683 T3557 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_40
[junit4:junit4]   2> 779 T3557 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 880 T3557 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 887 T3557 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 1478 T3557 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 1486 T3557 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 1489 T3557 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 1497 T3557 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1500 T3557 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1503 T3557 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1503 T3557 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1504 T3557 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test-files/solr/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/control/data/
[junit4:junit4]   2> 1504 T3557 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5fed27e4
[junit4:junit4]   2> 1505 T3557 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/control/data/index/
[junit4:junit4]   2> 1506 T3557 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/control/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 1507 T3557 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/control/data/index forceNew:false
[junit4:junit4]   2> 1512 T3557 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-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@27309f8c; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 1513 T3557 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 1514 T3557 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 1515 T3557 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 1515 T3557 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 1516 T3557 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 1516 T3557 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 1517 T3557 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 1517 T3557 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 1517 T3557 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 1518 T3557 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 1518 T3557 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 1519 T3557 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 1519 T3557 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 1519 T3557 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 1520 T3557 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 1520 T3557 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 1520 T3557 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 1521 T3557 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 1521 T3557 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1522 T3557 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1522 T3557 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1522 T3557 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1523 T3557 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1523 T3557 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1524 T3557 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1524 T3557 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 1524 T3557 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 1527 T3557 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 1530 T3557 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 1531 T3557 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> 1534 T3557 oass.SolrIndexSearcher.<init> Opening Searcher@582ad9be main
[junit4:junit4]   2> 1534 T3557 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 1535 T3557 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 1535 T3557 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 1541 T3557 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 1587 T3580 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@582ad9be main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 1590 T3562 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e9a7a3760002 type:create cxid:0x53 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer/queue Error:KeeperErrorCode = NoNode for /solr/overseer/queue
[junit4:junit4]   2> 1608 T3557 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 1608 T3557 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:34524/solr shardId:control_shard
[junit4:junit4]   2> 1609 T3557 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/control_shard/election
[junit4:junit4]   2> 1637 T3578 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 1637 T3562 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e9a7a3760002 type:delete cxid:0x66 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> 1645 T3557 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 1645 T3562 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e9a7a3760002 type:create cxid:0x68 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer/queue-work Error:KeeperErrorCode = NoNode for /solr/overseer/queue-work
[junit4:junit4]   2> 1646 T3562 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e9a7a3760002 type:create cxid:0x69 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 1693 T3577 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 2167 T3557 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 2168 T3557 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 2168 T3557 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:34524/solr/collection1/
[junit4:junit4]   2> 2168 T3557 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 2169 T3557 oasc.SyncStrategy.syncToMe http://127.0.0.1:34524/solr/collection1/ has no replicas
[junit4:junit4]   2> 2169 T3557 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:34524/solr/collection1/
[junit4:junit4]   2> 2169 T3557 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/control_shard
[junit4:junit4]   2> 2200 T3562 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e9a7a3760002 type:create cxid:0x88 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2714 T3578 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2717 T3577 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 2773 T3557 oasc.ZkController.register We are http://127.0.0.1:34524/solr/collection1/ and leader is http://127.0.0.1:34524/solr/collection1/
[junit4:junit4]   2> 2773 T3557 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:34524/solr
[junit4:junit4]   2> 2773 T3557 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 2775 T3557 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2776 T3557 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1
[junit4:junit4]   2> 2776 T3557 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 2776 T3557 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 3208 T3557 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 3211 T3557 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:65003
[junit4:junit4]   2> 3211 T3557 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 3211 T3557 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty1-1348244844108
[junit4:junit4]   2> 3212 T3557 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty1-1348244844108/'
[junit4:junit4]   2> 3233 T3578 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3235 T3557 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 3235 T3557 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 3235 T3557 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty1-1348244844108
[junit4:junit4]   2> 3236 T3557 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty1-1348244844108/solr.xml
[junit4:junit4]   2> 3236 T3557 oasc.CoreContainer.<init> New CoreContainer 1692977777
[junit4:junit4]   2> 3237 T3557 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty1-1348244844108/'
[junit4:junit4]   2> 3237 T3577 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 3237 T3557 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty1-1348244844108/'
[junit4:junit4]   2> 3254 T3557 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 3264 T3557 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:55943/solr
[junit4:junit4]   2> 3264 T3557 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:55943/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@14c02b59
[junit4:junit4]   2> 3265 T3590 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:55943
[junit4:junit4]   2> 3265 T3557 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 3266 T3590 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:55943, initiating session
[junit4:junit4]   2> 3266 T3559 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:64319
[junit4:junit4]   2> 3267 T3559 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:64319
[junit4:junit4]   2> 3268 T3561 oazs.NIOServerCnxn.finishSessionInit Established session 0x139e9a7a3760003 with negotiated timeout 5000 for client /140.211.11.196:64319
[junit4:junit4]   2> 3268 T3590 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:55943, sessionid = 0x139e9a7a3760003, negotiated timeout = 5000
[junit4:junit4]   2> 3268 T3591 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14c02b59 name:ZooKeeperConnection Watcher:127.0.0.1:55943/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3268 T3557 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 3269 T3562 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e9a7a3760003 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3270 T3562 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e9a7a3760003 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3272 T3557 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:65003_solr
[junit4:junit4]   2> 3272 T3562 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e9a7a3760003 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:65003_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:65003_solr
[junit4:junit4]   2> 3278 T3557 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:65003_solr
[junit4:junit4]   2> 3284 T3577 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 3284 T3557 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 3285 T3557 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 3285 T3557 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 3285 T3557 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 3286 T3557 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 3286 T3557 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 3286 T3557 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 3286 T3557 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 3287 T3557 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 3287 T3557 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 3297 T3557 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 3302 T3557 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty1-1348244844108/collection1
[junit4:junit4]   2> 3302 T3557 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 3302 T3557 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 3303 T3557 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 3303 T3557 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty1-1348244844108/collection1/'
[junit4:junit4]   2> 3304 T3557 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solrtest-jetty1-1348244844108/collection1/lib/README' to classloader
[junit4:junit4]   2> 3305 T3557 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solrtest-jetty1-1348244844108/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 3338 T3557 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_40
[junit4:junit4]   2> 3386 T3557 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 3487 T3557 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 3494 T3557 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 4212 T3557 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 4225 T3557 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 4229 T3557 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 4239 T3557 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 4244 T3557 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 4250 T3557 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 4251 T3557 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 4252 T3557 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty1-1348244844108/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty1/
[junit4:junit4]   2> 4253 T3557 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5fed27e4
[junit4:junit4]   2> 4254 T3557 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty1/index/
[junit4:junit4]   2> 4255 T3557 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 4256 T3557 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty1/index forceNew:false
[junit4:junit4]   2> 4263 T3557 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-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@b5185c; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 4263 T3557 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 4264 T3557 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 4266 T3557 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 4267 T3557 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 4268 T3557 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 4268 T3557 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 4269 T3557 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 4269 T3557 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 4270 T3557 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 4271 T3557 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 4271 T3557 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 4272 T3557 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 4273 T3557 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 4273 T3557 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 4274 T3557 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 4275 T3557 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 4275 T3557 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 4276 T3557 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 4277 T3557 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4277 T3557 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4278 T3557 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4279 T3557 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4279 T3557 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4280 T3557 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4281 T3557 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4281 T3557 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 4282 T3557 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 4286 T3557 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 4291 T3557 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 4292 T3557 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> 4296 T3557 oass.SolrIndexSearcher.<init> Opening Searcher@650bed2a main
[junit4:junit4]   2> 4297 T3557 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 4298 T3557 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 4299 T3557 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 4306 T3557 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 4365 T3592 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@650bed2a main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 4750 T3578 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4763 T3577 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4763 T3591 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4872 T3557 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 4872 T3557 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:65003/solr shardId:shard1
[junit4:junit4]   2> 4873 T3557 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 4877 T3562 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e9a7a3760003 type:delete cxid:0x42 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/collections/collection1/leaders Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders
[junit4:junit4]   2> 4877 T3557 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 4878 T3562 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e9a7a3760003 type:create cxid:0x43 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4879 T3557 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 4879 T3557 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 4880 T3557 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:65003/solr/collection1/
[junit4:junit4]   2> 4880 T3557 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 4880 T3557 oasc.SyncStrategy.syncToMe http://127.0.0.1:65003/solr/collection1/ has no replicas
[junit4:junit4]   2> 4881 T3557 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:65003/solr/collection1/
[junit4:junit4]   2> 4881 T3557 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 4883 T3562 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e9a7a3760003 type:create cxid:0x4d zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 5266 T3578 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 5315 T3577 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5315 T3591 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5343 T3557 oasc.ZkController.register We are http://127.0.0.1:65003/solr/collection1/ and leader is http://127.0.0.1:65003/solr/collection1/
[junit4:junit4]   2> 5343 T3557 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:65003/solr
[junit4:junit4]   2> 5343 T3557 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 5364 T3557 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 5365 T3557 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1
[junit4:junit4]   2> 5365 T3557 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 5366 T3557 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 5843 T3578 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 5857 T3577 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5857 T3591 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6006 T3557 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 6008 T3557 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:25098
[junit4:junit4]   2> 6009 T3557 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 6009 T3557 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty2-1348244846699
[junit4:junit4]   2> 6010 T3557 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty2-1348244846699/'
[junit4:junit4]   2> 6032 T3557 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 6033 T3557 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 6033 T3557 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty2-1348244846699
[junit4:junit4]   2> 6033 T3557 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty2-1348244846699/solr.xml
[junit4:junit4]   2> 6034 T3557 oasc.CoreContainer.<init> New CoreContainer 707335612
[junit4:junit4]   2> 6034 T3557 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty2-1348244846699/'
[junit4:junit4]   2> 6034 T3557 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty2-1348244846699/'
[junit4:junit4]   2> 6051 T3557 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 6061 T3557 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:55943/solr
[junit4:junit4]   2> 6061 T3557 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:55943/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@704dc0cd
[junit4:junit4]   2> 6062 T3602 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:55943
[junit4:junit4]   2> 6062 T3557 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 6063 T3602 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:55943, initiating session
[junit4:junit4]   2> 6064 T3559 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:21335
[junit4:junit4]   2> 6064 T3559 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:21335
[junit4:junit4]   2> 6065 T3561 oazs.NIOServerCnxn.finishSessionInit Established session 0x139e9a7a3760004 with negotiated timeout 5000 for client /140.211.11.196:21335
[junit4:junit4]   2> 6065 T3602 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:55943, sessionid = 0x139e9a7a3760004, negotiated timeout = 5000
[junit4:junit4]   2> 6065 T3603 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@704dc0cd name:ZooKeeperConnection Watcher:127.0.0.1:55943/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 6065 T3557 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 6066 T3562 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e9a7a3760004 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 6067 T3562 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e9a7a3760004 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 6076 T3557 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:25098_solr
[junit4:junit4]   2> 6076 T3562 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e9a7a3760004 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:25098_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:25098_solr
[junit4:junit4]   2> 6077 T3557 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:25098_solr
[junit4:junit4]   2> 6084 T3591 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 6084 T3577 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 6084 T3557 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 6084 T3557 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 6085 T3557 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 6085 T3557 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 6085 T3557 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 6085 T3557 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 6086 T3557 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 6086 T3557 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 6086 T3557 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 6087 T3557 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 6098 T3557 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 6101 T3557 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty2-1348244846699/collection1
[junit4:junit4]   2> 6102 T3557 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 6102 T3557 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 6103 T3557 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 6103 T3557 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty2-1348244846699/collection1/'
[junit4:junit4]   2> 6104 T3557 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solrtest-jetty2-1348244846699/collection1/lib/README' to classloader
[junit4:junit4]   2> 6105 T3557 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solrtest-jetty2-1348244846699/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 6139 T3557 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_40
[junit4:junit4]   2> 6183 T3557 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 6284 T3557 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 6290 T3557 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 6715 T3557 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 6724 T3557 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 6727 T3557 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 6739 T3557 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 6743 T3557 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 6746 T3557 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 6747 T3557 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 6748 T3557 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty2-1348244846699/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty2/
[junit4:junit4]   2> 6748 T3557 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5fed27e4
[junit4:junit4]   2> 6749 T3557 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty2/index/
[junit4:junit4]   2> 6750 T3557 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 6751 T3557 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty2/index forceNew:false
[junit4:junit4]   2> 6756 T3557 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-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@29cc77ef; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 6756 T3557 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 6757 T3557 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 6758 T3557 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 6759 T3557 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 6759 T3557 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 6759 T3557 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 6760 T3557 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 6760 T3557 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 6761 T3557 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 6761 T3557 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 6762 T3557 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 6762 T3557 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 6763 T3557 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 6763 T3557 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 6763 T3557 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 6764 T3557 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 6764 T3557 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 6765 T3557 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 6765 T3557 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6766 T3557 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6766 T3557 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6766 T3557 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6767 T3557 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6767 T3557 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6768 T3557 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6768 T3557 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 6769 T3557 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 6772 T3557 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 6775 T3557 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 6776 T3557 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> 6779 T3557 oass.SolrIndexSearcher.<init> Opening Searcher@546937e7 main
[junit4:junit4]   2> 6780 T3557 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 6780 T3557 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 6781 T3557 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 6795 T3557 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 6836 T3604 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@546937e7 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 6861 T3578 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6872 T3591 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6872 T3603 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6872 T3577 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7341 T3557 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 7341 T3557 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:25098/solr shardId:shard2
[junit4:junit4]   2> 7342 T3557 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4]   2> 7346 T3562 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e9a7a3760004 type:delete cxid:0x41 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> 7355 T3557 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 7356 T3562 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e9a7a3760004 type:create cxid:0x42 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7364 T3557 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 7365 T3557 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 7365 T3557 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:25098/solr/collection1/
[junit4:junit4]   2> 7365 T3557 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 7366 T3557 oasc.SyncStrategy.syncToMe http://127.0.0.1:25098/solr/collection1/ has no replicas
[junit4:junit4]   2> 7366 T3557 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:25098/solr/collection1/
[junit4:junit4]   2> 7366 T3557 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4]   2> 7368 T3562 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e9a7a3760004 type:create cxid:0x4b zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7379 T3578 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7384 T3603 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7384 T3591 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7384 T3577 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7430 T3557 oasc.ZkController.register We are http://127.0.0.1:25098/solr/collection1/ and leader is http://127.0.0.1:25098/solr/collection1/
[junit4:junit4]   2> 7430 T3557 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:25098/solr
[junit4:junit4]   2> 7430 T3557 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 7432 T3557 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7432 T3557 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1
[junit4:junit4]   2> 7433 T3557 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 7433 T3557 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 7872 T3557 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 7874 T3557 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:26763
[junit4:junit4]   2> 7875 T3557 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 7875 T3557 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty3-1348244848766
[junit4:junit4]   2> 7875 T3557 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty3-1348244848766/'
[junit4:junit4]   2> 7887 T3578 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7899 T3557 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 7899 T3557 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 7899 T3557 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty3-1348244848766
[junit4:junit4]   2> 7900 T3557 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty3-1348244848766/solr.xml
[junit4:junit4]   2> 7900 T3557 oasc.CoreContainer.<init> New CoreContainer 1249663083
[junit4:junit4]   2> 7900 T3557 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty3-1348244848766/'
[junit4:junit4]   2> 7901 T3557 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty3-1348244848766/'
[junit4:junit4]   2> 7901 T3603 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7901 T3577 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7901 T3591 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7918 T3557 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 7928 T3557 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:55943/solr
[junit4:junit4]   2> 7928 T3557 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:55943/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@6e55aff8
[junit4:junit4]   2> 7929 T3614 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:55943
[junit4:junit4]   2> 7929 T3557 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 7929 T3614 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:55943, initiating session
[junit4:junit4]   2> 7930 T3559 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:54119
[junit4:junit4]   2> 7930 T3559 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:54119
[junit4:junit4]   2> 7931 T3561 oazs.NIOServerCnxn.finishSessionInit Established session 0x139e9a7a3760005 with negotiated timeout 5000 for client /140.211.11.196:54119
[junit4:junit4]   2> 7931 T3614 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:55943, sessionid = 0x139e9a7a3760005, negotiated timeout = 5000
[junit4:junit4]   2> 7932 T3615 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6e55aff8 name:ZooKeeperConnection Watcher:127.0.0.1:55943/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 7932 T3557 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 7932 T3562 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e9a7a3760005 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7934 T3562 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e9a7a3760005 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7935 T3557 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:26763_solr
[junit4:junit4]   2> 7935 T3562 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e9a7a3760005 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:26763_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:26763_solr
[junit4:junit4]   2> 7943 T3557 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:26763_solr
[junit4:junit4]   2> 7945 T3603 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 7945 T3577 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 7945 T3591 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 7945 T3557 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 7946 T3557 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 7946 T3557 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 7946 T3557 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 7947 T3557 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 7947 T3557 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 7947 T3557 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 7947 T3557 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 7948 T3557 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 7948 T3557 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 7959 T3557 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 7963 T3557 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty3-1348244848766/collection1
[junit4:junit4]   2> 7964 T3557 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 7964 T3557 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 7964 T3557 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 7965 T3557 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty3-1348244848766/collection1/'
[junit4:junit4]   2> 7966 T3557 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solrtest-jetty3-1348244848766/collection1/lib/README' to classloader
[junit4:junit4]   2> 7967 T3557 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solrtest-jetty3-1348244848766/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 7999 T3557 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_40
[junit4:junit4]   2> 8045 T3557 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 8146 T3557 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 8151 T3557 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 8564 T3557 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 8572 T3557 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 8575 T3557 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 8583 T3557 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 8586 T3557 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 8590 T3557 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 8590 T3557 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 8591 T3557 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty3-1348244848766/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty3/
[junit4:junit4]   2> 8591 T3557 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5fed27e4
[junit4:junit4]   2> 8592 T3557 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty3/index/
[junit4:junit4]   2> 8593 T3557 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 8594 T3557 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty3/index forceNew:false
[junit4:junit4]   2> 8600 T3557 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-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty3/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@26c18bd1; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 8600 T3557 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 8601 T3557 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 8602 T3557 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 8603 T3557 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 8603 T3557 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 8604 T3557 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 8604 T3557 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 8604 T3557 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 8605 T3557 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 8605 T3557 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 8606 T3557 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 8606 T3557 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 8607 T3557 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 8607 T3557 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 8608 T3557 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 8608 T3557 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 8608 T3557 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 8609 T3557 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 8609 T3557 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8610 T3557 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8610 T3557 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8611 T3557 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8611 T3557 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8611 T3557 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8612 T3557 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8612 T3557 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 8613 T3557 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 8616 T3557 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 8619 T3557 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 8620 T3557 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> 8623 T3557 oass.SolrIndexSearcher.<init> Opening Searcher@3f599473 main
[junit4:junit4]   2> 8624 T3557 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 8624 T3557 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 8625 T3557 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 8630 T3557 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 8674 T3616 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3f599473 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 8906 T3578 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8918 T3603 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8918 T3591 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8918 T3577 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8918 T3615 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9179 T3557 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 9179 T3557 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:26763/solr shardId:shard1
[junit4:junit4]   2> 9182 T3557 oasc.ZkController.register We are http://127.0.0.1:26763/solr/collection1/ and leader is http://127.0.0.1:65003/solr/collection1/
[junit4:junit4]   2> 9182 T3557 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:26763/solr
[junit4:junit4]   2> 9183 T3557 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 9183 T3557 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C106 name=collection1 org.apache.solr.core.SolrCore@6c7e9506 url=http://127.0.0.1:26763/solr/collection1 node=127.0.0.1:26763_solr
[junit4:junit4]   2> 9184 T3617 C106 P26763 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 9184 T3557 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9185 T3617 C106 P26763 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 9185 T3557 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1
[junit4:junit4]   2> 9186 T3617 C106 P26763 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:65003/solr/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 9186 T3557 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 9186 T3617 C106 P26763 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:26763/solr START replicas=[http://127.0.0.1:65003/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 9187 T3617 C106 P26763 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 9186 T3557 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 9187 T3617 C106 P26763 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 9188 T3617 C106 P26763 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 9188 T3617 C106 P26763 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C107 name=collection1 org.apache.solr.core.SolrCore@739b3991 url=http://127.0.0.1:65003/solr/collection1 node=127.0.0.1:65003_solr
[junit4:junit4]   2> 9196 T3583 C107 P65003 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=0 
[junit4:junit4]   2> 9422 T3578 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9437 T3603 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9437 T3577 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9437 T3615 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9437 T3591 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9881 T3557 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 9884 T3557 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:11546
[junit4:junit4]   2> 9885 T3557 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 9885 T3557 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty4-1348244850525
[junit4:junit4]   2> 9886 T3557 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty4-1348244850525/'
[junit4:junit4]   2> 9921 T3557 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 9921 T3557 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 9922 T3557 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty4-1348244850525
[junit4:junit4]   2> 9922 T3557 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty4-1348244850525/solr.xml
[junit4:junit4]   2> 9922 T3557 oasc.CoreContainer.<init> New CoreContainer 1364183770
[junit4:junit4]   2> 9923 T3557 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty4-1348244850525/'
[junit4:junit4]   2> 9924 T3557 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty4-1348244850525/'
[junit4:junit4]   2> 9942 T3557 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 9952 T3557 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:55943/solr
[junit4:junit4]   2> 9952 T3557 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:55943/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@5d016b6d
[junit4:junit4]   2> 9953 T3628 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:55943
[junit4:junit4]   2> 9953 T3557 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 9953 T3628 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:55943, initiating session
[junit4:junit4]   2> 9954 T3559 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:24399
[junit4:junit4]   2> 9954 T3559 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:24399
[junit4:junit4]   2> 9955 T3561 oazs.NIOServerCnxn.finishSessionInit Established session 0x139e9a7a3760006 with negotiated timeout 5000 for client /140.211.11.196:24399
[junit4:junit4]   2> 9956 T3628 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:55943, sessionid = 0x139e9a7a3760006, negotiated timeout = 5000
[junit4:junit4]   2> 9956 T3629 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5d016b6d name:ZooKeeperConnection Watcher:127.0.0.1:55943/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 9956 T3557 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 9956 T3562 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e9a7a3760006 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 9965 T3562 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e9a7a3760006 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 9966 T3557 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:11546_solr
[junit4:junit4]   2> 9966 T3562 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e9a7a3760006 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:11546_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:11546_solr
[junit4:junit4]   2> 9968 T3557 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:11546_solr
[junit4:junit4]   2> 9977 T3603 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 9977 T3615 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 9977 T3591 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 9977 T3577 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 9978 T3557 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 9978 T3557 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 9979 T3557 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 9979 T3557 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 9979 T3557 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 9979 T3557 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 9980 T3557 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 9980 T3557 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 9980 T3557 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 9981 T3557 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 9991 T3557 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 9995 T3557 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty4-1348244850525/collection1
[junit4:junit4]   2> 9995 T3557 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 9996 T3557 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 9996 T3557 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 9997 T3557 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty4-1348244850525/collection1/'
[junit4:junit4]   2> 9998 T3557 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solrtest-jetty4-1348244850525/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 9998 T3557 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solrtest-jetty4-1348244850525/collection1/lib/README' to classloader
[junit4:junit4]   2> 10031 T3557 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_40
[junit4:junit4]   2> 10076 T3557 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 10177 T3557 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 10182 T3557 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 10606 T3557 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 10614 T3557 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 10618 T3557 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 10625 T3557 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 10629 T3557 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 10631 T3557 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 10632 T3557 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 10633 T3557 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solrtest-jetty4-1348244850525/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty4/
[junit4:junit4]   2> 10633 T3557 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5fed27e4
[junit4:junit4]   2> 10634 T3557 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty4/index/
[junit4:junit4]   2> 10635 T3557 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 10635 T3557 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty4/index forceNew:false
[junit4:junit4]   2> 10665 T3557 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-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2c1afe12; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 10665 T3557 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 10666 T3557 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 10668 T3557 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 10668 T3557 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 10668 T3557 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 10669 T3557 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 10669 T3557 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 10670 T3557 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 10670 T3557 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 10671 T3557 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 10671 T3557 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 10672 T3557 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 10672 T3557 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 10672 T3557 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 10673 T3557 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 10673 T3557 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 10674 T3557 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 10674 T3557 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 10674 T3557 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10675 T3557 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10675 T3557 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10676 T3557 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10676 T3557 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10677 T3557 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10677 T3557 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10678 T3557 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 10678 T3557 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 10681 T3557 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 10684 T3557 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 10685 T3557 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> 10688 T3557 oass.SolrIndexSearcher.<init> Opening Searcher@5d344985 main
[junit4:junit4]   2> 10689 T3557 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 10690 T3557 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 10690 T3557 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 10718 T3557 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 10762 T3630 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5d344985 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 10948 T3578 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 10962 T3615 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10962 T3591 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10962 T3629 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10962 T3603 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10962 T3577 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11267 T3557 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 11267 T3557 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:11546/solr shardId:shard2
[junit4:junit4]   2> 11274 T3557 oasc.ZkController.register We are http://127.0.0.1:11546/solr/collection1/ and leader is http://127.0.0.1:25098/solr/collection1/
[junit4:junit4]   2> 11275 T3557 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:11546/solr
[junit4:junit4]   2> 11275 T3557 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 11275 T3557 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C108 name=collection1 org.apache.solr.core.SolrCore@79287502 url=http://127.0.0.1:11546/solr/collection1 node=127.0.0.1:11546_solr
[junit4:junit4]   2> 11277 T3631 C108 P11546 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 11278 T3631 C108 P11546 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 11278 T3557 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 11280 T3631 C108 P11546 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:25098/solr/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 11280 T3631 C108 P11546 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:11546/solr START replicas=[http://127.0.0.1:25098/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 11280 T3557 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1
[junit4:junit4]   2> 11281 T3631 C108 P11546 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 11281 T3631 C108 P11546 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 11281 T3557 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 11281 T3631 C108 P11546 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 11282 T3631 C108 P11546 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 11282 T3557 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C109 name=collection1 org.apache.solr.core.SolrCore@72cea72b url=http://127.0.0.1:25098/solr/collection1 node=127.0.0.1:25098_solr
[junit4:junit4]   2> 11295 T3595 C109 P25098 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=1 
[junit4:junit4]   2> 11296 T3557 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:55943/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@70ec7606
[junit4:junit4]   2> 11297 T3633 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:55943
[junit4:junit4]   2> 11297 T3557 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 11298 T3633 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:55943, initiating session
[junit4:junit4]   2> 11298 T3559 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:36573
[junit4:junit4]   2> 11298 T3559 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:36573
[junit4:junit4]   2> 11299 T3561 oazs.NIOServerCnxn.finishSessionInit Established session 0x139e9a7a3760007 with negotiated timeout 10000 for client /140.211.11.196:36573
[junit4:junit4]   2> 11299 T3633 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:55943, sessionid = 0x139e9a7a3760007, negotiated timeout = 10000
[junit4:junit4]   2> 11300 T3634 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@70ec7606 name:ZooKeeperConnection Watcher:127.0.0.1:55943/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 11300 T3557 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 11301 T3557 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 11302 T3557 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   2> 11302 T3557 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 11311 T3557 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> ASYNC  NEW_CORE C110 name=collection1 org.apache.solr.core.SolrCore@594cd77 url=http://127.0.0.1:34524/solr/collection1 node=127.0.0.1:34524_solr
[junit4:junit4]   2> 11324 T3569 C110 P34524 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-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@27309f8c; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 11325 T3569 C110 P34524 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 11327 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[1 (1413737194606034944)]} 0 6
[junit4:junit4]   2> 11328 T3557 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:55943/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@149ea865
[junit4:junit4]   2> 11329 T3635 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:55943
[junit4:junit4]   2> 11329 T3557 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 11329 T3635 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:55943, initiating session
[junit4:junit4]   2> 11330 T3559 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:21796
[junit4:junit4]   2> 11330 T3559 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:21796
[junit4:junit4]   2> 11331 T3561 oazs.NIOServerCnxn.finishSessionInit Established session 0x139e9a7a3760008 with negotiated timeout 10000 for client /140.211.11.196:21796
[junit4:junit4]   2> 11331 T3635 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:55943, sessionid = 0x139e9a7a3760008, negotiated timeout = 10000
[junit4:junit4]   2> 11331 T3636 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@149ea865 name:ZooKeeperConnection Watcher:127.0.0.1:55943/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 11331 T3557 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 11332 T3557 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 11338 T3585 C107 P65003 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-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@b5185c; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 11339 T3585 C107 P65003 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2>  C106_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:26763_solr, base_url=http://127.0.0.1:26763/solr}
[junit4:junit4]   2> 11354 T3607 C106 P26763 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-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty3/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@26c18bd1; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 11355 T3607 C106 P26763 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 11357 T3607 C106 P26763 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:65003/solr/collection1/&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 11358 T3585 C107 P65003 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=23 
[junit4:junit4]   2> 11358 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[1]} 0 24
[junit4:junit4]   2> 11359 T3557 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):3600
[junit4:junit4]   2> 11360 T3557 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 11464 T3578 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 11479 T3603 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11479 T3591 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11479 T3629 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11479 T3634 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11479 T3615 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11479 T3636 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11479 T3577 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12204 T3617 C106 P26763 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 12204 T3617 C106 P26763 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=tlog{file=./org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty3/tlog/tlog.0000000000000000000 refcount=1}}
[junit4:junit4]   2> 12204 T3617 C106 P26763 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:65003/solr/collection1/. core=collection1
[junit4:junit4]   2> 12204 T3617 C106 P26763 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 12213 T3586 C107 P65003 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 12356 T3586 C107 P65003 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-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@b5185c; 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-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@b5185c; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0_MockSep_0.pos, _0_MockFixedIntBlock_0.tib, _0_Pulsing40_0.prx, _0_Pulsing40_0.frq, _0_MockFixedIntBlock_0.pyl, _0_MockFixedIntBlock_0.skp, _0_MockSep_0.skp, _0_MockFixedIntBlock_0.tii, _0_Pulsing40_0.tip, _0.si, _0_MockSep_0.doc, _0.fnm, _0_Pulsing40_0.tim, _0_MockFixedIntBlock_0.pos, _0_nrm.cfs, _0_MockRandom_0.skp, _0_MockFixedIntBlock_0.frq, _0_MockSep_0.tib, _0_MockRandom_0.sd, _0_MockRandom_0.frq, _0_MockRandom_0.tip, _0_MockFixedIntBlock_0.doc, _0_MockRandom_0.doc, _0_MockRandom_0.pos, _0_nrm.cfe, _0_MockSep_0.frq, segments_2, _0.fdx, _0_MockSep_0.tii, _0_MockRandom_0.pyl, _0_MockSep_0.pyl, _0_MockRandom_0.tim, _0.fdt]
[junit4:junit4]   2> 12357 T3586 C107 P65003 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 12361 T3557 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12370 T3586 C107 P65003 oass.SolrIndexSearcher.<init> Opening Searcher@2d5608cd main
[junit4:junit4]   2> 12370 T3586 C107 P65003 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 12371 T3592 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2d5608cd main{StandardDirectoryReader(segments_2:3 _0(4.0.0.2):C1)}
[junit4:junit4]   2> 12372 T3586 C107 P65003 /update {waitSearcher=true&commit=true&commit_end_point=true&wt=javabin&softCommit=false&version=2} {commit=} 0 159
[junit4:junit4]   2> 12372 T3617 C106 P26763 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 12372 T3617 C106 P26763 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 12373 T3587 C107 P65003 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 12374 T3587 C107 P65003 REQ /replication {command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
[junit4:junit4]   2> 12374 T3617 C106 P26763 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4]   2> 12374 T3617 C106 P26763 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 12374 T3617 C106 P26763 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 12378 T3587 C107 P65003 REQ /replication {command=filelist&generation=2&wt=javabin&qt=/replication&version=2} status=0 QTime=2 
[junit4:junit4]   2> 12379 T3617 C106 P26763 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 33
[junit4:junit4]   2> 12385 T3617 C106 P26763 oash.SnapPuller.fetchLatestIndex Starting download to ./org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty3/index.20120922032733702 fullCopy=true
[junit4:junit4]   2> 12388 T3587 C107 P65003 REQ /replication {file=_0_MockSep_0.pos&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12392 T3587 C107 P65003 REQ /replication {file=_0_Pulsing40_0.prx&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12395 T3587 C107 P65003 REQ /replication {file=_0_MockFixedIntBlock_0.tib&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12398 T3587 C107 P65003 REQ /replication {file=_0_Pulsing40_0.frq&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12401 T3587 C107 P65003 REQ /replication {file=_0_MockFixedIntBlock_0.skp&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12401 T3617 C106 P26763 oash.SnapPuller$FileFetcher.fetchPackets WARNING No content recieved for file: {name=_0_MockFixedIntBlock_0.skp, lastmodified=1348244853000, size=0}
[junit4:junit4]   2> 12405 T3587 C107 P65003 REQ /replication {file=_0_MockFixedIntBlock_0.pyl&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12406 T3617 C106 P26763 oash.SnapPuller$FileFetcher.fetchPackets WARNING No content recieved for file: {name=_0_MockFixedIntBlock_0.pyl, lastmodified=1348244853000, size=0}
[junit4:junit4]   2> 12408 T3587 C107 P65003 REQ /replication {file=_0_MockSep_0.skp&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12408 T3617 C106 P26763 oash.SnapPuller$FileFetcher.fetchPackets WARNING No content recieved for file: {name=_0_MockSep_0.skp, lastmodified=1348244853000, size=0}
[junit4:junit4]   2> 12411 T3587 C107 P65003 REQ /replication {file=_0_MockFixedIntBlock_0.tii&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12414 T3587 C107 P65003 REQ /replication {file=_0_Pulsing40_0.tip&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12417 T3587 C107 P65003 REQ /replication {file=_0_MockSep_0.doc&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12420 T3587 C107 P65003 REQ /replication {file=_0.si&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12423 T3587 C107 P65003 REQ /replication {file=_0_Pulsing40_0.tim&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12426 T3587 C107 P65003 REQ /replication {file=_0.fnm&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12429 T3587 C107 P65003 REQ /replication {file=_0_MockFixedIntBlock_0.pos&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12432 T3587 C107 P65003 REQ /replication {file=_0_nrm.cfs&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12435 T3587 C107 P65003 REQ /replication {file=_0_MockRandom_0.skp&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12436 T3617 C106 P26763 oash.SnapPuller$FileFetcher.fetchPackets WARNING No content recieved for file: {name=_0_MockRandom_0.skp, lastmodified=1348244853000, size=0}
[junit4:junit4]   2> 12439 T3587 C107 P65003 REQ /replication {file=_0_MockSep_0.tib&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12443 T3587 C107 P65003 REQ /replication {file=_0_MockFixedIntBlock_0.frq&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12447 T3587 C107 P65003 REQ /replication {file=_0_MockRandom_0.tip&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12450 T3587 C107 P65003 REQ /replication {file=_0_MockRandom_0.frq&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12453 T3587 C107 P65003 REQ /replication {file=_0_MockRandom_0.sd&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12457 T3587 C107 P65003 REQ /replication {file=_0_MockRandom_0.doc&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12460 T3587 C107 P65003 REQ /replication {file=_0_MockFixedIntBlock_0.doc&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12464 T3587 C107 P65003 REQ /replication {file=_0_nrm.cfe&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12468 T3587 C107 P65003 REQ /replication {file=_0_MockRandom_0.pos&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12471 T3587 C107 P65003 REQ /replication {file=segments_2&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12474 T3587 C107 P65003 REQ /replication {file=_0_MockSep_0.frq&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12478 T3587 C107 P65003 REQ /replication {file=_0.fdx&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12481 T3587 C107 P65003 REQ /replication {file=_0_MockSep_0.tii&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12485 T3587 C107 P65003 REQ /replication {file=_0_MockSep_0.pyl&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12486 T3617 C106 P26763 oash.SnapPuller$FileFetcher.fetchPackets WARNING No content recieved for file: {name=_0_MockSep_0.pyl, lastmodified=1348244853000, size=0}
[junit4:junit4]   2> 12489 T3587 C107 P65003 REQ /replication {file=_0_MockRandom_0.pyl&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12490 T3617 C106 P26763 oash.SnapPuller$FileFetcher.fetchPackets WARNING No content recieved for file: {name=_0_MockRandom_0.pyl, lastmodified=1348244853000, size=0}
[junit4:junit4]   2> 12493 T3587 C107 P65003 REQ /replication {file=_0_MockRandom_0.tim&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12496 T3587 C107 P65003 REQ /replication {file=_0.fdt&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 12497 T3617 C106 P26763 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 12497 T3617 C106 P26763 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20120922032733702
[junit4:junit4]   2> 12499 T3617 C106 P26763 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 12499 T3617 C106 P26763 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 12499 T3617 C106 P26763 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4]   2> 12502 T3617 C106 P26763 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=./org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty3/index/ new=./org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty3/index.20120922032733702
[junit4:junit4]   2> 12503 T3617 C106 P26763 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty3/index.20120922032733702 forceNew:true
[junit4:junit4]   2> 12515 T3617 C106 P26763 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-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty3/index.20120922032733702 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6c795551; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0_MockSep_0.pos, _0_Pulsing40_0.prx, _0_MockFixedIntBlock_0.tib, _0_Pulsing40_0.frq, _0_MockFixedIntBlock_0.skp, _0_MockFixedIntBlock_0.pyl, _0_MockSep_0.skp, _0_MockFixedIntBlock_0.tii, _0_Pulsing40_0.tip, _0_MockSep_0.doc, _0.si, _0_Pulsing40_0.tim, _0.fnm, _0_MockFixedIntBlock_0.pos, _0_nrm.cfs, _0_MockRandom_0.skp, _0_MockFixedIntBlock_0.frq, _0_MockSep_0.tib, _0_MockRandom_0.sd, _0_MockRandom_0.frq, _0_MockRandom_0.tip, _0_MockFixedIntBlock_0.doc, _0_MockRandom_0.doc, _0_MockRandom_0.pos, _0_nrm.cfe, _0_MockSep_0.frq, segments_2, _0.fdx, _0_MockSep_0.tii, _0_MockSep_0.pyl, _0_MockRandom_0.pyl, _0_MockRandom_0.tim, _0.fdt]
[junit4:junit4]   2> 12515 T3617 C106 P26763 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 12515 T3617 C106 P26763 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 12519 T3617 C106 P26763 oass.SolrIndexSearcher.<init> Opening Searcher@7d548680 main
[junit4:junit4]   2> 12521 T3616 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7d548680 main{StandardDirectoryReader(segments_2:3:nrt _0(4.0.0.2):C1)}
[junit4:junit4]   2> 12521 T3616 oasc.CachingDirectoryFactory.close Closing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty3/index
[junit4:junit4]   2> 12521 T3616 oash.SnapPuller$2.onClose removing old index directory ./org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty3/index
[junit4:junit4]   2> 12523 T3617 C106 P26763 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=false,waitSearcher=false,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 12524 T3617 C106 P26763 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 12524 T3617 C106 P26763 oasc.RecoveryStrategy.replay Replaying buffered documents. core=collection1
[junit4:junit4]   2> 12524 T3640 C106 P26763 oasu.UpdateLog$LogReplayer.doReplay WARNING Starting log replay tlog{file=./org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty3/tlog/tlog.0000000000000000000 refcount=2} active=true starting pos=430
[junit4:junit4]   2> 12525 T3640 C106 P26763 oasu.DirectUpdateHandler2.commit start commit{flags=2,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 12526 T3640 C106 P26763 oass.SolrIndexSearcher.<init> Opening Searcher@4851e378 main
[junit4:junit4]   2> 12527 T3640 C106 P26763 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 12527 T3616 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4851e378 main{StandardDirectoryReader(segments_2:3:nrt _0(4.0.0.2):C1)}
[junit4:junit4]   2> 12528 T3640 C106 P26763 oasu.UpdateLog$LogReplayer.run WARNING Log replay finished. recoveryInfo=RecoveryInfo{adds=0 deletes=0 deleteByQuery=0 errors=0 positionOfStart=430}
[junit4:junit4]   2> 12528 T3617 C106 P26763 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 12530 T3617 C106 P26763 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 12984 T3578 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12996 T3615 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12996 T3629 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12996 T3591 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12996 T3577 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12996 T3634 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12996 T3636 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12996 T3603 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 13363 T3557 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2>  C108_STATE=coll:collection1 core:collection1 props:{shard=shard2, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:11546_solr, base_url=http://127.0.0.1:11546/solr}
[junit4:junit4]   2> 14299 T3631 C108 P11546 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 14299 T3631 C108 P11546 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 14299 T3631 C108 P11546 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:25098/solr/collection1/. core=collection1
[junit4:junit4]   2> 14299 T3631 C108 P11546 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 14315 T3598 C109 P25098 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 14318 T3598 C109 P25098 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-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@29cc77ef; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 14319 T3598 C109 P25098 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 14320 T3598 C109 P25098 oass.SolrIndexSearcher.<init> Opening Searcher@360377d1 main
[junit4:junit4]   2> 14320 T3598 C109 P25098 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 14321 T3604 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@360377d1 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 14322 T3598 C109 P25098 /update {waitSearcher=true&commit=true&commit_end_point=true&wt=javabin&softCommit=false&version=2} {commit=} 0 7
[junit4:junit4]   2> 14322 T3631 C108 P11546 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 14323 T3631 C108 P11546 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 14324 T3599 C109 P25098 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 14324 T3599 C109 P25098 REQ /replication {command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14328 T3631 C108 P11546 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-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2c1afe12; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 14328 T3631 C108 P11546 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 14329 T3631 C108 P11546 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 14332 T3631 C108 P11546 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-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2c1afe12; 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-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2c1afe12; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 14332 T3631 C108 P11546 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 14335 T3631 C108 P11546 oass.SolrIndexSearcher.<init> Opening Searcher@5d773bf9 main
[junit4:junit4]   2> 14336 T3631 C108 P11546 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 14337 T3630 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5d773bf9 main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 14337 T3631 C108 P11546 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 14337 T3631 C108 P11546 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 14339 T3631 C108 P11546 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 14365 T3557 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 14500 T3578 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 14511 T3603 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14511 T3615 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14511 T3577 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14511 T3636 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14511 T3629 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14511 T3591 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14511 T3634 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 15367 T3557 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 15370 T3569 C110 P34524 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 15574 T3569 C110 P34524 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-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@27309f8c; 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-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@27309f8c; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0_MockSep_0.pos, _0_MockFixedIntBlock_0.tib, _0_Pulsing40_0.prx, _0_Pulsing40_0.frq, _0_MockFixedIntBlock_0.pyl, _0_MockFixedIntBlock_0.skp, _0_MockSep_0.skp, _0_MockFixedIntBlock_0.tii, _0_Pulsing40_0.tip, _0.si, _0_MockSep_0.doc, _0_MockRandom_0.tib, _0.fnm, _0_Pulsing40_0.tim, _0_MockFixedIntBlock_0.pos, _0_nrm.cfs, _0_MockRandom_0.skp, _0_MockFixedIntBlock_0.frq, _0_MockSep_0.tib, _0_MockRandom_0.sd, _0_MockRandom_0.frq, _0_MockRandom_0.tiv, _0_MockFixedIntBlock_0.doc, _0_MockRandom_0.doc, _0_MockRandom_0.pos, _0_nrm.cfe, _0_MockSep_0.frq, segments_2, _0.fdx, _0_MockSep_0.tii, _0_MockRandom_0.pyl, _0_MockSep_0.pyl, _0.fdt]
[junit4:junit4]   2> 15574 T3569 C110 P34524 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 15587 T3569 C110 P34524 oass.SolrIndexSearcher.<init> Opening Searcher@1668f412 main
[junit4:junit4]   2> 15588 T3569 C110 P34524 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 15589 T3580 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1668f412 main{StandardDirectoryReader(segments_2:3 _0(4.0.0.2):C1)}
[junit4:junit4]   2> 15590 T3569 C110 P34524 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 220
[junit4:junit4]   2> 15591 T3588 C107 P65003 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 15604 T3588 C107 P65003 oass.SolrIndexSearcher.<init> Opening Searcher@5157cfbc main
[junit4:junit4]   2> 15605 T3588 C107 P65003 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 15605 T3592 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5157cfbc main{StandardDirectoryReader(segments_2:3 _0(4.0.0.2):C1)}
[junit4:junit4]   2> 15606 T3588 C107 P65003 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:26763/solr/collection1/, StdNode: http://127.0.0.1:25098/solr/collection1/, StdNode: http://127.0.0.1:11546/solr/collection1/]
[junit4:junit4]   2> 15608 T3600 C109 P25098 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2>  C106_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:26763_solr, base_url=http://127.0.0.1:26763/solr}
[junit4:junit4]   2> 15608 T3607 C106 P26763 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 15611 T3607 C106 P26763 oass.SolrIndexSearcher.<init> Opening Searcher@4c9a8c17 main
[junit4:junit4]   2> 15611 T3607 C106 P26763 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 15612 T3616 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4c9a8c17 main{StandardDirectoryReader(segments_2:3:nrt _0(4.0.0.2):C1)}
[junit4:junit4]   2> 15613 T3607 C106 P26763 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&expungeDeletes=false&softCommit=false&version=2} {commit=} 0 5
[junit4:junit4]   2> 15613 T3600 C109 P25098 oass.SolrIndexSearcher.<init> Opening Searcher@36889ed2 main
[junit4:junit4]   2> 15613 T3600 C109 P25098 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 15615 T3604 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@36889ed2 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 15616 T3600 C109 P25098 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&expungeDeletes=false&softCommit=false&version=2} {commit=} 0 8
[junit4:junit4]   2>  C108_STATE=coll:collection1 core:collection1 props:{shard=shard2, roles=null, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:11546_solr, base_url=http://127.0.0.1:11546/solr}
[junit4:junit4]   2> 15618 T3621 C108 P11546 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 15622 T3621 C108 P11546 oass.SolrIndexSearcher.<init> Opening Searcher@2ed7b66b main
[junit4:junit4]   2> 15622 T3621 C108 P11546 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 15623 T3630 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2ed7b66b main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 15624 T3621 C108 P11546 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&expungeDeletes=false&softCommit=false&version=2} {commit=} 0 6
[junit4:junit4]   2> 15624 T3588 C107 P65003 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 33
[junit4:junit4]   2> 15629 T3570 C110 P34524 REQ /select {fl=id,score&shard.url=127.0.0.1:34524/solr/collection1/&NOW=1348244856950&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 15632 T3570 C110 P34524 REQ /select {shard.url=127.0.0.1:34524/solr/collection1/&NOW=1348244856950&q=*:*&ids=1&distrib=false&isShard=true&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 15633 T3569 C110 P34524 REQ /select {wt=javabin&q=*:*&version=2} hits=1 status=0 QTime=6 
[junit4:junit4]   2> 15633 T3557 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:55943/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@268956a3
[junit4:junit4]   2> 15634 T3644 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:55943
[junit4:junit4]   2> 15634 T3557 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 15635 T3644 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:55943, initiating session
[junit4:junit4]   2> 15635 T3559 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:28828
[junit4:junit4]   2> 15635 T3559 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:28828
[junit4:junit4]   2> 15637 T3561 oazs.NIOServerCnxn.finishSessionInit Established session 0x139e9a7a3760009 with negotiated timeout 10000 for client /140.211.11.196:28828
[junit4:junit4]   2> 15637 T3644 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:55943, sessionid = 0x139e9a7a3760009, negotiated timeout = 10000
[junit4:junit4]   2> 15637 T3645 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@268956a3 name:ZooKeeperConnection Watcher:127.0.0.1:55943/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 15637 T3557 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 15638 T3557 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 15639 T3562 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x139e9a7a3760009
[junit4:junit4]   2> 15640 T3645 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 15640 T3559 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:28828 which had sessionid 0x139e9a7a3760009
[junit4:junit4]   2> 15640 T3557 oaz.ZooKeeper.close Session: 0x139e9a7a3760009 closed
[junit4:junit4]   2> 15642 T3589 C107 P65003 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 15643 T3601 C109 P25098 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 15647 T3584 C107 P65003 REQ /select {fl=id,score&shard.url=127.0.0.1:65003/solr/collection1/|127.0.0.1:26763/solr/collection1/&NOW=1348244856968&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 15647 T3596 C109 P25098 REQ /select {fl=id,score&shard.url=127.0.0.1:25098/solr/collection1/|127.0.0.1:11546/solr/collection1/&NOW=1348244856968&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 15650 T3584 C107 P65003 REQ /select {shard.url=127.0.0.1:65003/solr/collection1/|127.0.0.1:26763/solr/collection1/&NOW=1348244856968&q=*:*&ids=1&distrib=false&isShard=true&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 15650 T3608 C106 P26763 REQ /select {wt=javabin&q=*:*&version=2} hits=1 status=0 QTime=5 
[junit4:junit4]   2> 15655 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[2 (1413737199148466176)]} 0 2
[junit4:junit4]   2> 15666 T3621 C108 P11546 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:25098/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15667 T3600 C109 P25098 REQ /update {distrib.from=http://127.0.0.1:65003/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 15667 T3588 C107 P65003 /update {wt=javabin&version=2} {add=[2]} 0 9
[junit4:junit4]   2> 15670 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[3 (1413737199166291968)]} 0 0
[junit4:junit4]   2> 15678 T3621 C108 P11546 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:25098/solr/collection1/&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 15679 T3600 C109 P25098 REQ /update {distrib.from=http://127.0.0.1:65003/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 15679 T3588 C107 P65003 /update {wt=javabin&version=2} {add=[3]} 0 6
[junit4:junit4]   2> 15682 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[4 (1413737199178874880)]} 0 0
[junit4:junit4]   2> 15692 T3607 C106 P26763 REQ /update {distrib.from=http://127.0.0.1:65003/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15693 T3588 C107 P65003 /update {wt=javabin&version=2} {add=[4 (1413737199182020608)]} 0 8
[junit4:junit4]   2> 15695 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[5 (1413737199192506368)]} 0 0
[junit4:junit4]   2> 15702 T3621 C108 P11546 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:25098/solr/collection1/&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 15703 T3600 C109 P25098 REQ /update {distrib.from=http://127.0.0.1:65003/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 15703 T3588 C107 P65003 /update {wt=javabin&version=2} {add=[5]} 0 5
[junit4:junit4]   2> 15706 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[6 (1413737199204040704)]} 0 0
[junit4:junit4]   2> 15713 T3621 C108 P11546 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:25098/solr/collection1/&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 15714 T3600 C109 P25098 REQ /update {distrib.from=http://127.0.0.1:65003/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 15714 T3588 C107 P65003 /update {wt=javabin&version=2} {add=[6]} 0 5
[junit4:junit4]   2> 15717 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[7 (1413737199215575040)]} 0 0
[junit4:junit4]   2> 15724 T3621 C108 P11546 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:25098/solr/collection1/&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 15725 T3600 C109 P25098 REQ /update {distrib.from=http://127.0.0.1:65003/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 15725 T3588 C107 P65003 /update {wt=javabin&version=2} {add=[7]} 0 5
[junit4:junit4]   2> 15728 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[8 (1413737199227109376)]} 0 0
[junit4:junit4]   2> 15735 T3607 C106 P26763 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:65003/solr/collection1/&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 15736 T3585 C107 P65003 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 15736 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[8]} 0 5
[junit4:junit4]   2> 15739 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[9 (1413737199238643712)]} 0 0
[junit4:junit4]   2> 15745 T3621 C108 P11546 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 15746 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[9 (1413737199241789440)]} 0 4
[junit4:junit4]   2> 15748 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[10 (1413737199248080896)]} 0 0
[junit4:junit4]   2> 15755 T3607 C106 P26763 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:65003/solr/collection1/&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 15756 T3585 C107 P65003 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 15756 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[10]} 0 5
[junit4:junit4]   2> 15771 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[11 (1413737199259615232)]} 0 12
[junit4:junit4]   2> 15779 T3607 C106 P26763 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:65003/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15779 T3585 C107 P65003 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 15779 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[11]} 0 5
[junit4:junit4]   2> 15783 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[12 (1413737199283732480)]} 0 1
[junit4:junit4]   2> 15788 T3607 C106 P26763 REQ /update {distrib.from=http://127.0.0.1:65003/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 15789 T3588 C107 P65003 /update {wt=javabin&version=2} {add=[12 (1413737199287926784)]} 0 3
[junit4:junit4]   2> 15791 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[13 (1413737199293169664)]} 0 0
[junit4:junit4]   2> 15798 T3607 C106 P26763 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:65003/solr/collection1/&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 15799 T3585 C107 P65003 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 15799 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[13]} 0 5
[junit4:junit4]   2> 15802 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[14 (1413737199304704000)]} 0 0
[junit4:junit4]   2> 15807 T3607 C106 P26763 REQ /update {distrib.from=http://127.0.0.1:65003/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 15808 T3588 C107 P65003 /update {wt=javabin&version=2} {add=[14 (1413737199307849728)]} 0 3
[junit4:junit4]   2> 15811 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[15 (1413737199314141184)]} 0 0
[junit4:junit4]   2> 15815 T3607 C106 P26763 REQ /update {distrib.from=http://127.0.0.1:65003/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 15816 T3588 C107 P65003 /update {wt=javabin&version=2} {add=[15 (1413737199316238336)]} 0 3
[junit4:junit4]   2> 15818 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[16 (1413737199321481216)]} 0 0
[junit4:junit4]   2> 15825 T3607 C106 P26763 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:65003/solr/collection1/&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 15825 T3585 C107 P65003 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15826 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[16]} 0 5
[junit4:junit4]   2> 15829 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[17 (1413737199331966976)]} 0 1
[junit4:junit4]   2> 15835 T3621 C108 P11546 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15835 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[17 (1413737199335112704)]} 0 4
[junit4:junit4]   2> 15839 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[100 (1413737199342452736)]} 0 1
[junit4:junit4]   2> 15871 T3607 C106 P26763 REQ /update {distrib.from=http://127.0.0.1:65003/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=14 
[junit4:junit4]   2> 15871 T3588 C107 P65003 /update {wt=javabin&version=2} {add=[100 (1413737199345598464)]} 0 30
[junit4:junit4]   2> 15875 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[101 (1413737199380201472)]} 0 0
[junit4:junit4]   2> 15881 T3607 C106 P26763 REQ /update {distrib.from=http://127.0.0.1:65003/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15882 T3588 C107 P65003 /update {wt=javabin&version=2} {add=[101 (1413737199383347200)]} 0 5
[junit4:junit4]   2> 15884 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[102 (1413737199390687232)]} 0 0
[junit4:junit4]   2> 15891 T3607 C106 P26763 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:65003/solr/collection1/&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 15892 T3585 C107 P65003 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 15892 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[102]} 0 5
[junit4:junit4]   2> 15905 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[103 (1413737199402221568)]} 0 10
[junit4:junit4]   2> 15913 T3621 C108 P11546 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:25098/solr/collection1/&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 15914 T3600 C109 P25098 REQ /update {distrib.from=http://127.0.0.1:65003/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 15914 T3588 C107 P65003 /update {wt=javabin&version=2} {add=[103]} 0 6
[junit4:junit4]   2> 15920 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[104 (1413737199427387392)]} 0 1
[junit4:junit4]   2> 15928 T3621 C108 P11546 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:25098/solr/collection1/&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 15928 T3600 C109 P25098 REQ /update {distrib.from=http://127.0.0.1:65003/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 15929 T3588 C107 P65003 /update {wt=javabin&version=2} {add=[104]} 0 6
[junit4:junit4]   2> 15931 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[105 (1413737199439970304)]} 0 0
[junit4:junit4]   2> 15961 T3621 C108 P11546 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:25098/solr/collection1/&wt=javabin&version=2} status=0 QTime=10 
[junit4:junit4]   2> 15961 T3600 C109 P25098 REQ /update {distrib.from=http://127.0.0.1:65003/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=26 
[junit4:junit4]   2> 15962 T3588 C107 P65003 /update {wt=javabin&version=2} {add=[105]} 0 29
[junit4:junit4]   2> 15965 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[106 (1413737199475621888)]} 0 0
[junit4:junit4]   2> 15974 T3621 C108 P11546 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:25098/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15974 T3600 C109 P25098 REQ /update {distrib.from=http://127.0.0.1:65003/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 15975 T3588 C107 P65003 /update {wt=javabin&version=2} {add=[106]} 0 7
[junit4:junit4]   2> 15977 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[107 (1413737199488204800)]} 0 0
[junit4:junit4]   2> 15983 T3607 C106 P26763 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:65003/solr/collection1/&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 15984 T3585 C107 P65003 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 15984 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[107]} 0 5
[junit4:junit4]   2> 15987 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[108 (1413737199498690560)]} 0 0
[junit4:junit4]   2> 15994 T3607 C106 P26763 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:65003/solr/collection1/&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 15995 T3585 C107 P65003 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 15995 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[108]} 0 5
[junit4:junit4]   2> 15998 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[109 (1413737199510224896)]} 0 0
[junit4:junit4]   2> 16004 T3607 C106 P26763 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:65003/solr/collection1/&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16005 T3585 C107 P65003 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 16005 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[109]} 0 5
[junit4:junit4]   2> 16008 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[110 (1413737199520710656)]} 0 0
[junit4:junit4]   2> 16014 T3607 C106 P26763 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:65003/solr/collection1/&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16015 T3585 C107 P65003 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 16015 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[110]} 0 5
[junit4:junit4]   2> 16018 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[111 (1413737199531196416)]} 0 0
[junit4:junit4]   2> 16025 T3607 C106 P26763 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:65003/solr/collection1/&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16026 T3585 C107 P65003 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 16026 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[111]} 0 5
[junit4:junit4]   2> 16029 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[112 (1413737199542730752)]} 0 0
[junit4:junit4]   2> 16036 T3621 C108 P11546 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:25098/solr/collection1/&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16036 T3600 C109 P25098 REQ /update {distrib.from=http://127.0.0.1:65003/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 16037 T3588 C107 P65003 /update {wt=javabin&version=2} {add=[112]} 0 5
[junit4:junit4]   2> 16047 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[113 (1413737199553216512)]} 0 8
[junit4:junit4]   2> 16054 T3607 C106 P26763 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:65003/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16054 T3585 C107 P65003 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 16055 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[113]} 0 6
[junit4:junit4]   2> 16058 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[114 (1413737199572090880)]} 0 1
[junit4:junit4]   2> 16062 T3607 C106 P26763 REQ /update {distrib.from=http://127.0.0.1:65003/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16063 T3588 C107 P65003 /update {wt=javabin&version=2} {add=[114 (1413737199575236608)]} 0 3
[junit4:junit4]   2> 16065 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[115 (1413737199580479488)]} 0 0
[junit4:junit4]   2> 16069 T3621 C108 P11546 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16070 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[115 (1413737199582576640)]} 0 3
[junit4:junit4]   2> 16072 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[116 (1413737199587819520)]} 0 0
[junit4:junit4]   2> 16078 T3621 C108 P11546 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:25098/solr/collection1/&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16078 T3600 C109 P25098 REQ /update {distrib.from=http://127.0.0.1:65003/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 16079 T3588 C107 P65003 /update {wt=javabin&version=2} {add=[116]} 0 5
[junit4:junit4]   2> 16081 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[117 (1413737199597256704)]} 0 0
[junit4:junit4]   2> 16086 T3621 C108 P11546 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16086 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[117 (1413737199600402432)]} 0 2
[junit4:junit4]   2> 16089 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[118 (1413737199605645312)]} 0 0
[junit4:junit4]   2> 16110 T3607 C106 P26763 REQ /update {distrib.from=http://127.0.0.1:65003/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=10 
[junit4:junit4]   2> 16111 T3588 C107 P65003 /update {wt=javabin&version=2} {add=[118 (1413737199607742464)]} 0 20
[junit4:junit4]   2> 16114 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[119 (1413737199631859712)]} 0 0
[junit4:junit4]   2> 16119 T3621 C108 P11546 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16119 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[119 (1413737199635005440)]} 0 2
[junit4:junit4]   2> 16122 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[120 (1413737199640248320)]} 0 0
[junit4:junit4]   2> 16127 T3621 C108 P11546 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16127 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[120 (1413737199643394048)]} 0 2
[junit4:junit4]   2> 16130 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[121 (1413737199648636928)]} 0 0
[junit4:junit4]   2> 16138 T3621 C108 P11546 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:25098/solr/collection1/&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16138 T3600 C109 P25098 REQ /update {distrib.from=http://127.0.0.1:65003/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 16139 T3588 C107 P65003 /update {wt=javabin&version=2} {add=[121]} 0 6
[junit4:junit4]   2> 16141 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[122 (1413737199660171264)]} 0 0
[junit4:junit4]   2> 16147 T3607 C106 P26763 REQ /update {distrib.from=http://127.0.0.1:65003/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16147 T3588 C107 P65003 /update {wt=javabin&version=2} {add=[122 (1413737199662268416)]} 0 4
[junit4:junit4]   2> 16158 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[123 (1413737199669608448)]} 0 8
[junit4:junit4]   2> 16164 T3607 C106 P26763 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:65003/solr/collection1/&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16165 T3585 C107 P65003 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 16165 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[123]} 0 5
[junit4:junit4]   2> 16169 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[124 (1413737199688482816)]} 0 1
[junit4:junit4]   2> 16173 T3607 C106 P26763 REQ /update {distrib.from=http://127.0.0.1:65003/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16173 T3588 C107 P65003 /update {wt=javabin&version=2} {add=[124 (1413737199691628544)]} 0 2
[junit4:junit4]   2> 16176 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[125 (1413737199696871424)]} 0 0
[junit4:junit4]   2> 16182 T3607 C106 P26763 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:65003/solr/collection1/&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16183 T3585 C107 P65003 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 16183 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[125]} 0 5
[junit4:junit4]   2> 16186 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[126 (1413737199707357184)]} 0 0
[junit4:junit4]   2> 16190 T3621 C108 P11546 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16191 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[126 (1413737199709454336)]} 0 2
[junit4:junit4]   2> 16193 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[127 (1413737199714697216)]} 0 0
[junit4:junit4]   2> 16216 T3621 C108 P11546 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:25098/solr/collection1/&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 16216 T3600 C109 P25098 REQ /update {distrib.from=http://127.0.0.1:65003/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=19 
[junit4:junit4]   2> 16217 T3588 C107 P65003 /update {wt=javabin&version=2} {add=[127]} 0 22
[junit4:junit4]   2> 16219 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[128 (1413737199741960192)]} 0 0
[junit4:junit4]   2> 16227 T3621 C108 P11546 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16228 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[128 (1413737199745105920)]} 0 6
[junit4:junit4]   2> 16231 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[129 (1413737199754543104)]} 0 0
[junit4:junit4]   2> 16237 T3607 C106 P26763 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:65003/solr/collection1/&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16238 T3585 C107 P65003 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 16238 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[129]} 0 5
[junit4:junit4]   2> 16241 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[130 (1413737199765028864)]} 0 0
[junit4:junit4]   2> 16245 T3621 C108 P11546 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16246 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[130 (1413737199767126016)]} 0 3
[junit4:junit4]   2> 16248 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[131 (1413737199772368896)]} 0 0
[junit4:junit4]   2> 16252 T3621 C108 P11546 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16253 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[131 (1413737199774466048)]} 0 3
[junit4:junit4]   2> 16255 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[132 (1413737199779708928)]} 0 0
[junit4:junit4]   2> 16259 T3607 C106 P26763 REQ /update {distrib.from=http://127.0.0.1:65003/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16260 T3588 C107 P65003 /update {wt=javabin&version=2} {add=[132 (1413737199781806080)]} 0 3
[junit4:junit4]   2> 16271 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[133 (1413737199788097536)]} 0 8
[junit4:junit4]   2> 16279 T3607 C106 P26763 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:65003/solr/collection1/&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16280 T3585 C107 P65003 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 16280 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[133]} 0 6
[junit4:junit4]   2> 16284 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[134 (1413737199809069056)]} 0 1
[junit4:junit4]   2> 16291 T3621 C108 P11546 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:25098/solr/collection1/&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16292 T3600 C109 P25098 REQ /update {distrib.from=http://127.0.0.1:65003/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 16292 T3588 C107 P65003 /update {wt=javabin&version=2} {add=[134]} 0 5
[junit4:junit4]   2> 16295 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[135 (1413737199821651968)]} 0 0
[junit4:junit4]   2> 16303 T3607 C106 P26763 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:65003/solr/collection1/&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16304 T3585 C107 P65003 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 16305 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[135]} 0 6
[junit4:junit4]   2> 16307 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[136 (1413737199834234880)]} 0 0
[junit4:junit4]   2> 16312 T3621 C108 P11546 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16312 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[136 (1413737199837380608)]} 0 2
[junit4:junit4]   2> 16315 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[137 (1413737199842623488)]} 0 0
[junit4:junit4]   2> 16320 T3621 C108 P11546 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16321 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[137 (1413737199845769216)]} 0 3
[junit4:junit4]   2> 16323 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[138 (1413737199851012096)]} 0 0
[junit4:junit4]   2> 16331 T3607 C106 P26763 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:65003/solr/collection1/&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16332 T3585 C107 P65003 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 16333 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[138]} 0 7
[junit4:junit4]   2> 16335 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[139 (1413737199863595008)]} 0 0
[junit4:junit4]   2> 16340 T3621 C108 P11546 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16341 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[139 (1413737199866740736)]} 0 3
[junit4:junit4]   2> 16343 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[140 (1413737199871983616)]} 0 0
[junit4:junit4]   2> 16348 T3621 C108 P11546 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16349 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[140 (1413737199875129344)]} 0 3
[junit4:junit4]   2> 16351 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[141 (1413737199880372224)]} 0 0
[junit4:junit4]   2> 16355 T3621 C108 P11546 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16356 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[141 (1413737199882469376)]} 0 3
[junit4:junit4]   2> 16358 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[142 (1413737199887712256)]} 0 0
[junit4:junit4]   2> 16376 T3621 C108 P11546 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 16377 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[142 (1413737199889809408)]} 0 17
[junit4:junit4]   2> 16389 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[143 (1413737199909732352)]} 0 10
[junit4:junit4]   2> 16398 T3621 C108 P11546 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:25098/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16398 T3600 C109 P25098 REQ /update {distrib.from=http://127.0.0.1:65003/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 16399 T3588 C107 P65003 /update {wt=javabin&version=2} {add=[143]} 0 7
[junit4:junit4]   2> 16402 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[144 (1413737199932801024)]} 0 1
[junit4:junit4]   2> 16409 T3621 C108 P11546 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:25098/solr/collection1/&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16410 T3600 C109 P25098 REQ /update {distrib.from=http://127.0.0.1:65003/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 16410 T3588 C107 P65003 /update {wt=javabin&version=2} {add=[144]} 0 5
[junit4:junit4]   2> 16413 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[145 (1413737199945383936)]} 0 0
[junit4:junit4]   2> 16420 T3621 C108 P11546 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:25098/solr/collection1/&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16421 T3600 C109 P25098 REQ /update {distrib.from=http://127.0.0.1:65003/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 16421 T3588 C107 P65003 /update {wt=javabin&version=2} {add=[145]} 0 5
[junit4:junit4]   2> 16424 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[146 (1413737199956918272)]} 0 0
[junit4:junit4]   2> 16444 T3607 C106 P26763 REQ /update {distrib.from=http://127.0.0.1:65003/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 16445 T3588 C107 P65003 /update {wt=javabin&version=2} {add=[146 (1413737199960064000)]} 0 18
[junit4:junit4]   2> 16447 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[147 (1413737199981035520)]} 0 0
[junit4:junit4]   2> 16454 T3621 C108 P11546 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:25098/solr/collection1/&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16455 T3600 C109 P25098 REQ /update {distrib.from=http://127.0.0.1:65003/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 16455 T3588 C107 P65003 /update {wt=javabin&version=2} {add=[147]} 0 5
[junit4:junit4]   2> 16457 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[148 (1413737199991521280)]} 0 0
[junit4:junit4]   2> 16465 T3607 C106 P26763 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:65003/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16465 T3585 C107 P65003 REQ /update {distrib.from=http://127.0.0.1:25098/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 16466 T3597 C109 P25098 /update {wt=javabin&version=2} {add=[148]} 0 7
[junit4:junit4]   2> 16468 T3569 C110 P34524 /update {wt=javabin&version=2} {add=[149 (1413737200003055616)]} 0 0
[junit4:junit4]   2> 16475 T3621 C108 P11546 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:25098/solr/collection1/&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 16476 T3600 C109 P25098 REQ /update {distrib.from=http://127.0.0.1:65003/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 16476 T3588 C107 P65003 /update {wt=javabin&version=2} {add=[149]} 0 5
[junit4:junit4]   2> 16476 T3557 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):3600
[junit4:junit4]   2> 16477 T3557 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 16480 T3569 C110 P34524 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 16995 T3569 C110 P34524 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-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@27309f8c; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0_MockSep_0.pos, _0_MockFixedIntBlock_0.tib, _0_Pulsing40_0.prx, _0_Pulsing40_0.frq, _0_MockFixedIntBlock_0.pyl, _0_MockFixedIntBlock_0.skp, _0_MockSep_0.skp, _0_MockFixedIntBlock_0.tii, _0_Pulsing40_0.tip, _0.si, _0_MockSep_0.doc, _0_MockRandom_0.tib, _0.fnm, _0_Pulsing40_0.tim, _0_MockFixedIntBlock_0.pos, _0_nrm.cfs, _0_MockRandom_0.skp, _0_MockFixedIntBlock_0.frq, _0_MockSep_0.tib, _0_MockRandom_0.sd, _0_MockRandom_0.frq, _0_MockRandom_0.tiv, _0_MockFixedIntBlock_0.doc, _0_MockRandom_0.doc, _0_MockRandom_0.pos, _0_nrm.cfe, _0_MockSep_0.frq, segments_2, _0.fdx, _0_MockSep_0.tii, _0_MockRandom_0.pyl, _0_MockSep_0.pyl, _0.fdt]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-s

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

ribute(JmxMBeanServer.java:672)
[junit4:junit4]   2> 	at org.apache.solr.core.JmxMonitoredMap.unregister(JmxMonitoredMap.java:174)
[junit4:junit4]   2> 	at org.apache.solr.core.JmxMonitoredMap.clear(JmxMonitoredMap.java:116)
[junit4:junit4]   2> 	at org.apache.solr.core.SolrCore.close(SolrCore.java:864)
[junit4:junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:213)
[junit4:junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:158)
[junit4:junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:102)
[junit4:junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:56)
[junit4:junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:131)
[junit4:junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:526)
[junit4:junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:502)
[junit4:junit4]   2> 
[junit4:junit4]   2> 307213 T3629 oasc.JmxMonitoredMap$SolrDynamicMBean.getMBeanInfo WARNING Could not getStatistics on info bean Lazy[solr.ReplicationHandler] java.lang.IllegalArgumentException: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348244841326/jetty4/index does not exist
[junit4:junit4]   2> 	at org.apache.commons.io.FileUtils.sizeOfDirectory(FileUtils.java:2074)
[junit4:junit4]   2> 	at org.apache.solr.handler.ReplicationHandler.getIndexSize(ReplicationHandler.java:477)
[junit4:junit4]   2> 	at org.apache.solr.handler.ReplicationHandler.getStatistics(ReplicationHandler.java:525)
[junit4:junit4]   2> 	at org.apache.solr.core.RequestHandlers$LazyRequestHandlerWrapper.getStatistics(RequestHandlers.java:310)
[junit4:junit4]   2> 	at org.apache.solr.core.JmxMonitoredMap$SolrDynamicMBean.getMBeanInfo(JmxMonitoredMap.java:231)
[junit4:junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.getClassName(DefaultMBeanServerInterceptor.java:1824)
[junit4:junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.safeGetClassName(DefaultMBeanServerInterceptor.java:1661)
[junit4:junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.checkMBeanPermission(DefaultMBeanServerInterceptor.java:1833)
[junit4:junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.exclusiveUnregisterMBean(DefaultMBeanServerInterceptor.java:436)
[junit4:junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.unregisterMBean(DefaultMBeanServerInterceptor.java:421)
[junit4:junit4]   2> 	at com.sun.jmx.mbeanserver.JmxMBeanServer.unregisterMBean(JmxMBeanServer.java:540)
[junit4:junit4]   2> 	at org.apache.solr.core.JmxMonitoredMap.unregister(JmxMonitoredMap.java:175)
[junit4:junit4]   2> 	at org.apache.solr.core.JmxMonitoredMap.clear(JmxMonitoredMap.java:116)
[junit4:junit4]   2> 	at org.apache.solr.core.SolrCore.close(SolrCore.java:864)
[junit4:junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:213)
[junit4:junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:158)
[junit4:junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:102)
[junit4:junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:56)
[junit4:junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:131)
[junit4:junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:526)
[junit4:junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:502)
[junit4:junit4]   2> 
[junit4:junit4]   2> 307217 T3629 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 307221 T3629 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=5,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=35,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4]   2> 307221 T3629 oasu.DefaultSolrCoreState.decref SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 307223 T3629 oasu.DefaultSolrCoreState.decref Closing SolrCoreState - canceling any ongoing recovery
[junit4:junit4]   2> 307223 T3629 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 307223 T3629 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 307224 T3629 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 307224 T3629 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 307224 T3629 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5d016b6d name:ZooKeeperConnection Watcher:127.0.0.1:55943/solr got event WatchedEvent state:Disconnected type:None path:null path:null type:None
[junit4:junit4]   2> 307224 T3629 oascc.ConnectionManager.process Client->ZooKeeper status change trigger but we are already closed
[junit4:junit4]   2> 307224 T3629 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> NOTE: test params are: codec=Lucene40: {n_f1=MockFixedIntBlock(blockSize=1388), foo_b=PostingsFormat(name=MockRandom), foo_d=Pulsing40(freqCutoff=14 minBlockSize=17 maxBlockSize=36), foo_f=PostingsFormat(name=MockRandom), n_tl1=MockFixedIntBlock(blockSize=1388), n_d1=PostingsFormat(name=MockSep), rnd_b=Pulsing40(freqCutoff=14 minBlockSize=17 maxBlockSize=36), intDefault=MockFixedIntBlock(blockSize=1388), n_td1=MockFixedIntBlock(blockSize=1388), id=Pulsing40(freqCutoff=14 minBlockSize=17 maxBlockSize=36), timestamp=PostingsFormat(name=MockSep), range_facet_sl=Pulsing40(freqCutoff=14 minBlockSize=17 maxBlockSize=36), range_facet_si=PostingsFormat(name=MockSep), oddField_s=Pulsing40(freqCutoff=14 minBlockSize=17 maxBlockSize=36), multiDefault=PostingsFormat(name=MockSep), n_tf1=PostingsFormat(name=MockSep), n_dt1=MockFixedIntBlock(blockSize=1388), n_ti1=Pulsing40(freqCutoff=14 minBlockSize=17 maxBlockSize=36), range_facet_l=PostingsFormat(name=MockSep), text=PostingsFormat(name=MockRandom), _version_=MockFixedIntBlock(blockSize=1388), SubjectTerms_mfacet=MockFixedIntBlock(blockSize=1388), a_t=PostingsFormat(name=MockSep), n_tdt1=MockFixedIntBlock(blockSize=1388), other_tl1=MockFixedIntBlock(blockSize=1388), n_l1=PostingsFormat(name=MockSep), a_si=MockFixedIntBlock(blockSize=1388)}, sim=DefaultSimilarity, locale=th, timezone=Pacific/Ponape
[junit4:junit4]   2> NOTE: FreeBSD 9.0-RELEASE amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=2,free=49613024,total=294977536
[junit4:junit4]   2> NOTE: All tests run in this JVM: [DisMaxRequestHandlerTest, ScriptEngineTest, ZkSolrClientTest, TestCSVLoader, TestDocSet, TestCSVResponseWriter, TestRealTimeGet, DOMUtilTest, QueryEqualityTest, TestSolrDeletionPolicy1, TestStressRecovery, URLClassifyProcessorTest, FullSolrCloudDistribCmdsTest, TestBM25SimilarityFactory, OpenExchangeRatesOrgProviderTest, TestFoldingMultitermQuery, LeaderElectionTest, PolyFieldTest, TestDistributedGrouping, OverseerTest, IndexSchemaTest, TestArbitraryIndexDir, TestDocumentBuilder, SolrIndexConfigTest, TestDFRSimilarityFactory, SignatureUpdateProcessorFactoryTest, TestSolrCoreProperties, TestSort, TestReversedWildcardFilterFactory, UUIDFieldTest, IndexSchemaRuntimeFieldTest, DocumentBuilderTest, QueryParsingTest, ZkNodePropsTest, XsltUpdateRequestHandlerTest, PrimUtilsTest, TestCollationKeyRangeQueries, TimeZoneUtilsTest, TestUpdate, HighlighterTest, ReturnFieldsTest, TestOmitPositions, IndexReaderFactoryTest, DistributedQueryElevationComponentTest, TestJmxIntegration, RequiredFieldsTest, TestValueSourceCache, TermVectorComponentTest, PrimitiveFieldTypeTest, TestReplicationHandler, TestRemoteStreaming, TestCharFilters, TestRecovery, TestCodecSupport, OutputWriterTest, RecoveryZkTest, ZkControllerTest, TestRandomFaceting, TestDistributedSearch, PingRequestHandlerTest, TestSurroundQueryParser, DocumentAnalysisRequestHandlerTest, SolrPluginUtilsTest, DebugComponentTest, RequestHandlersTest, CopyFieldTest, TestQueryUtils, SuggesterTSTTest, CSVRequestHandlerTest, ShowFileRequestHandlerTest, TestLuceneMatchVersion, TestPropInject, NoCacheHeaderTest, FieldMutatingUpdateProcessorTest, TestPropInjectDefaults, TestLFUCache, MultiTermTest, TestConfig, SpellPossibilityIteratorTest, TestLMDirichletSimilarityFactory, TestPluginEnable, TestFastLRUCache, ResourceLoaderTest, TestSystemIdResolver, SpellingQueryConverterTest, TestUtils, PreAnalyzedFieldTest, CircularListTest, PathHierarchyTokenizerFactoryTest, BasicDistributedZk2Test]
[junit4:junit4] Completed on J1 in 307.62s, 1 test, 1 failure <<< FAILURES!

[...truncated 10 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:32: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build.xml:179: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/module-build.xml:63: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/common-build.xml:1140: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/common-build.xml:813: There were test failures: 231 suites, 954 tests, 1 failure, 8 ignored (3 assumptions)

Total time: 70 minutes 32 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