lucene-dev mailing list archives

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

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([B213404B7CC29489:33F5CE530B9DF4B5]: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 7589 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4:junit4]   2> 4 T1631 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1348231642908
[junit4:junit4]   2> 8 T1631 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 11 T1632 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4]   2> 11 T1632 oazs.NIOServerCnxn$Factory.<init> binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 12 T1632 oazsp.FileTxnSnapLog.save Snapshotting: 0
[junit4:junit4]   2> 109 T1631 oasc.ZkTestServer.run start zk server on port:12608
[junit4:junit4]   2> 109 T1631 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:12608 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@5477b220
[junit4:junit4]   2> 110 T1637 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:12608
[junit4:junit4]   2> 110 T1631 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 110 T1637 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:12608, initiating session
[junit4:junit4]   2> 111 T1633 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:12609
[junit4:junit4]   2> 111 T1633 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:12609
[junit4:junit4]   2> 111 T1635 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 114 T1635 oazs.NIOServerCnxn.finishSessionInit Established session 0x139e8de3f250000 with negotiated timeout 10000 for client /140.211.11.196:12609
[junit4:junit4]   2> 114 T1637 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:12608, sessionid = 0x139e8de3f250000, negotiated timeout = 10000
[junit4:junit4]   2> 114 T1638 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5477b220 name:ZooKeeperConnection Watcher:127.0.0.1:12608 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 114 T1631 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 114 T1631 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 125 T1636 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x139e8de3f250000
[junit4:junit4]   2> 126 T1638 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 127 T1633 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:12609 which had sessionid 0x139e8de3f250000
[junit4:junit4]   2> 126 T1631 oaz.ZooKeeper.close Session: 0x139e8de3f250000 closed
[junit4:junit4]   2> 127 T1631 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:12608/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@57cc3437
[junit4:junit4]   2> 127 T1639 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:12608
[junit4:junit4]   2> 127 T1631 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 128 T1639 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:12608, initiating session
[junit4:junit4]   2> 128 T1633 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:12610
[junit4:junit4]   2> 128 T1633 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:12610
[junit4:junit4]   2> 130 T1635 oazs.NIOServerCnxn.finishSessionInit Established session 0x139e8de3f250001 with negotiated timeout 10000 for client /140.211.11.196:12610
[junit4:junit4]   2> 130 T1639 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:12608, sessionid = 0x139e8de3f250001, negotiated timeout = 10000
[junit4:junit4]   2> 130 T1640 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@57cc3437 name:ZooKeeperConnection Watcher:127.0.0.1:12608/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 130 T1631 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 130 T1631 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 139 T1631 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 145 T1631 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 147 T1631 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 150 T1631 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 150 T1631 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 166 T1631 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4]   2> 167 T1631 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 270 T1631 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 271 T1631 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 274 T1631 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4]   2> 275 T1631 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 286 T1631 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4]   2> 286 T1631 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 290 T1631 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4]   2> 290 T1631 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 293 T1631 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 294 T1631 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 298 T1631 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 299 T1631 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 303 T1631 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 304 T1631 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 307 T1631 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4]   2> 308 T1631 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 312 T1636 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x139e8de3f250001
[junit4:junit4]   2> 313 T1640 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 313 T1633 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:12610 which had sessionid 0x139e8de3f250001
[junit4:junit4]   2> 313 T1631 oaz.ZooKeeper.close Session: 0x139e8de3f250001 closed
[junit4:junit4]   2> 317 T1631 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 323 T1631 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:12611
[junit4:junit4]   2> 324 T1631 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 325 T1631 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 325 T1631 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 388 T1631 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 389 T1631 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 390 T1631 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 391 T1631 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/solr.xml
[junit4:junit4]   2> 391 T1631 oasc.CoreContainer.<init> New CoreContainer 739217287
[junit4:junit4]   2> 393 T1631 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 393 T1631 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 437 T1631 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 463 T1631 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:12608/solr
[junit4:junit4]   2> 464 T1631 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:12608/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@71d06455
[junit4:junit4]   2> 465 T1650 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:12608
[junit4:junit4]   2> 465 T1631 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 466 T1650 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:12608, initiating session
[junit4:junit4]   2> 466 T1633 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:12613
[junit4:junit4]   2> 467 T1633 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:12613
[junit4:junit4]   2> 472 T1635 oazs.NIOServerCnxn.finishSessionInit Established session 0x139e8de3f250002 with negotiated timeout 5000 for client /140.211.11.196:12613
[junit4:junit4]   2> 472 T1650 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:12608, sessionid = 0x139e8de3f250002, negotiated timeout = 5000
[junit4:junit4]   2> 473 T1651 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@71d06455 name:ZooKeeperConnection Watcher:127.0.0.1:12608/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 473 T1631 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 476 T1636 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e8de3f250002 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 484 T1631 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 487 T1631 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:12611_solr
[junit4:junit4]   2> 488 T1636 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e8de3f250002 type:delete cxid:0x7 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:12611_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:12611_solr
[junit4:junit4]   2> 489 T1631 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:12611_solr
[junit4:junit4]   2> 498 T1631 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 499 T1631 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 499 T1631 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 499 T1631 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 500 T1631 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 500 T1631 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 500 T1631 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 500 T1631 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 501 T1631 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 501 T1631 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 513 T1631 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 519 T1636 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e8de3f250002 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> 529 T1631 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 532 T1631 oasc.Overseer.start Overseer (id=88357708950208514-127.0.0.1:12611_solr-n_0000000000) starting
[junit4:junit4]   2> 532 T1636 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e8de3f250002 type:create cxid:0x1a zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 538 T1636 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e8de3f250002 type:create cxid:0x1b zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 544 T1636 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e8de3f250002 type:create cxid:0x1c zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 551 T1636 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e8de3f250002 type:create cxid:0x1d zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 552 T1653 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 553 T1631 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 560 T1631 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 565 T1631 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1
[junit4:junit4]   2> 566 T1631 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 566 T1652 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 566 T1631 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 567 T1631 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 568 T1631 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4]   2> 569 T1631 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4]   2> 569 T1631 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 605 T1631 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_40
[junit4:junit4]   2> 658 T1631 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 759 T1631 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 768 T1631 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 1197 T1631 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 1205 T1631 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 1208 T1631 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 1220 T1631 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1225 T1631 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1228 T1631 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1229 T1631 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1230 T1631 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/control/data/
[junit4:junit4]   2> 1231 T1631 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@24988707
[junit4:junit4]   2> 1254 T1631 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/control/data/index/
[junit4:junit4]   2> 1255 T1631 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/control/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 1255 T1631 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/control/data/index forceNew:false
[junit4:junit4]   2> 1286 T1631 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/control/data/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 1287 T1631 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 1287 T1631 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 1289 T1631 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 1289 T1631 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 1290 T1631 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 1290 T1631 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 1291 T1631 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 1291 T1631 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 1291 T1631 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 1292 T1631 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 1292 T1631 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 1293 T1631 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 1293 T1631 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 1293 T1631 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 1294 T1631 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 1294 T1631 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 1295 T1631 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 1295 T1631 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 1295 T1631 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1296 T1631 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1296 T1631 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1297 T1631 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1297 T1631 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1298 T1631 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1298 T1631 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1298 T1631 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 1299 T1631 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 1301 T1631 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 1305 T1631 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 1306 T1631 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> 1310 T1631 oass.SolrIndexSearcher.<init> Opening Searcher@260ce582 main
[junit4:junit4]   2> 1311 T1631 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 1311 T1631 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 1311 T1631 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 1318 T1631 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 1364 T1654 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@260ce582 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 1368 T1636 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e8de3f250002 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> 1379 T1631 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 1380 T1631 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:12611/solr shardId:control_shard
[junit4:junit4]   2> 1381 T1631 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/control_shard/election
[junit4:junit4]   2> 1402 T1636 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e8de3f250002 type:delete cxid:0x62 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/collections/control_collection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/control_collection/leaders
[junit4:junit4]   2> 1403 T1631 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 1404 T1636 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e8de3f250002 type:create cxid:0x63 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 1575 T1652 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 1576 T1636 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e8de3f250002 type:create cxid:0x6a zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer/queue-work Error:KeeperErrorCode = NoNode for /solr/overseer/queue-work
[junit4:junit4]   2> 1597 T1651 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 1906 T1631 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 1907 T1631 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 1908 T1631 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:12611/solr/collection1/
[junit4:junit4]   2> 1908 T1631 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 1909 T1631 oasc.SyncStrategy.syncToMe http://127.0.0.1:12611/solr/collection1/ has no replicas
[junit4:junit4]   2> 1909 T1631 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:12611/solr/collection1/
[junit4:junit4]   2> 1910 T1631 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/control_shard
[junit4:junit4]   2> 1926 T1636 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e8de3f250002 type:create cxid:0x88 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2105 T1652 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2118 T1651 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 2132 T1631 oasc.ZkController.register We are http://127.0.0.1:12611/solr/collection1/ and leader is http://127.0.0.1:12611/solr/collection1/
[junit4:junit4]   2> 2132 T1631 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:12611/solr
[junit4:junit4]   2> 2133 T1631 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 2135 T1631 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2136 T1631 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0
[junit4:junit4]   2> 2137 T1631 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 2137 T1631 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 2607 T1631 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 2610 T1631 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:12625
[junit4:junit4]   2> 2611 T1631 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 2611 T1631 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty1-1348231645056
[junit4:junit4]   2> 2612 T1631 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty1-1348231645056/'
[junit4:junit4]   2> 2622 T1652 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2646 T1631 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 2646 T1631 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 2647 T1631 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty1-1348231645056
[junit4:junit4]   2> 2647 T1631 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty1-1348231645056/solr.xml
[junit4:junit4]   2> 2647 T1631 oasc.CoreContainer.<init> New CoreContainer 1067725749
[junit4:junit4]   2> 2648 T1631 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty1-1348231645056/'
[junit4:junit4]   2> 2649 T1631 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty1-1348231645056/'
[junit4:junit4]   2> 2674 T1631 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 2682 T1651 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 2689 T1631 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:12608/solr
[junit4:junit4]   2> 2689 T1631 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:12608/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@2ef8b9b0
[junit4:junit4]   2> 2690 T1664 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:12608
[junit4:junit4]   2> 2690 T1631 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 2691 T1664 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:12608, initiating session
[junit4:junit4]   2> 2691 T1633 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:12626
[junit4:junit4]   2> 2692 T1633 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:12626
[junit4:junit4]   2> 2762 T1635 oazs.NIOServerCnxn.finishSessionInit Established session 0x139e8de3f250003 with negotiated timeout 5000 for client /140.211.11.196:12626
[junit4:junit4]   2> 2762 T1664 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:12608, sessionid = 0x139e8de3f250003, negotiated timeout = 5000
[junit4:junit4]   2> 2763 T1665 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2ef8b9b0 name:ZooKeeperConnection Watcher:127.0.0.1:12608/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 2763 T1631 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 2764 T1636 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e8de3f250003 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2783 T1636 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e8de3f250003 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2785 T1631 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:12625_solr
[junit4:junit4]   2> 2786 T1636 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e8de3f250003 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:12625_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:12625_solr
[junit4:junit4]   2> 2793 T1631 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:12625_solr
[junit4:junit4]   2> 2800 T1651 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 2801 T1631 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 2801 T1631 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 2802 T1631 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 2802 T1631 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 2803 T1631 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 2803 T1631 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 2804 T1631 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 2804 T1631 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 2805 T1631 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 2805 T1631 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 2823 T1631 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 2829 T1631 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty1-1348231645056/collection1
[junit4:junit4]   2> 2830 T1631 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 2830 T1631 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 2831 T1631 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 2832 T1631 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty1-1348231645056/collection1/'
[junit4:junit4]   2> 2834 T1631 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/solrtest-jetty1-1348231645056/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 2835 T1631 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/solrtest-jetty1-1348231645056/collection1/lib/README' to classloader
[junit4:junit4]   2> 2887 T1631 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_40
[junit4:junit4]   2> 2960 T1631 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 3061 T1631 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 3082 T1631 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 3743 T1631 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 3757 T1631 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 3762 T1631 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 3779 T1631 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 3785 T1631 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 3790 T1631 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 3792 T1631 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 3793 T1631 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty1-1348231645056/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty1/
[junit4:junit4]   2> 3794 T1631 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@24988707
[junit4:junit4]   2> 3795 T1631 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty1/index/
[junit4:junit4]   2> 3796 T1631 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 3797 T1631 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty1/index forceNew:false
[junit4:junit4]   2> 3814 T1631 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty1/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 3814 T1631 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 3815 T1631 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 3818 T1631 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 3818 T1631 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 3819 T1631 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 3819 T1631 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 3820 T1631 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 3821 T1631 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 3821 T1631 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 3822 T1631 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 3823 T1631 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 3823 T1631 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 3824 T1631 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 3825 T1631 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 3826 T1631 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 3826 T1631 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 3827 T1631 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 3827 T1631 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 3828 T1631 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3829 T1631 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3830 T1631 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3830 T1631 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3831 T1631 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3832 T1631 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3832 T1631 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3833 T1631 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 3834 T1631 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 3838 T1631 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 3843 T1631 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 3844 T1631 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> 3849 T1631 oass.SolrIndexSearcher.<init> Opening Searcher@286ec14c main
[junit4:junit4]   2> 3850 T1631 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 3851 T1631 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 3851 T1631 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 3859 T1631 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 3913 T1666 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@286ec14c main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 4271 T1652 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4281 T1665 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4281 T1651 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4420 T1631 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 4420 T1631 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:12625/solr shardId:shard1
[junit4:junit4]   2> 4422 T1631 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 4449 T1636 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e8de3f250003 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> 4450 T1631 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 4451 T1636 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e8de3f250003 type:create cxid:0x43 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4460 T1631 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 4461 T1631 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 4461 T1631 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:12625/solr/collection1/
[junit4:junit4]   2> 4462 T1631 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 4462 T1631 oasc.SyncStrategy.syncToMe http://127.0.0.1:12625/solr/collection1/ has no replicas
[junit4:junit4]   2> 4462 T1631 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:12625/solr/collection1/
[junit4:junit4]   2> 4463 T1631 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 4470 T1636 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e8de3f250003 type:create cxid:0x4d zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4792 T1652 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4809 T1651 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4809 T1665 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4837 T1631 oasc.ZkController.register We are http://127.0.0.1:12625/solr/collection1/ and leader is http://127.0.0.1:12625/solr/collection1/
[junit4:junit4]   2> 4837 T1631 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:12625/solr
[junit4:junit4]   2> 4838 T1631 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 4840 T1631 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4841 T1631 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0
[junit4:junit4]   2> 4841 T1631 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 4841 T1631 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 5175 T1631 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 5177 T1631 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:12629
[junit4:junit4]   2> 5178 T1631 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 5178 T1631 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty2-1348231647754
[junit4:junit4]   2> 5178 T1631 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty2-1348231647754/'
[junit4:junit4]   2> 5205 T1631 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 5205 T1631 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 5206 T1631 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty2-1348231647754
[junit4:junit4]   2> 5206 T1631 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty2-1348231647754/solr.xml
[junit4:junit4]   2> 5206 T1631 oasc.CoreContainer.<init> New CoreContainer 547390083
[junit4:junit4]   2> 5207 T1631 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty2-1348231647754/'
[junit4:junit4]   2> 5207 T1631 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty2-1348231647754/'
[junit4:junit4]   2> 5226 T1631 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 5237 T1631 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:12608/solr
[junit4:junit4]   2> 5237 T1631 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:12608/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@62793703
[junit4:junit4]   2> 5238 T1676 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:12608
[junit4:junit4]   2> 5238 T1631 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 5239 T1676 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:12608, initiating session
[junit4:junit4]   2> 5239 T1633 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:12630
[junit4:junit4]   2> 5240 T1633 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:12630
[junit4:junit4]   2> 5241 T1635 oazs.NIOServerCnxn.finishSessionInit Established session 0x139e8de3f250004 with negotiated timeout 5000 for client /140.211.11.196:12630
[junit4:junit4]   2> 5241 T1676 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:12608, sessionid = 0x139e8de3f250004, negotiated timeout = 5000
[junit4:junit4]   2> 5242 T1677 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@62793703 name:ZooKeeperConnection Watcher:127.0.0.1:12608/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 5242 T1631 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 5242 T1636 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e8de3f250004 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 5244 T1636 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e8de3f250004 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 5253 T1631 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:12629_solr
[junit4:junit4]   2> 5253 T1636 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e8de3f250004 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:12629_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:12629_solr
[junit4:junit4]   2> 5255 T1631 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:12629_solr
[junit4:junit4]   2> 5257 T1665 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 5257 T1651 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 5258 T1631 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 5258 T1631 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 5259 T1631 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 5259 T1631 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 5259 T1631 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 5259 T1631 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 5260 T1631 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 5260 T1631 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 5260 T1631 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 5261 T1631 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 5273 T1631 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 5278 T1631 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty2-1348231647754/collection1
[junit4:junit4]   2> 5278 T1631 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 5279 T1631 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 5279 T1631 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 5280 T1631 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty2-1348231647754/collection1/'
[junit4:junit4]   2> 5281 T1631 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/solrtest-jetty2-1348231647754/collection1/lib/README' to classloader
[junit4:junit4]   2> 5282 T1631 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/solrtest-jetty2-1348231647754/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 5314 T1652 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 5318 T1631 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_40
[junit4:junit4]   2> 5325 T1665 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5325 T1651 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5325 T1677 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5371 T1631 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 5472 T1631 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 5480 T1631 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 5987 T1631 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 5997 T1631 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 6000 T1631 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 6013 T1631 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 6018 T1631 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 6022 T1631 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 6023 T1631 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 6024 T1631 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty2-1348231647754/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty2/
[junit4:junit4]   2> 6024 T1631 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@24988707
[junit4:junit4]   2> 6026 T1631 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty2/index/
[junit4:junit4]   2> 6026 T1631 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 6027 T1631 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty2/index forceNew:false
[junit4:junit4]   2> 6038 T1631 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty2/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 6039 T1631 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 6039 T1631 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 6041 T1631 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 6041 T1631 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 6042 T1631 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 6042 T1631 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 6043 T1631 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 6043 T1631 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 6044 T1631 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 6044 T1631 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 6045 T1631 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 6045 T1631 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 6046 T1631 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 6046 T1631 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 6047 T1631 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 6047 T1631 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 6048 T1631 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 6048 T1631 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 6049 T1631 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6049 T1631 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6050 T1631 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6050 T1631 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6051 T1631 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6051 T1631 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6052 T1631 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6052 T1631 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 6053 T1631 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 6056 T1631 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 6060 T1631 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 6062 T1631 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> 6065 T1631 oass.SolrIndexSearcher.<init> Opening Searcher@730965d2 main
[junit4:junit4]   2> 6067 T1631 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 6067 T1631 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 6068 T1631 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 6074 T1631 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 6123 T1678 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@730965d2 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 6333 T1652 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6347 T1665 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6347 T1677 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6347 T1651 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6630 T1631 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 6630 T1631 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:12629/solr shardId:shard2
[junit4:junit4]   2> 6632 T1631 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4]   2> 6648 T1636 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e8de3f250004 type:delete cxid:0x42 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/collections/collection1/leaders/shard2 Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders/shard2
[junit4:junit4]   2> 6649 T1631 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 6649 T1636 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e8de3f250004 type:create cxid:0x43 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 6651 T1631 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 6652 T1631 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 6652 T1631 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:12629/solr/collection1/
[junit4:junit4]   2> 6653 T1631 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 6653 T1631 oasc.SyncStrategy.syncToMe http://127.0.0.1:12629/solr/collection1/ has no replicas
[junit4:junit4]   2> 6654 T1631 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:12629/solr/collection1/
[junit4:junit4]   2> 6654 T1631 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4]   2> 6658 T1636 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e8de3f250004 type:create cxid:0x4c zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 6852 T1652 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6870 T1665 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6870 T1651 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6870 T1677 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6872 T1631 oasc.ZkController.register We are http://127.0.0.1:12629/solr/collection1/ and leader is http://127.0.0.1:12629/solr/collection1/
[junit4:junit4]   2> 6872 T1631 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:12629/solr
[junit4:junit4]   2> 6872 T1631 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 6879 T1631 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6886 T1631 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0
[junit4:junit4]   2> 6886 T1631 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 6886 T1631 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 7236 T1631 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 7239 T1631 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:12632
[junit4:junit4]   2> 7240 T1631 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 7240 T1631 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty3-1348231649800
[junit4:junit4]   2> 7240 T1631 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty3-1348231649800/'
[junit4:junit4]   2> 7267 T1631 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 7268 T1631 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 7268 T1631 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty3-1348231649800
[junit4:junit4]   2> 7268 T1631 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty3-1348231649800/solr.xml
[junit4:junit4]   2> 7269 T1631 oasc.CoreContainer.<init> New CoreContainer 209520181
[junit4:junit4]   2> 7269 T1631 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty3-1348231649800/'
[junit4:junit4]   2> 7269 T1631 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty3-1348231649800/'
[junit4:junit4]   2> 7289 T1631 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 7301 T1631 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:12608/solr
[junit4:junit4]   2> 7301 T1631 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:12608/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@170d6172
[junit4:junit4]   2> 7302 T1688 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:12608
[junit4:junit4]   2> 7302 T1631 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 7303 T1688 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:12608, initiating session
[junit4:junit4]   2> 7303 T1633 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:12633
[junit4:junit4]   2> 7303 T1633 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:12633
[junit4:junit4]   2> 7306 T1635 oazs.NIOServerCnxn.finishSessionInit Established session 0x139e8de3f250005 with negotiated timeout 5000 for client /140.211.11.196:12633
[junit4:junit4]   2> 7306 T1688 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:12608, sessionid = 0x139e8de3f250005, negotiated timeout = 5000
[junit4:junit4]   2> 7306 T1689 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@170d6172 name:ZooKeeperConnection Watcher:127.0.0.1:12608/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 7306 T1631 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 7307 T1636 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e8de3f250005 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7308 T1636 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e8de3f250005 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7323 T1631 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:12632_solr
[junit4:junit4]   2> 7323 T1636 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e8de3f250005 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:12632_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:12632_solr
[junit4:junit4]   2> 7324 T1631 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:12632_solr
[junit4:junit4]   2> 7326 T1651 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 7326 T1665 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 7326 T1677 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 7327 T1631 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 7327 T1631 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 7327 T1631 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 7328 T1631 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 7328 T1631 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 7328 T1631 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 7328 T1631 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 7329 T1631 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 7329 T1631 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 7329 T1631 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 7341 T1631 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 7346 T1631 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty3-1348231649800/collection1
[junit4:junit4]   2> 7346 T1631 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 7347 T1631 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 7347 T1631 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 7348 T1631 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty3-1348231649800/collection1/'
[junit4:junit4]   2> 7350 T1631 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/solrtest-jetty3-1348231649800/collection1/lib/README' to classloader
[junit4:junit4]   2> 7350 T1631 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/solrtest-jetty3-1348231649800/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 7387 T1631 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_40
[junit4:junit4]   2> 7388 T1652 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7394 T1677 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7394 T1689 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7394 T1665 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7394 T1651 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7439 T1631 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 7540 T1631 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 7547 T1631 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 7974 T1631 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 7982 T1631 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 7986 T1631 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 7997 T1631 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 8001 T1631 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 8004 T1631 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 8005 T1631 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 8006 T1631 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty3-1348231649800/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty3/
[junit4:junit4]   2> 8006 T1631 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@24988707
[junit4:junit4]   2> 8007 T1631 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty3/index/
[junit4:junit4]   2> 8008 T1631 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 8009 T1631 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty3/index forceNew:false
[junit4:junit4]   2> 8013 T1631 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty3/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 8013 T1631 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 8014 T1631 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 8016 T1631 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 8016 T1631 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 8016 T1631 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 8017 T1631 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 8017 T1631 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 8017 T1631 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 8018 T1631 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 8018 T1631 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 8019 T1631 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 8019 T1631 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 8020 T1631 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 8020 T1631 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 8021 T1631 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 8021 T1631 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 8022 T1631 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 8022 T1631 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 8022 T1631 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8023 T1631 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8023 T1631 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8024 T1631 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8024 T1631 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8025 T1631 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8025 T1631 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8026 T1631 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 8026 T1631 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 8029 T1631 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 8032 T1631 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 8033 T1631 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> 8036 T1631 oass.SolrIndexSearcher.<init> Opening Searcher@9ffb9fa main
[junit4:junit4]   2> 8037 T1631 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 8038 T1631 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 8038 T1631 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 8056 T1631 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 8099 T1690 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@9ffb9fa main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 8401 T1652 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8415 T1689 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8415 T1651 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8415 T1665 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8415 T1677 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8604 T1631 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 8604 T1631 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:12632/solr shardId:shard1
[junit4:junit4]   2> 8608 T1631 oasc.ZkController.register We are http://127.0.0.1:12632/solr/collection1/ and leader is http://127.0.0.1:12625/solr/collection1/
[junit4:junit4]   2> 8608 T1631 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:12632/solr
[junit4:junit4]   2> 8609 T1631 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 8609 T1631 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C119 name=collection1 org.apache.solr.core.SolrCore@35f251a2 url=http://127.0.0.1:12632/solr/collection1 node=127.0.0.1:12632_solr
[junit4:junit4]   2> 8617 T1691 C119 P12632 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 8617 T1631 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8618 T1691 C119 P12632 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 8619 T1631 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0
[junit4:junit4]   2> 8619 T1631 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 8620 T1631 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 8622 T1691 C119 P12632 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:12625/solr/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 8622 T1691 C119 P12632 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:12632/solr START replicas=[http://127.0.0.1:12625/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 8622 T1691 C119 P12632 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 8623 T1691 C119 P12632 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 8623 T1691 C119 P12632 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 8623 T1691 C119 P12632 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C120 name=collection1 org.apache.solr.core.SolrCore@7c4832c7 url=http://127.0.0.1:12625/solr/collection1 node=127.0.0.1:12625_solr
[junit4:junit4]   2> 8633 T1657 C120 P12625 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=0 
[junit4:junit4]   2> 8919 T1652 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8930 T1677 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8930 T1651 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8930 T1665 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8930 T1689 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9093 T1631 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 9096 T1631 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:12651
[junit4:junit4]   2> 9097 T1631 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 9097 T1631 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty4-1348231651543
[junit4:junit4]   2> 9098 T1631 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty4-1348231651543/'
[junit4:junit4]   2> 9139 T1631 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 9140 T1631 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 9140 T1631 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty4-1348231651543
[junit4:junit4]   2> 9141 T1631 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty4-1348231651543/solr.xml
[junit4:junit4]   2> 9141 T1631 oasc.CoreContainer.<init> New CoreContainer 2118660123
[junit4:junit4]   2> 9142 T1631 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty4-1348231651543/'
[junit4:junit4]   2> 9143 T1631 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty4-1348231651543/'
[junit4:junit4]   2> 9170 T1631 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 9188 T1631 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:12608/solr
[junit4:junit4]   2> 9189 T1631 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:12608/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@3409c845
[junit4:junit4]   2> 9190 T1702 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:12608
[junit4:junit4]   2> 9190 T1631 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 9190 T1702 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:12608, initiating session
[junit4:junit4]   2> 9191 T1633 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:12653
[junit4:junit4]   2> 9191 T1633 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:12653
[junit4:junit4]   2> 9194 T1635 oazs.NIOServerCnxn.finishSessionInit Established session 0x139e8de3f250006 with negotiated timeout 5000 for client /140.211.11.196:12653
[junit4:junit4]   2> 9194 T1702 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:12608, sessionid = 0x139e8de3f250006, negotiated timeout = 5000
[junit4:junit4]   2> 9195 T1703 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3409c845 name:ZooKeeperConnection Watcher:127.0.0.1:12608/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 9195 T1631 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 9196 T1636 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e8de3f250006 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 9197 T1636 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e8de3f250006 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 9204 T1631 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:12651_solr
[junit4:junit4]   2> 9205 T1636 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139e8de3f250006 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:12651_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:12651_solr
[junit4:junit4]   2> 9206 T1631 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:12651_solr
[junit4:junit4]   2> 9208 T1677 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 9208 T1665 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 9208 T1651 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 9208 T1689 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 9209 T1631 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 9210 T1631 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 9210 T1631 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 9211 T1631 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 9211 T1631 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 9212 T1631 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 9212 T1631 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 9213 T1631 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 9213 T1631 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 9213 T1631 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 9230 T1631 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 9237 T1631 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty4-1348231651543/collection1
[junit4:junit4]   2> 9237 T1631 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 9238 T1631 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 9238 T1631 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 9240 T1631 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty4-1348231651543/collection1/'
[junit4:junit4]   2> 9241 T1631 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/solrtest-jetty4-1348231651543/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 9242 T1631 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/solrtest-jetty4-1348231651543/collection1/lib/README' to classloader
[junit4:junit4]   2> 9297 T1631 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_40
[junit4:junit4]   2> 9370 T1631 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 9471 T1631 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 9482 T1631 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 10135 T1631 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 10147 T1631 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 10151 T1631 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 10165 T1631 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 10170 T1631 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 10175 T1631 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 10176 T1631 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 10177 T1631 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-jetty4-1348231651543/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty4/
[junit4:junit4]   2> 10178 T1631 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@24988707
[junit4:junit4]   2> 10179 T1631 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty4/index/
[junit4:junit4]   2> 10180 T1631 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 10181 T1631 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty4/index forceNew:false
[junit4:junit4]   2> 10187 T1631 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty4/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 10188 T1631 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 10189 T1631 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 10191 T1631 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 10191 T1631 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 10192 T1631 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 10192 T1631 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 10193 T1631 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 10193 T1631 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 10194 T1631 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 10195 T1631 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 10195 T1631 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 10196 T1631 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 10197 T1631 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 10197 T1631 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 10198 T1631 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 10199 T1631 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 10199 T1631 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 10200 T1631 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 10200 T1631 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10201 T1631 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10202 T1631 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10202 T1631 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10203 T1631 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10204 T1631 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10204 T1631 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10205 T1631 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 10206 T1631 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 10209 T1631 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 10214 T1631 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 10215 T1631 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> 10219 T1631 oass.SolrIndexSearcher.<init> Opening Searcher@b9db7d8 main
[junit4:junit4]   2> 10221 T1631 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 10221 T1631 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 10222 T1631 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 10229 T1631 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 10288 T1704 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@b9db7d8 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 10444 T1652 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 10460 T1665 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10460 T1677 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10460 T1703 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10460 T1689 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10460 T1651 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10796 T1631 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 10796 T1631 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:12651/solr shardId:shard2
[junit4:junit4]   2> 10800 T1631 oasc.ZkController.register We are http://127.0.0.1:12651/solr/collection1/ and leader is http://127.0.0.1:12629/solr/collection1/
[junit4:junit4]   2> 10801 T1631 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:12651/solr
[junit4:junit4]   2> 10801 T1631 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 10802 T1631 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C121 name=collection1 org.apache.solr.core.SolrCore@c4dc96f url=http://127.0.0.1:12651/solr/collection1 node=127.0.0.1:12651_solr
[junit4:junit4]   2> 10803 T1705 C121 P12651 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 10803 T1705 C121 P12651 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 10803 T1631 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 10805 T1705 C121 P12651 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:12629/solr/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 10805 T1705 C121 P12651 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:12651/solr START replicas=[http://127.0.0.1:12629/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 10805 T1631 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0
[junit4:junit4]   2> 10805 T1705 C121 P12651 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 10805 T1631 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 10806 T1705 C121 P12651 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 10806 T1705 C121 P12651 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 10806 T1631 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 10807 T1705 C121 P12651 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C122 name=collection1 org.apache.solr.core.SolrCore@be8bba9 url=http://127.0.0.1:12629/solr/collection1 node=127.0.0.1:12629_solr
[junit4:junit4]   2> 10815 T1669 C122 P12629 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=0 
[junit4:junit4]   2> 10831 T1631 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:12608/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@469145fc
[junit4:junit4]   2> 10832 T1707 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:12608
[junit4:junit4]   2> 10832 T1631 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 10832 T1707 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:12608, initiating session
[junit4:junit4]   2> 10832 T1633 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:12677
[junit4:junit4]   2> 10833 T1633 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:12677
[junit4:junit4]   2> 10838 T1635 oazs.NIOServerCnxn.finishSessionInit Established session 0x139e8de3f250007 with negotiated timeout 10000 for client /140.211.11.196:12677
[junit4:junit4]   2> 10838 T1707 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:12608, sessionid = 0x139e8de3f250007, negotiated timeout = 10000
[junit4:junit4]   2> 10838 T1708 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@469145fc name:ZooKeeperConnection Watcher:127.0.0.1:12608/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 10839 T1631 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 10839 T1631 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 10843 T1631 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   2> 10844 T1631 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 10854 T1631 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> ASYNC  NEW_CORE C123 name=collection1 org.apache.solr.core.SolrCore@671733ba url=http://127.0.0.1:12611/solr/collection1 node=127.0.0.1:12611_solr
[junit4:junit4]   2> 10867 T1643 C123 P12611 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/control/data/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 10867 T1643 C123 P12611 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 10872 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[1 (1413723354580385792)]} 0 10
[junit4:junit4]   2> 10873 T1631 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:12608/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@175303d0
[junit4:junit4]   2> 10874 T1709 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:12608
[junit4:junit4]   2> 10874 T1631 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 10874 T1709 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:12608, initiating session
[junit4:junit4]   2> 10875 T1633 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:12680
[junit4:junit4]   2> 10875 T1633 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:12680
[junit4:junit4]   2> 10876 T1635 oazs.NIOServerCnxn.finishSessionInit Established session 0x139e8de3f250008 with negotiated timeout 10000 for client /140.211.11.196:12680
[junit4:junit4]   2> 10876 T1709 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:12608, sessionid = 0x139e8de3f250008, negotiated timeout = 10000
[junit4:junit4]   2> 10877 T1710 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@175303d0 name:ZooKeeperConnection Watcher:127.0.0.1:12608/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 10877 T1631 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 10878 T1631 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 10891 T1659 C120 P12625 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty1/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 10892 T1659 C120 P12625 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2>  C119_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:12632_solr, base_url=http://127.0.0.1:12632/solr}
[junit4:junit4]   2> 10906 T1681 C119 P12632 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty3/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 10906 T1681 C119 P12632 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 10910 T1681 C119 P12632 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12625/solr/collection1/&wt=javabin&version=2} status=0 QTime=8 
[junit4:junit4]   2> 10911 T1659 C120 P12625 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=24 
[junit4:junit4]   2> 10912 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[1]} 0 31
[junit4:junit4]   2> 10912 T1631 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):1800
[junit4:junit4]   2> 10913 T1631 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 10969 T1652 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 10980 T1708 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10980 T1710 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10980 T1651 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10980 T1665 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10980 T1677 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10980 T1703 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10980 T1689 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11652 T1691 C119 P12632 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 11652 T1691 C119 P12632 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=tlog{file=./org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty3/tlog/tlog.0000000000000000000 refcount=1}}
[junit4:junit4]   2> 11652 T1691 C119 P12632 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:12625/solr/collection1/. core=collection1
[junit4:junit4]   2> 11653 T1691 C119 P12632 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 11663 T1660 C120 P12625 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 11817 T1660 C120 P12625 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty1/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty1/index,segFN=segments_2,generation=2,filenames=[_0_Block_0.pos, _0_Block_0.tip, _0_Lucene40_0.tim, _0.fnm, _0_Block_0.doc, _0_Pulsing40_0.tim, _0_Memory_0.ram, _0_Block_0.tim, _0_nrm.cfs, _0_Pulsing40_0.prx, _0_Lucene40_0.prx, _0_Pulsing40_0.frq, _0_Lucene40_0.tip, _0_Lucene40_0.frq, _0_nrm.cfe, _0_Pulsing40_0.tip, segments_2, _0.fdx, _0.si, _0.fdt]
[junit4:junit4]   2> 11818 T1660 C120 P12625 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 11833 T1660 C120 P12625 oass.SolrIndexSearcher.<init> Opening Searcher@51ee25b5 main
[junit4:junit4]   2> 11833 T1660 C120 P12625 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 11835 T1666 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@51ee25b5 main{StandardDirectoryReader(segments_2:3 _0(4.0.0.2):C1)}
[junit4:junit4]   2> 11835 T1660 C120 P12625 /update {waitSearcher=true&commit=true&commit_end_point=true&wt=javabin&softCommit=false&version=2} {commit=} 0 172
[junit4:junit4]   2> 11836 T1691 C119 P12632 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 11837 T1691 C119 P12632 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 11839 T1661 C120 P12625 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 11839 T1661 C120 P12625 REQ /replication {command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
[junit4:junit4]   2> 11840 T1691 C119 P12632 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4]   2> 11840 T1691 C119 P12632 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 11840 T1691 C119 P12632 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 11844 T1661 C120 P12625 REQ /replication {command=filelist&generation=2&wt=javabin&qt=/replication&version=2} status=0 QTime=2 
[junit4:junit4]   2> 11845 T1691 C119 P12632 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 20
[junit4:junit4]   2> 11852 T1691 C119 P12632 oash.SnapPuller.fetchLatestIndex Starting download to ./org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty3/index.20120921234734750 fullCopy=true
[junit4:junit4]   2> 11855 T1661 C120 P12625 REQ /replication {file=_0_Block_0.tip&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11861 T1661 C120 P12625 REQ /replication {file=_0_Block_0.pos&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11865 T1661 C120 P12625 REQ /replication {file=_0_Lucene40_0.tim&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11869 T1661 C120 P12625 REQ /replication {file=_0_Pulsing40_0.tim&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11874 T1661 C120 P12625 REQ /replication {file=_0_Block_0.doc&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11878 T1661 C120 P12625 REQ /replication {file=_0.fnm&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11882 T1661 C120 P12625 REQ /replication {file=_0_Block_0.tim&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11886 T1661 C120 P12625 REQ /replication {file=_0_Memory_0.ram&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11890 T1661 C120 P12625 REQ /replication {file=_0_nrm.cfs&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11894 T1661 C120 P12625 REQ /replication {file=_0_Lucene40_0.prx&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11898 T1661 C120 P12625 REQ /replication {file=_0_Pulsing40_0.prx&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11902 T1661 C120 P12625 REQ /replication {file=_0_Pulsing40_0.frq&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11906 T1661 C120 P12625 REQ /replication {file=_0_Lucene40_0.tip&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11911 T1661 C120 P12625 REQ /replication {file=_0_Lucene40_0.frq&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11915 T1631 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 11916 T1661 C120 P12625 REQ /replication {file=_0_nrm.cfe&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11921 T1661 C120 P12625 REQ /replication {file=segments_2&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11926 T1661 C120 P12625 REQ /replication {file=_0_Pulsing40_0.tip&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11930 T1661 C120 P12625 REQ /replication {file=_0.fdx&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11935 T1661 C120 P12625 REQ /replication {file=_0.si&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11939 T1661 C120 P12625 REQ /replication {file=_0.fdt&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11940 T1691 C119 P12632 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 11988 T1691 C119 P12632 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20120921234734750
[junit4:junit4]   2> 11990 T1691 C119 P12632 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 11990 T1691 C119 P12632 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 11990 T1691 C119 P12632 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4]   2> 11997 T1691 C119 P12632 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=./org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty3/index/ new=./org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty3/index.20120921234734750
[junit4:junit4]   2> 11998 T1691 C119 P12632 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty3/index.20120921234734750 forceNew:true
[junit4:junit4]   2> 12009 T1691 C119 P12632 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty3/index.20120921234734750,segFN=segments_2,generation=2,filenames=[_0_Block_0.pos, _0_Block_0.tip, _0_Lucene40_0.tim, _0.fnm, _0_Block_0.doc, _0_Pulsing40_0.tim, _0_Memory_0.ram, _0_Block_0.tim, _0_nrm.cfs, _0_Pulsing40_0.prx, _0_Lucene40_0.prx, _0_Pulsing40_0.frq, _0_Lucene40_0.tip, _0_Lucene40_0.frq, _0_nrm.cfe, _0_Pulsing40_0.tip, segments_2, _0.fdx, _0.si, _0.fdt]
[junit4:junit4]   2> 12009 T1691 C119 P12632 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 12009 T1691 C119 P12632 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 12014 T1691 C119 P12632 oass.SolrIndexSearcher.<init> Opening Searcher@730ec85 main
[junit4:junit4]   2> 12016 T1690 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@730ec85 main{StandardDirectoryReader(segments_2:3:nrt _0(4.0.0.2):C1)}
[junit4:junit4]   2> 12016 T1690 oasc.CachingDirectoryFactory.close Closing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty3/index
[junit4:junit4]   2> 12016 T1690 oash.SnapPuller$2.onClose removing old index directory ./org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty3/index
[junit4:junit4]   2> 12018 T1691 C119 P12632 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=false,waitSearcher=false,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 12019 T1691 C119 P12632 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 12026 T1691 C119 P12632 oasc.RecoveryStrategy.replay Replaying buffered documents. core=collection1
[junit4:junit4]   2> 12026 T1714 C119 P12632 oasu.UpdateLog$LogReplayer.doReplay WARNING Starting log replay tlog{file=./org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty3/tlog/tlog.0000000000000000000 refcount=2} active=true starting pos=432
[junit4:junit4]   2> 12031 T1714 C119 P12632 oasu.DirectUpdateHandler2.commit start commit{flags=2,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 12032 T1714 C119 P12632 oass.SolrIndexSearcher.<init> Opening Searcher@4c55ead1 main
[junit4:junit4]   2> 12033 T1714 C119 P12632 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 12034 T1690 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4c55ead1 main{StandardDirectoryReader(segments_2:3:nrt _0(4.0.0.2):C1)}
[junit4:junit4]   2> 12035 T1714 C119 P12632 oasu.UpdateLog$LogReplayer.run WARNING Log replay finished. recoveryInfo=RecoveryInfo{adds=0 deletes=0 deleteByQuery=0 errors=0 positionOfStart=432}
[junit4:junit4]   2> 12035 T1691 C119 P12632 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 12037 T1691 C119 P12632 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 12499 T1652 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12606 T1708 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12606 T1689 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12606 T1677 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12607 T1665 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12607 T1651 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12606 T1703 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12606 T1710 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12917 T1631 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2>  C121_STATE=coll:collection1 core:collection1 props:{shard=shard2, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:12651_solr, base_url=http://127.0.0.1:12651/solr}
[junit4:junit4]   2> 13828 T1705 C121 P12651 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 13828 T1705 C121 P12651 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 13828 T1705 C121 P12651 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:12629/solr/collection1/. core=collection1
[junit4:junit4]   2> 13829 T1705 C121 P12651 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 13843 T1672 C122 P12629 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 13848 T1672 C122 P12629 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty2/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 13849 T1672 C122 P12629 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 13850 T1672 C122 P12629 oass.SolrIndexSearcher.<init> Opening Searcher@106a65e5 main
[junit4:junit4]   2> 13851 T1672 C122 P12629 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 13852 T1678 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@106a65e5 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 13853 T1672 C122 P12629 /update {waitSearcher=true&commit=true&commit_end_point=true&wt=javabin&softCommit=false&version=2} {commit=} 0 10
[junit4:junit4]   2> 13853 T1705 C121 P12651 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 13854 T1705 C121 P12651 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 13855 T1673 C122 P12629 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 13856 T1673 C122 P12629 REQ /replication {command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
[junit4:junit4]   2> 13860 T1705 C121 P12651 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty4/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 13860 T1705 C121 P12651 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 13861 T1705 C121 P12651 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 13863 T1705 C121 P12651 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty4/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty4/index,segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 13864 T1705 C121 P12651 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 13867 T1705 C121 P12651 oass.SolrIndexSearcher.<init> Opening Searcher@60dac43d main
[junit4:junit4]   2> 13867 T1705 C121 P12651 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 13869 T1704 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@60dac43d main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 13869 T1705 C121 P12651 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 13869 T1705 C121 P12651 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 13871 T1705 C121 P12651 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 13920 T1631 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 14174 T1652 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 14190 T1708 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14190 T1689 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14190 T1665 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14190 T1651 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14190 T1677 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14190 T1703 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14190 T1710 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14922 T1631 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 14926 T1643 C123 P12611 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 15030 T1643 C123 P12611 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/control/data/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/control/data/index,segFN=segments_2,generation=2,filenames=[_0_Block_0.pos, _0_Block_0.tip, _0_Lucene40_0.tim, _0.fnm, _0_Block_0.doc, _0_Pulsing40_0.tim, _0_Memory_0.ram, _0_Block_0.tim, _0_nrm.cfs, _0_Pulsing40_0.prx, _0_Lucene40_0.prx, _0_Pulsing40_0.frq, _0_Lucene40_0.tip, _0_Lucene40_0.frq, _0_nrm.cfe, _0_Pulsing40_0.tip, segments_2, _0.fdx, _0.si, _0.fdt]
[junit4:junit4]   2> 15031 T1643 C123 P12611 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 15055 T1643 C123 P12611 oass.SolrIndexSearcher.<init> Opening Searcher@13a4548a main
[junit4:junit4]   2> 15056 T1643 C123 P12611 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 15058 T1654 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@13a4548a main{StandardDirectoryReader(segments_2:3 _0(4.0.0.2):C1)}
[junit4:junit4]   2> 15058 T1643 C123 P12611 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 132
[junit4:junit4]   2> 15061 T1671 C122 P12629 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 15065 T1671 C122 P12629 oass.SolrIndexSearcher.<init> Opening Searcher@4ccc4940 main
[junit4:junit4]   2> 15065 T1671 C122 P12629 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 15067 T1678 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4ccc4940 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 15067 T1671 C122 P12629 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:12625/solr/collection1/, StdNode: http://127.0.0.1:12632/solr/collection1/, StdNode: http://127.0.0.1:12651/solr/collection1/]
[junit4:junit4]   2>  C119_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:12632_solr, base_url=http://127.0.0.1:12632/solr}
[junit4:junit4]   2> 15070 T1681 C119 P12632 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 15070 T1659 C120 P12625 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 15074 T1681 C119 P12632 oass.SolrIndexSearcher.<init> Opening Searcher@485bdc53 main
[junit4:junit4]   2> 15075 T1681 C119 P12632 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 15076 T1690 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@485bdc53 main{StandardDirectoryReader(segments_2:3:nrt _0(4.0.0.2):C1)}
[junit4:junit4]   2> 15076 T1681 C119 P12632 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&expungeDeletes=false&softCommit=false&version=2} {commit=} 0 6
[junit4:junit4]   2>  C121_STATE=coll:collection1 core:collection1 props:{shard=shard2, roles=null, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:12651_solr, base_url=http://127.0.0.1:12651/solr}
[junit4:junit4]   2> 15082 T1695 C121 P12651 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 15085 T1659 C120 P12625 oass.SolrIndexSearcher.<init> Opening Searcher@3817eaf7 main
[junit4:junit4]   2> 15086 T1659 C120 P12625 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 15087 T1695 C121 P12651 oass.SolrIndexSearcher.<init> Opening Searcher@1b9b07b7 main
[junit4:junit4]   2> 15088 T1695 C121 P12651 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 15088 T1666 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3817eaf7 main{StandardDirectoryReader(segments_2:3 _0(4.0.0.2):C1)}
[junit4:junit4]   2> 15089 T1704 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1b9b07b7 main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 15089 T1659 C120 P12625 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&expungeDeletes=false&softCommit=false&version=2} {commit=} 0 19
[junit4:junit4]   2> 15090 T1695 C121 P12651 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&expungeDeletes=false&softCommit=false&version=2} {commit=} 0 8
[junit4:junit4]   2> 15090 T1671 C122 P12629 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 29
[junit4:junit4]   2> 15096 T1644 C123 P12611 REQ /select {fl=id,score&shard.url=127.0.0.1:12611/solr/collection1/&NOW=1348231657997&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 15100 T1644 C123 P12611 REQ /select {shard.url=127.0.0.1:12611/solr/collection1/&NOW=1348231657997&q=*:*&ids=1&distrib=false&isShard=true&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 15102 T1643 C123 P12611 REQ /select {wt=javabin&q=*:*&version=2} hits=1 status=0 QTime=9 
[junit4:junit4]   2> 15102 T1631 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:12608/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@55c9aec6
[junit4:junit4]   2> 15103 T1718 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:12608
[junit4:junit4]   2> 15103 T1631 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 15104 T1718 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:12608, initiating session
[junit4:junit4]   2> 15104 T1633 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:12721
[junit4:junit4]   2> 15105 T1633 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:12721
[junit4:junit4]   2> 15106 T1635 oazs.NIOServerCnxn.finishSessionInit Established session 0x139e8de3f250009 with negotiated timeout 10000 for client /140.211.11.196:12721
[junit4:junit4]   2> 15106 T1718 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:12608, sessionid = 0x139e8de3f250009, negotiated timeout = 10000
[junit4:junit4]   2> 15107 T1719 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@55c9aec6 name:ZooKeeperConnection Watcher:127.0.0.1:12608/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 15107 T1631 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 15108 T1631 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 15110 T1636 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x139e8de3f250009
[junit4:junit4]   2> 15111 T1719 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 15111 T1633 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:12721 which had sessionid 0x139e8de3f250009
[junit4:junit4]   2> 15111 T1631 oaz.ZooKeeper.close Session: 0x139e8de3f250009 closed
[junit4:junit4]   2> 15113 T1662 C120 P12625 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 15115 T1674 C122 P12629 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 15120 T1663 C120 P12625 REQ /select {fl=id,score&shard.url=127.0.0.1:12625/solr/collection1/|127.0.0.1:12632/solr/collection1/&NOW=1348231658020&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 15120 T1696 C121 P12651 REQ /select {fl=id,score&shard.url=127.0.0.1:12629/solr/collection1/|127.0.0.1:12651/solr/collection1/&NOW=1348231658020&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 15123 T1663 C120 P12625 REQ /select {shard.url=127.0.0.1:12625/solr/collection1/|127.0.0.1:12632/solr/collection1/&NOW=1348231658020&q=*:*&ids=1&distrib=false&isShard=true&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 15124 T1682 C119 P12632 REQ /select {wt=javabin&q=*:*&version=2} hits=1 status=0 QTime=8 
[junit4:junit4]   2> 15133 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[2 (1413723359052562432)]} 0 6
[junit4:junit4]   2> 15144 T1695 C121 P12651 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12629/solr/collection1/&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 15145 T1675 C122 P12629 REQ /update {distrib.from=http://127.0.0.1:12625/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=9 
[junit4:junit4]   2> 15145 T1658 C120 P12625 /update {wt=javabin&version=2} {add=[2]} 0 11
[junit4:junit4]   2> 15150 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[3 (1413723359073533952)]} 0 2
[junit4:junit4]   2> 15157 T1695 C121 P12651 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15158 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[3 (1413723359078776832)]} 0 5
[junit4:junit4]   2> 15162 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[4 (1413723359086116864)]} 0 2
[junit4:junit4]   2> 15177 T1681 C119 P12632 REQ /update {distrib.from=http://127.0.0.1:12625/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 15177 T1658 C120 P12625 /update {wt=javabin&version=2} {add=[4 (1413723359091359744)]} 0 12
[junit4:junit4]   2> 15181 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[5 (1413723359106039808)]} 0 2
[junit4:junit4]   2> 15191 T1695 C121 P12651 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12629/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15192 T1675 C122 P12629 REQ /update {distrib.from=http://127.0.0.1:12625/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 15192 T1658 C120 P12625 /update {wt=javabin&version=2} {add=[5]} 0 8
[junit4:junit4]   2> 15197 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[6 (1413723359122817024)]} 0 2
[junit4:junit4]   2> 15208 T1695 C121 P12651 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12629/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15209 T1675 C122 P12629 REQ /update {distrib.from=http://127.0.0.1:12625/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 15209 T1658 C120 P12625 /update {wt=javabin&version=2} {add=[6]} 0 9
[junit4:junit4]   2> 15214 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[7 (1413723359140642816)]} 0 2
[junit4:junit4]   2> 15223 T1695 C121 P12651 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12629/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15224 T1675 C122 P12629 REQ /update {distrib.from=http://127.0.0.1:12625/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 15224 T1658 C120 P12625 /update {wt=javabin&version=2} {add=[7]} 0 7
[junit4:junit4]   2> 15229 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[8 (1413723359156371456)]} 0 2
[junit4:junit4]   2> 15238 T1681 C119 P12632 REQ /update {distrib.from=http://127.0.0.1:12625/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15239 T1658 C120 P12625 /update {wt=javabin&version=2} {add=[8 (1413723359161614336)]} 0 7
[junit4:junit4]   2> 15244 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[9 (1413723359172100096)]} 0 2
[junit4:junit4]   2> 15254 T1695 C121 P12651 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12629/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15255 T1675 C122 P12629 REQ /update {distrib.from=http://127.0.0.1:12625/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 15255 T1658 C120 P12625 /update {wt=javabin&version=2} {add=[9]} 0 8
[junit4:junit4]   2> 15260 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[10 (1413723359188877312)]} 0 2
[junit4:junit4]   2> 15271 T1681 C119 P12632 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12625/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15272 T1659 C120 P12625 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 15273 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[10]} 0 10
[junit4:junit4]   2> 15300 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[11 (1413723359206703104)]} 0 25
[junit4:junit4]   2> 15311 T1681 C119 P12632 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12625/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15311 T1659 C120 P12625 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 15312 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[11]} 0 9
[junit4:junit4]   2> 15318 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[12 (1413723359248646144)]} 0 3
[junit4:junit4]   2> 15326 T1681 C119 P12632 REQ /update {distrib.from=http://127.0.0.1:12625/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15327 T1658 C120 P12625 /update {wt=javabin&version=2} {add=[12 (1413723359254937600)]} 0 6
[junit4:junit4]   2> 15331 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[13 (1413723359264374784)]} 0 1
[junit4:junit4]   2> 15338 T1681 C119 P12632 REQ /update {distrib.from=http://127.0.0.1:12625/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15339 T1658 C120 P12625 /update {wt=javabin&version=2} {add=[13 (1413723359268569088)]} 0 5
[junit4:junit4]   2> 15343 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[14 (1413723359276957696)]} 0 1
[junit4:junit4]   2> 15353 T1681 C119 P12632 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12625/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15354 T1659 C120 P12625 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 15355 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[14]} 0 9
[junit4:junit4]   2> 15358 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[15 (1413723359292686336)]} 0 1
[junit4:junit4]   2> 15368 T1681 C119 P12632 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12625/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15369 T1659 C120 P12625 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 15370 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[15]} 0 9
[junit4:junit4]   2> 15373 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[16 (1413723359308414976)]} 0 1
[junit4:junit4]   2> 15382 T1681 C119 P12632 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12625/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15383 T1659 C120 P12625 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 15383 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[16]} 0 7
[junit4:junit4]   2> 15389 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[17 (1413723359323095040)]} 0 3
[junit4:junit4]   2> 15398 T1695 C121 P12651 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 15398 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[17 (1413723359328337920)]} 0 7
[junit4:junit4]   2> 15402 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[100 (1413723359338823680)]} 0 1
[junit4:junit4]   2> 15444 T1681 C119 P12632 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12625/solr/collection1/&wt=javabin&version=2} status=0 QTime=18 
[junit4:junit4]   2> 15445 T1659 C120 P12625 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=38 
[junit4:junit4]   2> 15446 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[100]} 0 41
[junit4:junit4]   2> 15450 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[101 (1413723359389155328)]} 0 1
[junit4:junit4]   2> 15461 T1681 C119 P12632 REQ /update {distrib.from=http://127.0.0.1:12625/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15461 T1658 C120 P12625 /update {wt=javabin&version=2} {add=[101 (1413723359393349632)]} 0 8
[junit4:junit4]   2> 15465 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[102 (1413723359404883968)]} 0 1
[junit4:junit4]   2> 15472 T1681 C119 P12632 REQ /update {distrib.from=http://127.0.0.1:12625/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15472 T1658 C120 P12625 /update {wt=javabin&version=2} {add=[102 (1413723359409078272)]} 0 4
[junit4:junit4]   2> 15494 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[103 (1413723359416418304)]} 0 19
[junit4:junit4]   2> 15501 T1695 C121 P12651 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15501 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[103 (1413723359439486976)]} 0 4
[junit4:junit4]   2> 15507 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[104 (1413723359446827008)]} 0 3
[junit4:junit4]   2> 15514 T1695 C121 P12651 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12629/solr/collection1/&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 15515 T1675 C122 P12629 REQ /update {distrib.from=http://127.0.0.1:12625/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 15515 T1658 C120 P12625 /update {wt=javabin&version=2} {add=[104]} 0 6
[junit4:junit4]   2> 15519 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[105 (1413723359461507072)]} 0 1
[junit4:junit4]   2> 15554 T1695 C121 P12651 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=19 
[junit4:junit4]   2> 15555 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[105 (1413723359464652800)]} 0 34
[junit4:junit4]   2> 15560 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[106 (1413723359503450112)]} 0 2
[junit4:junit4]   2> 15570 T1695 C121 P12651 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 15570 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[106 (1413723359507644416)]} 0 8
[junit4:junit4]   2> 15574 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[107 (1413723359519178752)]} 0 1
[junit4:junit4]   2> 15583 T1681 C119 P12632 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12625/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15584 T1659 C120 P12625 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 15584 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[107]} 0 7
[junit4:junit4]   2> 15588 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[108 (1413723359533858816)]} 0 1
[junit4:junit4]   2> 15597 T1681 C119 P12632 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12625/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15598 T1659 C120 P12625 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 15598 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[108]} 0 7
[junit4:junit4]   2> 15602 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[109 (1413723359548538880)]} 0 1
[junit4:junit4]   2> 15609 T1681 C119 P12632 REQ /update {distrib.from=http://127.0.0.1:12625/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15610 T1658 C120 P12625 /update {wt=javabin&version=2} {add=[109 (1413723359552733184)]} 0 5
[junit4:junit4]   2> 15613 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[110 (1413723359560073216)]} 0 1
[junit4:junit4]   2> 15622 T1681 C119 P12632 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12625/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15623 T1659 C120 P12625 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 15623 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[110]} 0 7
[junit4:junit4]   2> 15627 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[111 (1413723359574753280)]} 0 1
[junit4:junit4]   2> 15637 T1681 C119 P12632 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12625/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15638 T1659 C120 P12625 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 15638 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[111]} 0 7
[junit4:junit4]   2> 15642 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[112 (1413723359590481920)]} 0 1
[junit4:junit4]   2> 15651 T1695 C121 P12651 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12629/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15652 T1675 C122 P12629 REQ /update {distrib.from=http://127.0.0.1:12625/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 15653 T1658 C120 P12625 /update {wt=javabin&version=2} {add=[112]} 0 8
[junit4:junit4]   2> 15670 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[113 (1413723359605161984)]} 0 15
[junit4:junit4]   2> 15678 T1681 C119 P12632 REQ /update {distrib.from=http://127.0.0.1:12625/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15679 T1658 C120 P12625 /update {wt=javabin&version=2} {add=[113 (1413723359624036352)]} 0 6
[junit4:junit4]   2> 15684 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[114 (1413723359632424960)]} 0 3
[junit4:junit4]   2> 15693 T1681 C119 P12632 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12625/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15694 T1659 C120 P12625 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 15694 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[114]} 0 7
[junit4:junit4]   2> 15698 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[115 (1413723359649202176)]} 0 1
[junit4:junit4]   2> 15707 T1695 C121 P12651 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12629/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15708 T1675 C122 P12629 REQ /update {distrib.from=http://127.0.0.1:12625/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 15708 T1658 C120 P12625 /update {wt=javabin&version=2} {add=[115]} 0 7
[junit4:junit4]   2> 15712 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[116 (1413723359663882240)]} 0 1
[junit4:junit4]   2> 15721 T1695 C121 P12651 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12629/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15722 T1675 C122 P12629 REQ /update {distrib.from=http://127.0.0.1:12625/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 15722 T1658 C120 P12625 /update {wt=javabin&version=2} {add=[116]} 0 7
[junit4:junit4]   2> 15727 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[117 (1413723359679610880)]} 0 1
[junit4:junit4]   2> 15734 T1695 C121 P12651 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15735 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[117 (1413723359683805184)]} 0 5
[junit4:junit4]   2> 15740 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[118 (1413723359693242368)]} 0 2
[junit4:junit4]   2> 15770 T1681 C119 P12632 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12625/solr/collection1/&wt=javabin&version=2} status=0 QTime=14 
[junit4:junit4]   2> 15771 T1659 C120 P12625 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=26 
[junit4:junit4]   2> 15771 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[118]} 0 28
[junit4:junit4]   2> 15775 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[119 (1413723359729942528)]} 0 1
[junit4:junit4]   2> 15782 T1695 C121 P12651 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15783 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[119 (1413723359734136832)]} 0 5
[junit4:junit4]   2> 15787 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[120 (1413723359742525440)]} 0 1
[junit4:junit4]   2> 15796 T1695 C121 P12651 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12629/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15797 T1675 C122 P12629 REQ /update {distrib.from=http://127.0.0.1:12625/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 15797 T1658 C120 P12625 /update {wt=javabin&version=2} {add=[120]} 0 7
[junit4:junit4]   2> 15801 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[121 (1413723359757205504)]} 0 1
[junit4:junit4]   2> 15808 T1695 C121 P12651 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15809 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[121 (1413723359761399808)]} 0 5
[junit4:junit4]   2> 15812 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[122 (1413723359768739840)]} 0 1
[junit4:junit4]   2> 15822 T1681 C119 P12632 REQ /update {distrib.from=http://127.0.0.1:12625/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15823 T1658 C120 P12625 /update {wt=javabin&version=2} {add=[122 (1413723359772934144)]} 0 8
[junit4:junit4]   2> 15839 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[123 (1413723359784468480)]} 0 13
[junit4:junit4]   2> 15845 T1681 C119 P12632 REQ /update {distrib.from=http://127.0.0.1:12625/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15846 T1658 C120 P12625 /update {wt=javabin&version=2} {add=[123 (1413723359800197120)]} 0 5
[junit4:junit4]   2> 15850 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[124 (1413723359807537152)]} 0 2
[junit4:junit4]   2> 15857 T1681 C119 P12632 REQ /update {distrib.from=http://127.0.0.1:12625/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15858 T1658 C120 P12625 /update {wt=javabin&version=2} {add=[124 (1413723359812780032)]} 0 5
[junit4:junit4]   2> 15861 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[125 (1413723359820120064)]} 0 1
[junit4:junit4]   2> 15870 T1681 C119 P12632 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12625/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15871 T1659 C120 P12625 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 15871 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[125]} 0 7
[junit4:junit4]   2> 15875 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[126 (1413723359834800128)]} 0 1
[junit4:junit4]   2> 15882 T1695 C121 P12651 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15883 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[126 (1413723359838994432)]} 0 5
[junit4:junit4]   2> 15886 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[127 (1413723359846334464)]} 0 1
[junit4:junit4]   2> 15911 T1695 C121 P12651 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=12 
[junit4:junit4]   2> 15911 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[127 (1413723359850528768)]} 0 22
[junit4:junit4]   2> 15915 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[128 (1413723359876743168)]} 0 1
[junit4:junit4]   2> 15924 T1695 C121 P12651 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15925 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[128 (1413723359880937472)]} 0 7
[junit4:junit4]   2> 15928 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[129 (1413723359890374656)]} 0 1
[junit4:junit4]   2> 15937 T1681 C119 P12632 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12625/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15938 T1659 C120 P12625 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 15938 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[129]} 0 7
[junit4:junit4]   2> 15942 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[130 (1413723359905054720)]} 0 1
[junit4:junit4]   2> 15949 T1695 C121 P12651 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15950 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[130 (1413723359909249024)]} 0 5
[junit4:junit4]   2> 15953 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[131 (1413723359916589056)]} 0 1
[junit4:junit4]   2> 15962 T1695 C121 P12651 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12629/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15963 T1675 C122 P12629 REQ /update {distrib.from=http://127.0.0.1:12625/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 15963 T1658 C120 P12625 /update {wt=javabin&version=2} {add=[131]} 0 7
[junit4:junit4]   2> 15967 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[132 (1413723359931269120)]} 0 1
[junit4:junit4]   2> 15974 T1681 C119 P12632 REQ /update {distrib.from=http://127.0.0.1:12625/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15975 T1658 C120 P12625 /update {wt=javabin&version=2} {add=[132 (1413723359935463424)]} 0 5
[junit4:junit4]   2> 15990 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[133 (1413723359942803456)]} 0 13
[junit4:junit4]   2> 15997 T1681 C119 P12632 REQ /update {distrib.from=http://127.0.0.1:12625/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15998 T1658 C120 P12625 /update {wt=javabin&version=2} {add=[133 (1413723359959580672)]} 0 5
[junit4:junit4]   2> 16002 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[134 (1413723359966920704)]} 0 2
[junit4:junit4]   2> 16009 T1695 C121 P12651 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16010 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[134 (1413723359972163584)]} 0 5
[junit4:junit4]   2> 16013 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[135 (1413723359979503616)]} 0 1
[junit4:junit4]   2> 16022 T1681 C119 P12632 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12625/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16023 T1659 C120 P12625 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 16023 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[135]} 0 7
[junit4:junit4]   2> 16027 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[136 (1413723359994183680)]} 0 1
[junit4:junit4]   2> 16036 T1695 C121 P12651 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12629/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16037 T1675 C122 P12629 REQ /update {distrib.from=http://127.0.0.1:12625/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 16037 T1658 C120 P12625 /update {wt=javabin&version=2} {add=[136]} 0 8
[junit4:junit4]   2> 16041 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[137 (1413723360008863744)]} 0 1
[junit4:junit4]   2> 16050 T1695 C121 P12651 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12629/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16053 T1675 C122 P12629 REQ /update {distrib.from=http://127.0.0.1:12625/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 16053 T1658 C120 P12625 /update {wt=javabin&version=2} {add=[137]} 0 9
[junit4:junit4]   2> 16057 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[138 (1413723360025640960)]} 0 1
[junit4:junit4]   2> 16067 T1681 C119 P12632 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12625/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16068 T1659 C120 P12625 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 16069 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[138]} 0 9
[junit4:junit4]   2> 16073 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[139 (1413723360042418176)]} 0 1
[junit4:junit4]   2> 16080 T1695 C121 P12651 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16081 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[139 (1413723360046612480)]} 0 5
[junit4:junit4]   2> 16085 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[140 (1413723360055001088)]} 0 1
[junit4:junit4]   2> 16095 T1695 C121 P12651 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12629/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16096 T1675 C122 P12629 REQ /update {distrib.from=http://127.0.0.1:12625/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 16097 T1658 C120 P12625 /update {wt=javabin&version=2} {add=[140]} 0 9
[junit4:junit4]   2> 16100 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[141 (1413723360070729728)]} 0 1
[junit4:junit4]   2> 16109 T1695 C121 P12651 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12629/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16110 T1675 C122 P12629 REQ /update {distrib.from=http://127.0.0.1:12625/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 16110 T1658 C120 P12625 /update {wt=javabin&version=2} {add=[141]} 0 7
[junit4:junit4]   2> 16114 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[142 (1413723360085409792)]} 0 1
[junit4:junit4]   2> 16142 T1695 C121 P12651 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12629/solr/collection1/&wt=javabin&version=2} status=0 QTime=12 
[junit4:junit4]   2> 16143 T1675 C122 P12629 REQ /update {distrib.from=http://127.0.0.1:12625/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=24 
[junit4:junit4]   2> 16143 T1658 C120 P12625 /update {wt=javabin&version=2} {add=[142]} 0 26
[junit4:junit4]   2> 16159 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[143 (1413723360120012800)]} 0 13
[junit4:junit4]   2> 16169 T1695 C121 P12651 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 16170 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[143 (1413723360136790016)]} 0 8
[junit4:junit4]   2> 16175 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[144 (1413723360148324352)]} 0 2
[junit4:junit4]   2> 16182 T1695 C121 P12651 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16183 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[144 (1413723360153567232)]} 0 5
[junit4:junit4]   2> 16186 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[145 (1413723360160907264)]} 0 1
[junit4:junit4]   2> 16193 T1695 C121 P12651 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16194 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[145 (1413723360165101568)]} 0 5
[junit4:junit4]   2> 16197 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[146 (1413723360172441600)]} 0 1
[junit4:junit4]   2> 16223 T1681 C119 P12632 REQ /update {distrib.from=http://127.0.0.1:12625/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=12 
[junit4:junit4]   2> 16224 T1658 C120 P12625 /update {wt=javabin&version=2} {add=[146 (1413723360176635904)]} 0 24
[junit4:junit4]   2> 16228 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[147 (1413723360204947456)]} 0 1
[junit4:junit4]   2> 16235 T1695 C121 P12651 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16236 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[147 (1413723360209141760)]} 0 5
[junit4:junit4]   2> 16239 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[148 (1413723360216481792)]} 0 1
[junit4:junit4]   2> 16250 T1681 C119 P12632 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12625/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 16251 T1659 C120 P12625 REQ /update {distrib.from=http://127.0.0.1:12629/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=8 
[junit4:junit4]   2> 16252 T1671 C122 P12629 /update {wt=javabin&version=2} {add=[148]} 0 11
[junit4:junit4]   2> 16256 T1643 C123 P12611 /update {wt=javabin&version=2} {add=[149 (1413723360234307584)]} 0 1
[junit4:junit4]   2> 16265 T1695 C121 P12651 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:12629/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 16266 T1675 C122 P12629 REQ /update {distrib.from=http://127.0.0.1:12625/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 16266 T1658 C120 P12625 /update {wt=javabin&version=2} {add=[149]} 0 7
[junit4:junit4]   2> 16267 T1631 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):1800
[junit4:junit4]   2> 16268 T1631 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 16270 T1643 C123 P12611 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 16709 T1643 C123 P12611 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/control/data/index,segFN=segments_2,generation=2,filenames=[_0_Block_0.pos, _0_Block_0.tip, _0_Lucene40_0.tim, _0.fnm, _0_Block_0.doc, _0_Pulsing40_0.tim, _0_Memory_0.ram, _0_Block_0.tim, _0_nrm.cfs, _0_Pulsing40_0.prx, _0_Lucene40_0.prx, _0_Pulsing40_0.frq, _0_Lucene40_0.tip, _0_Lucene40_0.frq, _0_nrm.cfe, _0_Pulsing40_0.tip, segments_2, _0.fdx, _0.si, _0.fdt]
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/control/data/index,segFN=segments_3,generation=3,filenames=[_5_nrm.cfe, _2_Block_0.pos, _5_Memory_0.ram, _7.si, _3.fdt, _0_Lucene40_0.prx, _0_Pulsing40_0.frq, _7_Memory_0.ram, _7.fnm, _6_Block_0.pos, _5_Pulsing40_0.tip, _5_Pulsing40_0.tim, _1_Block_0.pos, _1_Block_0.tip, _0_Lucene40_0.tim, _0_Pulsing40_0.tim, _1_Block_0.tim, _0_Memory_0.ram, _2.fdt, _3_Pulsing40_0.tip, _7.fdx, _2.fdx, _7.fdt, _3_Pulsing40_0.tim, _0_Lucene40_0.tip, _3_Block_0.pos, _3_Block_0.doc, _1.fdx, _7_Pulsing40_0.frq, _1.fdt, _5_nrm.cfs, _2_Lucene40_0.prx, _7_Block_0.pos, _3.si, _6.fdt, _6_Memory_0.ram, _2.si, _3_Pulsing40_0.frq, _2_Pulsing40_0.tim, _2_Block_0.tim, _6.fdx, _2_Pulsing40_0.tip, _2_Block_0.tip, _3.fnm, _5_Block_0.tim, _4_Pulsing40_0.prx, _1_Memory_0.ram, _2_nrm.cfe, _5_Pulsing40_0.frq, _0_Lucene40_0.frq, _0_Pulsing40_0.tip, _2_nrm.cfs, _5_Block_0.doc, _4_Block_0.pos, _3_Block_0.tip, _4_Block_0.tip, _1_Lucene40_0.frq, _2.fnm, _7_Pulsing40_0.tim, _3.fdx, _4_Pulsing40_0.tip, _4_Pulsing40_0.tim, _2_Lucene40_0.frq, _5_Pulsing40_0.prx, _1.si, _6.si, _6.fnm, _7_Pulsing40_0.tip, _1_Lucene40_0.tim, _3_nrm.cfe, _0_Block_0.tip, _5.fdt, _1_Pulsing40_0.tip, _6_Pulsing40_0.frq, _0_Block_0.tim, _1_Pulsing40_0.tim, _7_Block_0.tim, _4.fnm, _4_nrm.cfe, _7_Block_0.tip, _0_Pulsing40_0.prx, _7_Pulsing40_0.prx, _1.fnm, _1_Lucene40_0.tip, _1_Pulsing40_0.frq, _4.fdx, _2_Lucene40_0.tip, _3_Block_0.tim, _6_Pulsing40_0.tim, _1_Pulsing40_0.prx, _6_Pulsing40_0.tip, _2_Lucene40_0.tim, _1_Block_0.doc, _2_Pulsing40_0.prx, _0.fnm, _4_Block_0.tim, _6_Block_0.doc, _2_Pulsing40_0.frq, _1_Lucene40_0.prx, _5.si, _3_nrm.cfs, _6_Pulsing40_0.prx, _4_Memory_0.ram, _4_nrm.cfs, _5_Block_0.tip, _7_Block_0.doc, _0_Block_0.pos, _4_Block_0.doc, _6_nrm.cfs, _7_nrm.cfs, _5_Block_0.pos, _2_Memory_0.ram, _0.si, _3_Memory_0.ram, _1_nrm.cfs, _5.fnm, _0_Block_0.doc, _7_nrm.cfe, _6_nrm.cfe, _0_nrm.cfs, _4.fdt, _4.si, _1_nrm.cfe, _3_Pulsing40_0.prx, _4_Pulsing40_0.frq, _6_Block_0.tip, _0_nrm.cfe, _5.fdx, _0.fdx, _6_Block_0.tim, _2_Block_0.doc, segments_3, _0.fdt]
[junit4:junit4]   2> 16710 T1643 C123 P12611 oasc.SolrDeletionPolicy.updateCommits newest commit = 3
[junit4:junit4]   2> 16798 T1643 C123 P12611 oass.SolrIndexSearcher.<init> Opening Searcher@538cf3d4 main
[junit4:junit4]   2> 16799 T1643 C123 P12611 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 16800 T1654 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@538cf3d4 main{StandardDirectoryReader(segments_3:17 _0(4.0.0.2):C1 _1(4.0.0.2):C10 _2(4.0.0.2):C10 _3(4.0.0.2):C10 _4(4.0.0.2):C10 _5(4.0.0.2):C10 _6(4.0.0.2):C10 _7(4.0.0.2):C6)}
[junit4:junit4]   2> 16801 T1643 C123 P12611 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 531
[junit4:junit4]   2> 16804 T1658 C120 P12625 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 17099 T1658 C120 P12625 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty1/index,segFN=segments_2,generation=2,filenames=[_0_Block_0.pos, _0_Block_0.tip, _0_Lucene40_0.tim, _0.fnm, _0_Block_0.doc, _0_Pulsing40_0.tim, _0_Memory_0.ram, _0_Block_0.tim, _0_nrm.cfs, _0_Pulsing40_0.prx, _0_Lucene40_0.prx, _0_Pulsing40_0.frq, _0_Lucene40_0.tip, _0_Lucene40_0.frq, _0_nrm.cfe, _0_Pulsing40_0.tip, segments_2, _0.fdx, _0.si, _0.fdt]
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty1/index,segFN=segments_3,generation=3,filenames=[_3_nrm.cfe, _1_Lucene40_0.tim, _0_Block_0.tip, _2_Block_0.pos, _1_Pulsing40_0.tip, _0_Block_0.tim, _1_Pulsing40_0.tim, _4_nrm.cfe, _4.fnm, _3.fdt, _0_Pulsing40_0.prx, _0_Lucene40_0.prx, _0_Pulsing40_0.frq, _1.fnm, _1_Lucene40_0.tip, _4.fdx, _1_Pulsing40_0.frq, _3_Block_0.tim, _1_Pulsing40_0.prx, _1_Block_0.doc, _2_Pulsing40_0.prx, _1_Block_0.tip, _1_Block_0.pos, _0_Lucene40_0.tim, _4_Block_0.tim, _0.fnm, _0_Pulsing40_0.tim, _1_Block_0.tim, _0_Memory_0.ram, _3_Pulsing40_0.tip, _2.fdt, _2.fdx, _3_Pulsing40_0.tim, _2_Pulsing40_0.frq, _3_Block_0.pos, _0_Lucene40_0.tip, _1_Lucene40_0.prx, _3_Block_0.doc, _3_nrm.cfs, _1.fdx, _1.fdt, _4_Memory_0.ram, _4_nrm.cfs, _3.si, _3_Pulsing40_0.frq, _2.si, _0_Block_0.pos, _2_Pulsing40_0.tim, _2_Block_0.tim, _2_Block_0.tip, _2_Pulsing40_0.tip, _3.fnm, _4_Block_0.doc, _4_Pulsing40_0.prx, _2_nrm.cfe, _1_Memory_0.ram, _0_Lucene40_0.frq, _0_Pulsing40_0.tip, _2_Memory_0.ram, _3_Memory_0.ram, _2_nrm.cfs, _0.si, _4_Block_0.pos, _3_Block_0.tip, _1_nrm.cfs, _0_Block_0.doc, _4_Block_0.tip, _1_Lucene40_0.frq, _4.si, _4.fdt, _0_nrm.cfs, _1_nrm.cfe, _2.fnm, _3.fdx, _4_Pulsing40_0.tip, _4_Pulsing40_0.frq, _3_Pulsing40_0.prx, _4_Pulsing40_0.tim, _1.si, _0_nrm.cfe, _0.fdx, _2_Block_0.doc, _0.fdt, segments_3]
[junit4:junit4]   2> 17100 T1658 C120 P12625 oasc.SolrDeletionPolicy.updateCommits newest commit = 3
[junit4:junit4]   2> 17139 T1658 C120 P12625 oass.SolrIndexSearcher.<init> Opening Searcher@5ed6ac2d main
[junit4:junit4]   2> 17140 T1658 C120 P12625 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 17141 T1666 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5ed6ac2d main{StandardDirectoryReader(segments_3:11 _0(4.0.0.2):C1 _1(4.0.0.2):C10 _2(4.0.0.2):C10 _3(4.0.0.2):C10 _4(4.0.0.2):C1)}
[junit4:junit4]   2> 17142 T1658 C120 P12625 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:12632/solr/collection1/, StdNode: http://127.0.0.1:12629/solr/collection1/, StdNode: http://127.0.0.1:12651/solr/collection1/]
[junit4:junit4]   2> 17144 T1681 C119 P12632 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 17145 T1695 C121 P12651 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 17145 T1675 C122 P12629 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 17884 T1695 C121 P12651 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty4/index,segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/jetty4/index,segFN=segments_3,generation=3,filenames=[_3_nrm.cfe, _0_Block_0.tip, _2_Block_0.pos, _1_Pulsing40_0.tip, _0_Block_0.tim, _1_Pulsing40_0.tim, _3.fdt, _0_Pulsing40_0.prx, _0_Lucene40_0.prx, _0_Pulsing40_0.frq, _1.fnm, _1_Pulsing40_0.frq, _3_Block_0.tim, _1_Pulsing40_0.prx, _1_Block_0.doc, _2_Pulsing40_0.prx, _1_Block_0.tip, _1_Block_0.pos, _0_Lucene40_0.tim, _0.fnm, _0_Pulsing40_0.tim, _1_Block_0.tim, _0_Memory_0.ram, _3_Pulsing40_0.tip, _2.fdt, _2.fdx, _3_Pulsing40_0.tim, _2_Pulsing40_0.frq, _3_Block_0.pos, _0_Lucene40_0.tip, _3_Block_0.doc, _3_nrm.cfs, _1.fdx, _1.fdt, _3.si, _3_Pulsing40_0.frq, _2.si, _0_Block_0.pos, _2_Pulsing40_0.tim, _2_Block_0.tim, _2_Block_0.tip, _2_Pulsing40_0.tip, _3.fnm, _1_Memory_0.ram, _2_nrm.cfe, _0_Lucene40_0.frq, _0_Pulsing40_0.tip, _2_Memory_0.ram, _3_Memory_0.ram, _0.si, _2_nrm.cfs, _3_Block_0.tip, _1_nrm.cfs, _0_Block_0.doc, _0_nrm.cfs, _1_nrm.cfe, _2.fnm, _3.fdx, _3_Pulsing40_0.prx, _1.si, _0_nrm.cfe, _0.fdx, _2_Block_0.doc, _0.fdt, segments_3]
[junit4:junit4]   2> 17884 T1695 C121 P12651 oasc.SolrDeletionPolicy.updateCommits newest commit = 3
[junit4:juni

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

.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> 306844 T1703 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-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-1348231642908/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> 306849 T1703 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 306851 T1703 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> 306852 T1703 oasu.DefaultSolrCoreState.decref SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 306853 T1703 oasu.DefaultSolrCoreState.decref Closing SolrCoreState - canceling any ongoing recovery
[junit4:junit4]   2> 306854 T1703 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 306854 T1703 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 306854 T1703 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 306854 T1703 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 306854 T1703 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3409c845 name:ZooKeeperConnection Watcher:127.0.0.1:12608/solr got event WatchedEvent state:Disconnected type:None path:null path:null type:None
[junit4:junit4]   2> 306855 T1703 oascc.ConnectionManager.process Client->ZooKeeper status change trigger but we are already closed
[junit4:junit4]   2> 306855 T1703 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> NOTE: test params are: codec=Lucene40: {n_f1=Block(blocksize=128), foo_b=Lucene40(minBlockSize=28 maxBlockSize=143), foo_d=PostingsFormat(name=Memory doPackFST= false), foo_f=Lucene40(minBlockSize=28 maxBlockSize=143), n_tl1=Block(blocksize=128), n_d1=Pulsing40(freqCutoff=12 minBlockSize=28 maxBlockSize=143), rnd_b=PostingsFormat(name=Memory doPackFST= false), intDefault=Block(blocksize=128), n_td1=Block(blocksize=128), id=PostingsFormat(name=Memory doPackFST= false), timestamp=Pulsing40(freqCutoff=12 minBlockSize=28 maxBlockSize=143), range_facet_sl=PostingsFormat(name=Memory doPackFST= false), range_facet_si=Pulsing40(freqCutoff=12 minBlockSize=28 maxBlockSize=143), oddField_s=PostingsFormat(name=Memory doPackFST= false), multiDefault=Pulsing40(freqCutoff=12 minBlockSize=28 maxBlockSize=143), n_tf1=Pulsing40(freqCutoff=12 minBlockSize=28 maxBlockSize=143), n_dt1=Block(blocksize=128), n_ti1=PostingsFormat(name=Memory doPackFST= false), range_facet_l=Pulsing40(freqCutoff=12 minBlockSize=28 maxBlockSize=143), text=Lucene40(minBlockSize=28 maxBlockSize=143), _version_=Block(blocksize=128), SubjectTerms_mfacet=Block(blocksize=128), a_t=Pulsing40(freqCutoff=12 minBlockSize=28 maxBlockSize=143), n_tdt1=Block(blocksize=128), other_tl1=Block(blocksize=128), n_l1=Pulsing40(freqCutoff=12 minBlockSize=28 maxBlockSize=143), a_si=Block(blocksize=128)}, sim=DefaultSimilarity, locale=sr_CS, timezone=Pacific/Pohnpei
[junit4:junit4]   2> NOTE: FreeBSD 9.0-RELEASE amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=2,free=51599456,total=218431488
[junit4:junit4]   2> NOTE: All tests run in this JVM: [TestNumberUtils, TestIBSimilarityFactory, CurrencyFieldTest, TestFiltering, DefaultValueUpdateProcessorTest, TestGroupingSearch, TestLMDirichletSimilarityFactory, NumericFieldsTest, BinaryUpdateRequestHandlerTest, TestLFUCache, SolrRequestParserTest, LoggingHandlerTest, SortByFunctionTest, FieldAnalysisRequestHandlerTest, SystemInfoHandlerTest, NoCacheHeaderTest, ResponseLogComponentTest, TestCollationField, TestDefaultSimilarityFactory, TestQueryTypes, TestFastOutputStream, SearchHandlerTest, SolrPluginUtilsTest, TestExtendedDismaxParser, HighlighterConfigTest, TestFaceting, TestBinaryResponseWriter, DistributedTermsComponentTest, TestSuggestSpellingConverter, FileBasedSpellCheckerTest, MinimalSchemaTest, TestPHPSerializedResponseWriter, SimpleFacetsTest, CoreContainerCoreInitFailuresTest, WordBreakSolrSpellCheckerTest, TestSolr4Spatial, TestRandomFaceting, ZkControllerTest, SimplePostToolTest, PluginInfoTest, SpellCheckCollatorTest, TestIndexSearcher, TestConfig, JsonLoaderTest, TestPseudoReturnFields, DistanceFunctionTest, SampleTest, TestFastLRUCache, TestSearchPerf, BadComponentTest, MBeansHandlerTest, TestPerFieldSimilarity, JSONWriterTest, TestSolrJ, TestSolrQueryParser, FastVectorHighlighterTest, UpdateRequestProcessorFactoryTest, TestReplicationHandler, LeaderElectionTest, DistributedSpellCheckComponentTest, TestHashPartitioner, SolrCoreTest, IndexBasedSpellCheckerTest, TestRangeQuery, DirectUpdateHandlerTest, TestMultiCoreConfBootstrap, TestCoreContainer, ConvertedLegacyTest, PeerSyncTest, QueryElevationComponentTest, SignatureUpdateProcessorFactoryTest, TestJmxIntegration, CoreAdminHandlerTest, DirectSolrConnectionTest, TestRemoteStreaming, CacheHeaderTest, QueryEqualityTest, TestWordDelimiterFilterFactory, PolyFieldTest, TestCSVResponseWriter, MoreLikeThisHandlerTest, DistributedQueryElevationComponentTest, TermsComponentTest, DocumentAnalysisRequestHandlerTest, DirectUpdateHandlerOptimizeTest, TestValueSourceCache, RequestHandlersTest, TestOmitPositions, CopyFieldTest, TestArbitraryIndexDir, SolrCmdDistributorTest, TestLuceneMatchVersion, TestIndexingPerformance, AlternateDirectoryTest, SOLR749Test, TestXIncludeConfig, TestDocSet, TestQuerySenderNoQuery, OutputWriterTest, LegacyHTMLStripCharFilterTest, TestLMJelinekMercerSimilarityFactory, DateMathParserTest, ResourceLoaderTest, TestSystemIdResolver, SpellingQueryConverterTest, DOMUtilTest, PreAnalyzedFieldTest, ZkNodePropsTest, CircularListTest, TestDocumentBuilder, PathHierarchyTokenizerFactoryTest, TestCharFilters, BasicDistributedZk2Test]
[junit4:junit4] Completed on J0 in 307.19s, 1 test, 1 failure <<< FAILURES!

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

Total time: 34 minutes 56 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