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-trunk-Java6 - Build # 15238 - Still Failing
Date Sat, 15 Sep 2012 14:19:42 GMT
Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-Java6/15238/

1 tests failed.
REGRESSION:  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([2699A0D210724562:A77F2ECA672D255E]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.waitToSeeNotLive(AbstractFullDistribZkTestBase.java:1215)
	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:691)
	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 7597 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4:junit4]   2> 307 T3 oasc.CoreContainer.finalize SEVERE CoreContainer was not shutdown prior to finalize(), indicates a bug -- POSSIBLE RESOURCE LEAK!!!  instance=1342595455
[junit4:junit4]   2> 2 T1727 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1347718593368
[junit4:junit4]   2> 3 T1727 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 7 T1728 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4]   2> 7 T1728 oazs.NIOServerCnxn$Factory.<init> binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 8 T1728 oazsp.FileTxnSnapLog.save Snapshotting: 0
[junit4:junit4]   2> 104 T1727 oasc.ZkTestServer.run start zk server on port:36773
[junit4:junit4]   2> 104 T1727 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:36773 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@4d9db274
[junit4:junit4]   2> 105 T1727 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 114 T1733 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:36773
[junit4:junit4]   2> 117 T1733 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:36773, initiating session
[junit4:junit4]   2> 117 T1729 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:36774
[junit4:junit4]   2> 118 T1729 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:36774
[junit4:junit4]   2> 118 T1731 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 131 T1731 oazs.NIOServerCnxn.finishSessionInit Established session 0x139ca49bb5e0000 with negotiated timeout 10000 for client /140.211.11.196:36774
[junit4:junit4]   2> 131 T1733 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:36773, sessionid = 0x139ca49bb5e0000, negotiated timeout = 10000
[junit4:junit4]   2> 131 T1734 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4d9db274 name:ZooKeeperConnection Watcher:127.0.0.1:36773 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 131 T1727 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 132 T1727 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 169 T1732 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x139ca49bb5e0000
[junit4:junit4]   2> 215 T1734 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 215 T1727 oaz.ZooKeeper.close Session: 0x139ca49bb5e0000 closed
[junit4:junit4]   2> 216 T1729 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:36774 which had sessionid 0x139ca49bb5e0000
[junit4:junit4]   2> 217 T1727 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:36773/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@2e217cec
[junit4:junit4]   2> 217 T1735 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:36773
[junit4:junit4]   2> 218 T1727 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 218 T1735 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:36773, initiating session
[junit4:junit4]   2> 219 T1729 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:36775
[junit4:junit4]   2> 219 T1729 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:36775
[junit4:junit4]   2> 221 T1731 oazs.NIOServerCnxn.finishSessionInit Established session 0x139ca49bb5e0001 with negotiated timeout 10000 for client /140.211.11.196:36775
[junit4:junit4]   2> 221 T1735 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:36773, sessionid = 0x139ca49bb5e0001, negotiated timeout = 10000
[junit4:junit4]   2> 222 T1736 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2e217cec name:ZooKeeperConnection Watcher:127.0.0.1:36773/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 222 T1727 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 222 T1727 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 272 T1727 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 316 T1727 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 355 T1727 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 372 T1727 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 372 T1727 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 395 T1727 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4]   2> 396 T1727 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 524 T1727 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 525 T1727 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 533 T1727 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4]   2> 534 T1727 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 543 T1727 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4]   2> 544 T1727 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 547 T1727 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4]   2> 547 T1727 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 550 T1727 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 550 T1727 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 553 T1727 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 553 T1727 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 561 T1727 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 561 T1727 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 564 T1727 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4]   2> 564 T1727 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 567 T1732 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x139ca49bb5e0001
[junit4:junit4]   2> 578 T1736 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 578 T1729 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:36775 which had sessionid 0x139ca49bb5e0001
[junit4:junit4]   2> 578 T1727 oaz.ZooKeeper.close Session: 0x139ca49bb5e0001 closed
[junit4:junit4]   2> 582 T1727 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 599 T1727 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:36777
[junit4:junit4]   2> 600 T1727 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 600 T1727 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 600 T1727 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 626 T1727 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 627 T1727 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 627 T1727 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 627 T1727 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/solr.xml
[junit4:junit4]   2> 628 T1727 oasc.CoreContainer.<init> New CoreContainer 1805515362
[junit4:junit4]   2> 628 T1727 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 628 T1727 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 647 T1727 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 659 T1727 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:36773/solr
[junit4:junit4]   2> 659 T1727 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:36773/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@1686c73b
[junit4:junit4]   2> 663 T1727 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 665 T1746 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:36773
[junit4:junit4]   2> 666 T1746 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:36773, initiating session
[junit4:junit4]   2> 666 T1729 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:36778
[junit4:junit4]   2> 677 T1729 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:36778
[junit4:junit4]   2> 686 T1731 oazs.NIOServerCnxn.finishSessionInit Established session 0x139ca49bb5e0002 with negotiated timeout 5000 for client /140.211.11.196:36778
[junit4:junit4]   2> 686 T1746 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:36773, sessionid = 0x139ca49bb5e0002, negotiated timeout = 5000
[junit4:junit4]   2> 687 T1747 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1686c73b name:ZooKeeperConnection Watcher:127.0.0.1:36773/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 687 T1727 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 698 T1732 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139ca49bb5e0002 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 701 T1727 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 714 T1727 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36777_solr
[junit4:junit4]   2> 715 T1732 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139ca49bb5e0002 type:delete cxid:0x7 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:36777_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:36777_solr
[junit4:junit4]   2> 715 T1727 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:36777_solr
[junit4:junit4]   2> 724 T1727 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 725 T1727 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 726 T1727 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 726 T1727 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 726 T1727 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 727 T1727 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 727 T1727 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 728 T1727 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 728 T1727 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 729 T1727 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 745 T1727 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 760 T1732 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139ca49bb5e0002 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> 772 T1727 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 784 T1727 oasc.Overseer.start Overseer (id=88324085735358466-127.0.0.1:36777_solr-n_0000000000) starting
[junit4:junit4]   2> 785 T1732 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139ca49bb5e0002 type:create cxid:0x1a zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 797 T1732 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139ca49bb5e0002 type:create cxid:0x1b zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 799 T1732 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139ca49bb5e0002 type:create cxid:0x1c zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 800 T1732 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139ca49bb5e0002 type:create cxid:0x1d zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 811 T1749 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 812 T1727 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 815 T1727 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 817 T1748 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 822 T1727 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1
[junit4:junit4]   2> 822 T1727 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 823 T1727 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 824 T1727 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 825 T1727 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4]   2> 826 T1727 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4]   2> 827 T1727 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 882 T1727 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 951 T1727 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 1055 T1727 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 1063 T1727 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 1722 T1727 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 1739 T1727 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 1743 T1727 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 1759 T1727 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1765 T1727 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1770 T1727 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1771 T1727 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1773 T1727 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/control/data/
[junit4:junit4]   2> 1773 T1727 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4b4c28db
[junit4:junit4]   2> 1774 T1727 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/control/data/index/
[junit4:junit4]   2> 1775 T1727 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/control/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 1776 T1727 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/control/data/index forceNew:false
[junit4:junit4]   2> 1827 T1727 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@24b1cddb; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 1828 T1727 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 1829 T1727 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 1831 T1727 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 1831 T1727 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 1832 T1727 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 1832 T1727 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 1833 T1727 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 1833 T1727 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 1834 T1727 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 1834 T1727 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 1835 T1727 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 1836 T1727 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 1836 T1727 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 1837 T1727 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 1837 T1727 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 1838 T1727 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 1838 T1727 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 1839 T1727 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 1839 T1727 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1840 T1727 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1840 T1727 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1841 T1727 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1841 T1727 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1842 T1727 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1842 T1727 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1843 T1727 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 1844 T1727 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 1848 T1727 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 1853 T1727 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 1854 T1727 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> 1858 T1727 oass.SolrIndexSearcher.<init> Opening Searcher@7deb44d9 main
[junit4:junit4]   2> 1860 T1727 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 1860 T1727 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 1861 T1727 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 1869 T1727 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 1924 T1750 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7deb44d9 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 1927 T1732 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139ca49bb5e0002 type:create cxid:0x56 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer/queue Error:KeeperErrorCode = NoNode for /solr/overseer/queue
[junit4:junit4]   2> 1936 T1727 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 1936 T1727 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:36777/solr shardId:control_shard
[junit4:junit4]   2> 1937 T1727 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/control_shard/election
[junit4:junit4]   2> 1956 T1732 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139ca49bb5e0002 type:delete cxid:0x65 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/collections/control_collection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/control_collection/leaders
[junit4:junit4]   2> 1957 T1727 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 1958 T1732 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139ca49bb5e0002 type:create cxid:0x66 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2324 T1748 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2325 T1732 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139ca49bb5e0002 type:create cxid:0x6d zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer/queue-work Error:KeeperErrorCode = NoNode for /solr/overseer/queue-work
[junit4:junit4]   2> 2352 T1747 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 2471 T1727 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 2472 T1727 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 2472 T1727 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:36777/solr/collection1/
[junit4:junit4]   2> 2473 T1727 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 2473 T1727 oasc.SyncStrategy.syncToMe http://127.0.0.1:36777/solr/collection1/ has no replicas
[junit4:junit4]   2> 2473 T1727 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:36777/solr/collection1/
[junit4:junit4]   2> 2474 T1727 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/control_shard
[junit4:junit4]   2> 2478 T1732 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139ca49bb5e0002 type:create cxid:0x8b zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2858 T1748 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2882 T1747 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 2896 T1727 oasc.ZkController.register We are http://127.0.0.1:36777/solr/collection1/ and leader is http://127.0.0.1:36777/solr/collection1/
[junit4:junit4]   2> 2896 T1727 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:36777/solr
[junit4:junit4]   2> 2897 T1727 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 2899 T1727 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2899 T1727 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1
[junit4:junit4]   2> 2900 T1727 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 2900 T1727 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 2915 T1727 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 2917 T1727 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:36792
[junit4:junit4]   2> 2918 T1727 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 2918 T1727 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 2919 T1727 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 2964 T1727 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 2965 T1727 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 2965 T1727 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 2966 T1727 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/solr.xml
[junit4:junit4]   2> 2966 T1727 oasc.CoreContainer.<init> New CoreContainer 241805068
[junit4:junit4]   2> 2967 T1727 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 2967 T1727 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 2993 T1727 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 3008 T1727 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:36773/solr
[junit4:junit4]   2> 3009 T1727 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:36773/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@673c4e73
[junit4:junit4]   2> 3015 T1760 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:36773
[junit4:junit4]   2> 3015 T1727 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 3017 T1760 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:36773, initiating session
[junit4:junit4]   2> 3017 T1729 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:36795
[junit4:junit4]   2> 3018 T1729 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:36795
[junit4:junit4]   2> 3035 T1731 oazs.NIOServerCnxn.finishSessionInit Established session 0x139ca49bb5e0003 with negotiated timeout 5000 for client /140.211.11.196:36795
[junit4:junit4]   2> 3035 T1760 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:36773, sessionid = 0x139ca49bb5e0003, negotiated timeout = 5000
[junit4:junit4]   2> 3035 T1761 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@673c4e73 name:ZooKeeperConnection Watcher:127.0.0.1:36773/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3036 T1727 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 3047 T1732 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139ca49bb5e0003 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3049 T1732 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139ca49bb5e0003 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3071 T1727 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36792_solr
[junit4:junit4]   2> 3071 T1732 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139ca49bb5e0003 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:36792_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:36792_solr
[junit4:junit4]   2> 3075 T1727 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:36792_solr
[junit4:junit4]   2> 3087 T1747 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 3088 T1727 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 3089 T1727 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 3089 T1727 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 3089 T1727 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 3090 T1727 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 3090 T1727 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 3091 T1727 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 3091 T1727 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 3092 T1727 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 3092 T1727 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 3107 T1727 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 3124 T1727 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1
[junit4:junit4]   2> 3124 T1727 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 3125 T1727 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 3125 T1727 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 3127 T1727 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4]   2> 3128 T1727 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4]   2> 3129 T1727 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 3176 T1727 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 3245 T1727 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 3346 T1727 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 3352 T1727 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 3386 T1748 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3396 T1761 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 3396 T1747 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 3964 T1727 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 3976 T1727 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 3980 T1727 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 3995 T1727 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 4001 T1727 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 4005 T1727 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 4007 T1727 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 4008 T1727 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty1/
[junit4:junit4]   2> 4008 T1727 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4b4c28db
[junit4:junit4]   2> 4010 T1727 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty1/index/
[junit4:junit4]   2> 4011 T1727 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 4012 T1727 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty1/index forceNew:false
[junit4:junit4]   2> 4020 T1727 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@1b4b1c2b; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 4020 T1727 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 4021 T1727 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 4024 T1727 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 4024 T1727 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 4025 T1727 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 4025 T1727 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 4026 T1727 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 4026 T1727 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 4027 T1727 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 4028 T1727 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 4028 T1727 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 4029 T1727 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 4030 T1727 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 4030 T1727 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 4031 T1727 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 4031 T1727 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 4032 T1727 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 4033 T1727 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 4033 T1727 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4034 T1727 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4035 T1727 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4035 T1727 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4036 T1727 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4037 T1727 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4037 T1727 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4038 T1727 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 4039 T1727 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 4042 T1727 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 4047 T1727 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 4049 T1727 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> 4053 T1727 oass.SolrIndexSearcher.<init> Opening Searcher@b2ff5c1 main
[junit4:junit4]   2> 4054 T1727 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 4055 T1727 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 4056 T1727 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 4063 T1727 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 4117 T1762 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@b2ff5c1 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 4403 T1748 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4418 T1761 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4418 T1747 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4624 T1727 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 4624 T1727 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:36792/solr shardId:shard1
[junit4:junit4]   2> 4626 T1727 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 4642 T1732 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139ca49bb5e0003 type:delete cxid:0x43 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/collections/collection1/leaders Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders
[junit4:junit4]   2> 4642 T1727 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 4643 T1732 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139ca49bb5e0003 type:create cxid:0x44 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4653 T1727 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 4654 T1727 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 4654 T1727 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:36792/solr/collection1/
[junit4:junit4]   2> 4655 T1727 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 4656 T1727 oasc.SyncStrategy.syncToMe http://127.0.0.1:36792/solr/collection1/ has no replicas
[junit4:junit4]   2> 4656 T1727 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:36792/solr/collection1/
[junit4:junit4]   2> 4657 T1727 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 4662 T1732 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139ca49bb5e0003 type:create cxid:0x4e zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4926 T1748 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4941 T1747 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4941 T1761 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4970 T1727 oasc.ZkController.register We are http://127.0.0.1:36792/solr/collection1/ and leader is http://127.0.0.1:36792/solr/collection1/
[junit4:junit4]   2> 4970 T1727 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:36792/solr
[junit4:junit4]   2> 4970 T1727 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 4972 T1727 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4973 T1727 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1
[junit4:junit4]   2> 4973 T1727 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 4973 T1727 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 4983 T1727 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 4985 T1727 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:36799
[junit4:junit4]   2> 4985 T1727 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 4986 T1727 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 4986 T1727 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 5008 T1727 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 5009 T1727 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 5009 T1727 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 5009 T1727 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/solr.xml
[junit4:junit4]   2> 5009 T1727 oasc.CoreContainer.<init> New CoreContainer 724235823
[junit4:junit4]   2> 5010 T1727 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 5010 T1727 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 5026 T1727 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 5039 T1727 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:36773/solr
[junit4:junit4]   2> 5040 T1727 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:36773/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@203006b9
[junit4:junit4]   2> 5041 T1772 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:36773
[junit4:junit4]   2> 5041 T1727 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 5042 T1729 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:36800
[junit4:junit4]   2> 5042 T1772 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:36773, initiating session
[junit4:junit4]   2> 5043 T1729 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:36800
[junit4:junit4]   2> 5046 T1731 oazs.NIOServerCnxn.finishSessionInit Established session 0x139ca49bb5e0004 with negotiated timeout 5000 for client /140.211.11.196:36800
[junit4:junit4]   2> 5046 T1772 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:36773, sessionid = 0x139ca49bb5e0004, negotiated timeout = 5000
[junit4:junit4]   2> 5046 T1773 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@203006b9 name:ZooKeeperConnection Watcher:127.0.0.1:36773/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 5047 T1727 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 5048 T1732 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139ca49bb5e0004 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 5101 T1732 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139ca49bb5e0004 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 5111 T1727 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36799_solr
[junit4:junit4]   2> 5111 T1732 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139ca49bb5e0004 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:36799_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:36799_solr
[junit4:junit4]   2> 5112 T1727 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:36799_solr
[junit4:junit4]   2> 5120 T1747 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 5120 T1761 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 5121 T1727 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 5121 T1727 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 5122 T1727 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 5122 T1727 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 5123 T1727 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 5123 T1727 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 5123 T1727 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 5124 T1727 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 5124 T1727 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 5125 T1727 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 5175 T1727 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 5182 T1727 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1
[junit4:junit4]   2> 5182 T1727 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 5183 T1727 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 5183 T1727 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 5185 T1727 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4]   2> 5186 T1727 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4]   2> 5187 T1727 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 5232 T1727 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 5300 T1727 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 5401 T1727 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 5407 T1727 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 5452 T1748 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 5458 T1773 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5458 T1761 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5458 T1747 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5946 T1727 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 5955 T1727 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 5959 T1727 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 5970 T1727 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 5975 T1727 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 5980 T1727 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 5981 T1727 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 5982 T1727 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty2/
[junit4:junit4]   2> 5983 T1727 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4b4c28db
[junit4:junit4]   2> 5984 T1727 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty2/index/
[junit4:junit4]   2> 5985 T1727 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 5986 T1727 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty2/index forceNew:false
[junit4:junit4]   2> 5993 T1727 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@45cf7f34; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 5994 T1727 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 5995 T1727 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 5997 T1727 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 5997 T1727 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 5998 T1727 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 5998 T1727 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 5999 T1727 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 6000 T1727 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 6000 T1727 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 6001 T1727 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 6002 T1727 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 6002 T1727 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 6003 T1727 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 6004 T1727 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 6004 T1727 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 6005 T1727 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 6005 T1727 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 6006 T1727 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 6007 T1727 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6007 T1727 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6008 T1727 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6009 T1727 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6009 T1727 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6010 T1727 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6010 T1727 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6011 T1727 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 6012 T1727 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 6016 T1727 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 6021 T1727 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 6022 T1727 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> 6026 T1727 oass.SolrIndexSearcher.<init> Opening Searcher@60f30300 main
[junit4:junit4]   2> 6028 T1727 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 6028 T1727 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 6029 T1727 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 6036 T1727 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 6098 T1774 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@60f30300 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 6464 T1748 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6481 T1761 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6481 T1773 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6481 T1747 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6605 T1727 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 6605 T1727 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:36799/solr shardId:shard2
[junit4:junit4]   2> 6606 T1727 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4]   2> 6621 T1732 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139ca49bb5e0004 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> 6628 T1727 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 6629 T1732 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139ca49bb5e0004 type:create cxid:0x43 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 6640 T1727 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 6640 T1727 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 6641 T1727 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:36799/solr/collection1/
[junit4:junit4]   2> 6641 T1727 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 6641 T1727 oasc.SyncStrategy.syncToMe http://127.0.0.1:36799/solr/collection1/ has no replicas
[junit4:junit4]   2> 6642 T1727 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:36799/solr/collection1/
[junit4:junit4]   2> 6642 T1727 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4]   2> 6645 T1732 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139ca49bb5e0004 type:create cxid:0x4c zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 6985 T1748 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7011 T1773 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7011 T1761 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7011 T1747 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7013 T1727 oasc.ZkController.register We are http://127.0.0.1:36799/solr/collection1/ and leader is http://127.0.0.1:36799/solr/collection1/
[junit4:junit4]   2> 7013 T1727 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:36799/solr
[junit4:junit4]   2> 7014 T1727 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 7024 T1727 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7025 T1727 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1
[junit4:junit4]   2> 7025 T1727 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 7026 T1727 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 7040 T1727 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 7043 T1727 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:36802
[junit4:junit4]   2> 7043 T1727 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 7044 T1727 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 7044 T1727 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 7078 T1727 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 7078 T1727 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 7079 T1727 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 7079 T1727 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/solr.xml
[junit4:junit4]   2> 7080 T1727 oasc.CoreContainer.<init> New CoreContainer 1982724397
[junit4:junit4]   2> 7080 T1727 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 7081 T1727 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 7104 T1727 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 7119 T1727 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:36773/solr
[junit4:junit4]   2> 7119 T1727 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:36773/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@56e54fca
[junit4:junit4]   2> 7120 T1784 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:36773
[junit4:junit4]   2> 7120 T1727 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 7121 T1784 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:36773, initiating session
[junit4:junit4]   2> 7122 T1729 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:36803
[junit4:junit4]   2> 7122 T1729 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:36803
[junit4:junit4]   2> 7124 T1731 oazs.NIOServerCnxn.finishSessionInit Established session 0x139ca49bb5e0005 with negotiated timeout 5000 for client /140.211.11.196:36803
[junit4:junit4]   2> 7124 T1784 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:36773, sessionid = 0x139ca49bb5e0005, negotiated timeout = 5000
[junit4:junit4]   2> 7124 T1785 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@56e54fca name:ZooKeeperConnection Watcher:127.0.0.1:36773/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 7124 T1727 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 7125 T1732 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139ca49bb5e0005 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7136 T1732 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139ca49bb5e0005 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7138 T1727 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36802_solr
[junit4:junit4]   2> 7138 T1732 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139ca49bb5e0005 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:36802_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:36802_solr
[junit4:junit4]   2> 7147 T1727 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:36802_solr
[junit4:junit4]   2> 7155 T1773 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 7155 T1747 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 7155 T1761 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 7155 T1727 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 7156 T1727 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 7156 T1727 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 7156 T1727 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 7157 T1727 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 7157 T1727 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 7157 T1727 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 7158 T1727 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 7158 T1727 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 7158 T1727 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 7167 T1727 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 7171 T1727 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1
[junit4:junit4]   2> 7172 T1727 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 7173 T1727 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 7173 T1727 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 7174 T1727 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4]   2> 7175 T1727 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4]   2> 7175 T1727 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 7209 T1727 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 7255 T1727 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 7356 T1727 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 7361 T1727 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 7526 T1748 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7593 T1785 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7593 T1773 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7593 T1761 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7593 T1747 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7809 T1727 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 7818 T1727 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 7821 T1727 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 7833 T1727 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 7837 T1727 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 7841 T1727 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 7842 T1727 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 7843 T1727 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty3/
[junit4:junit4]   2> 7844 T1727 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4b4c28db
[junit4:junit4]   2> 7845 T1727 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty3/index/
[junit4:junit4]   2> 7845 T1727 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 7846 T1727 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty3/index forceNew:false
[junit4:junit4]   2> 7851 T1727 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty3/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@7f8d771e; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 7852 T1727 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 7852 T1727 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 7854 T1727 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 7854 T1727 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 7855 T1727 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 7855 T1727 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 7856 T1727 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 7856 T1727 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 7856 T1727 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 7857 T1727 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 7857 T1727 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 7858 T1727 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 7858 T1727 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 7859 T1727 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 7859 T1727 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 7859 T1727 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 7860 T1727 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 7860 T1727 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 7861 T1727 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7861 T1727 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7862 T1727 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7862 T1727 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7862 T1727 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7863 T1727 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7863 T1727 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7864 T1727 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 7864 T1727 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 7867 T1727 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 7870 T1727 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 7871 T1727 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> 7874 T1727 oass.SolrIndexSearcher.<init> Opening Searcher@60ee9763 main
[junit4:junit4]   2> 7875 T1727 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 7876 T1727 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 7876 T1727 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 7882 T1727 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 7940 T1786 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@60ee9763 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 8104 T1748 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8119 T1785 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8119 T1747 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8119 T1761 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8119 T1773 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8447 T1727 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 8447 T1727 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:36802/solr shardId:shard1
[junit4:junit4]   2> 8451 T1727 oasc.ZkController.register We are http://127.0.0.1:36802/solr/collection1/ and leader is http://127.0.0.1:36792/solr/collection1/
[junit4:junit4]   2> 8451 T1727 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:36802/solr
[junit4:junit4]   2> 8451 T1727 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 8452 T1727 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C121 name=collection1 org.apache.solr.core.SolrCore@6e74e3e8 url=http://127.0.0.1:36802/solr/collection1 node=127.0.0.1:36802_solr
[junit4:junit4]   2> 8453 T1787 C121 P36802 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 8453 T1787 C121 P36802 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 8453 T1727 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8454 T1787 C121 P36802 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:36792/solr/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 8454 T1787 C121 P36802 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:36802/solr START replicas=[http://127.0.0.1:36792/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 8454 T1727 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1
[junit4:junit4]   2> 8455 T1787 C121 P36802 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 8455 T1727 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 8455 T1787 C121 P36802 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 8455 T1787 C121 P36802 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 8455 T1727 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 8455 T1787 C121 P36802 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@4f49ba55 url=http://127.0.0.1:36792/solr/collection1 node=127.0.0.1:36792_solr
[junit4:junit4]   2> 8466 T1753 C122 P36792 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=1 
[junit4:junit4]   2> 8467 T1727 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 8469 T1727 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:36807
[junit4:junit4]   2> 8470 T1727 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 8470 T1727 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 8470 T1727 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 8494 T1727 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 8494 T1727 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 8495 T1727 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 8495 T1727 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/solr.xml
[junit4:junit4]   2> 8495 T1727 oasc.CoreContainer.<init> New CoreContainer 667399224
[junit4:junit4]   2> 8496 T1727 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 8496 T1727 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 8515 T1727 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 8526 T1727 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:36773/solr
[junit4:junit4]   2> 8527 T1727 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:36773/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@5de0e371
[junit4:junit4]   2> 8528 T1798 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:36773
[junit4:junit4]   2> 8528 T1727 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 8529 T1798 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:36773, initiating session
[junit4:junit4]   2> 8529 T1729 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:36809
[junit4:junit4]   2> 8529 T1729 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:36809
[junit4:junit4]   2> 8531 T1731 oazs.NIOServerCnxn.finishSessionInit Established session 0x139ca49bb5e0006 with negotiated timeout 5000 for client /140.211.11.196:36809
[junit4:junit4]   2> 8531 T1798 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:36773, sessionid = 0x139ca49bb5e0006, negotiated timeout = 5000
[junit4:junit4]   2> 8531 T1799 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5de0e371 name:ZooKeeperConnection Watcher:127.0.0.1:36773/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 8531 T1727 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 8532 T1732 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139ca49bb5e0006 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8538 T1732 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139ca49bb5e0006 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8539 T1727 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36807_solr
[junit4:junit4]   2> 8539 T1732 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139ca49bb5e0006 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:36807_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:36807_solr
[junit4:junit4]   2> 8540 T1727 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:36807_solr
[junit4:junit4]   2> 8549 T1761 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 8549 T1785 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 8549 T1773 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 8549 T1747 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 8550 T1727 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 8551 T1727 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 8551 T1727 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 8552 T1727 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 8552 T1727 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 8553 T1727 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 8553 T1727 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 8554 T1727 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 8554 T1727 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 8554 T1727 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 8566 T1727 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 8573 T1727 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1
[junit4:junit4]   2> 8573 T1727 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 8574 T1727 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 8574 T1727 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 8576 T1727 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4]   2> 8577 T1727 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4]   2> 8578 T1727 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 8623 T1748 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8628 T1727 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 8628 T1747 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8628 T1799 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8628 T1785 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8628 T1773 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8628 T1761 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8699 T1727 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 8800 T1727 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 8806 T1727 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 9373 T1727 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 9381 T1727 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 9384 T1727 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 9394 T1727 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 9399 T1727 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 9404 T1727 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 9406 T1727 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 9407 T1727 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty4/
[junit4:junit4]   2> 9408 T1727 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4b4c28db
[junit4:junit4]   2> 9409 T1727 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty4/index/
[junit4:junit4]   2> 9410 T1727 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 9411 T1727 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty4/index forceNew:false
[junit4:junit4]   2> 9428 T1727 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@7a30e1fb; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 9428 T1727 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 9429 T1727 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 9431 T1727 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 9432 T1727 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 9432 T1727 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 9433 T1727 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 9434 T1727 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 9434 T1727 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 9434 T1727 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 9435 T1727 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 9436 T1727 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 9436 T1727 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 9437 T1727 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 9438 T1727 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 9438 T1727 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 9439 T1727 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 9439 T1727 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 9440 T1727 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 9440 T1727 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 9441 T1727 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 9442 T1727 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 9442 T1727 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 9443 T1727 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 9443 T1727 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 9444 T1727 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 9445 T1727 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 9445 T1727 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 9449 T1727 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 9454 T1727 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 9455 T1727 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> 9459 T1727 oass.SolrIndexSearcher.<init> Opening Searcher@3be092df main
[junit4:junit4]   2> 9460 T1727 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 9460 T1727 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 9461 T1727 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 9468 T1727 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 9522 T1800 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3be092df main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 9648 T1748 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9662 T1785 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9662 T1799 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9662 T1773 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9662 T1761 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9662 T1747 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10028 T1727 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 10028 T1727 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:36807/solr shardId:shard2
[junit4:junit4]   2> 10036 T1727 oasc.ZkController.register We are http://127.0.0.1:36807/solr/collection1/ and leader is http://127.0.0.1:36799/solr/collection1/
[junit4:junit4]   2> 10037 T1727 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:36807/solr
[junit4:junit4]   2> 10037 T1727 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 10038 T1727 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C123 name=collection1 org.apache.solr.core.SolrCore@5b2b9428 url=http://127.0.0.1:36807/solr/collection1 node=127.0.0.1:36807_solr
[junit4:junit4]   2> 10538 T1801 C123 P36807 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 10539 T1801 C123 P36807 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 10539 T1727 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 10548 T1801 C123 P36807 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:36799/solr/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 10548 T1801 C123 P36807 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:36807/solr START replicas=[http://127.0.0.1:36799/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 10548 T1727 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1
[junit4:junit4]   2> 10549 T1801 C123 P36807 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 10549 T1727 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 10549 T1801 C123 P36807 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 10549 T1801 C123 P36807 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 10549 T1727 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 10549 T1801 C123 P36807 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C124 name=collection1 org.apache.solr.core.SolrCore@4699457 url=http://127.0.0.1:36799/solr/collection1 node=127.0.0.1:36799_solr
[junit4:junit4]   2> 10559 T1765 C124 P36799 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=0 
[junit4:junit4]   2> 10569 T1727 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:36773/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@5e79d80e
[junit4:junit4]   2> 10570 T1803 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:36773
[junit4:junit4]   2> 10570 T1727 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 10571 T1803 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:36773, initiating session
[junit4:junit4]   2> 10571 T1729 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:36814
[junit4:junit4]   2> 10571 T1729 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:36814
[junit4:junit4]   2> 10573 T1731 oazs.NIOServerCnxn.finishSessionInit Established session 0x139ca49bb5e0007 with negotiated timeout 10000 for client /140.211.11.196:36814
[junit4:junit4]   2> 10573 T1803 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:36773, sessionid = 0x139ca49bb5e0007, negotiated timeout = 10000
[junit4:junit4]   2> 10573 T1804 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5e79d80e name:ZooKeeperConnection Watcher:127.0.0.1:36773/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 10573 T1727 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 10574 T1727 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 10576 T1727 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   2> 10576 T1727 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 10587 T1727 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> ASYNC  NEW_CORE C125 name=collection1 org.apache.solr.core.SolrCore@70c1e33 url=http://127.0.0.1:36777/solr/collection1 node=127.0.0.1:36777_solr
[junit4:junit4]   2> 10603 T1739 C125 P36777 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@24b1cddb; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 10605 T1739 C125 P36777 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 10611 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[1 (1413185382869106688)]} 0 14
[junit4:junit4]   2> 10612 T1727 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:36773/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@1be83698
[junit4:junit4]   2> 10613 T1805 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:36773
[junit4:junit4]   2> 10613 T1727 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 10614 T1805 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:36773, initiating session
[junit4:junit4]   2> 10614 T1729 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:36817
[junit4:junit4]   2> 10615 T1729 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:36817
[junit4:junit4]   2> 10627 T1731 oazs.NIOServerCnxn.finishSessionInit Established session 0x139ca49bb5e0008 with negotiated timeout 10000 for client /140.211.11.196:36817
[junit4:junit4]   2> 10627 T1805 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:36773, sessionid = 0x139ca49bb5e0008, negotiated timeout = 10000
[junit4:junit4]   2> 10627 T1806 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1be83698 name:ZooKeeperConnection Watcher:127.0.0.1:36773/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 10627 T1727 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 10628 T1727 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 10636 T1755 C122 P36792 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@1b4b1c2b; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 10637 T1755 C122 P36792 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2>  C121_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:36802_solr, base_url=http://127.0.0.1:36802/solr}
[junit4:junit4]   2> 10654 T1777 C121 P36802 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty3/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@7f8d771e; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 10655 T1777 C121 P36802 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 10659 T1777 C121 P36802 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=9 
[junit4:junit4]   2> 10660 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[1 (1413185382904758272)]} 0 28
[junit4:junit4]   2> 10661 T1727 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):1440
[junit4:junit4]   2> 10662 T1727 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 11050 T1748 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 11067 T1785 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11067 T1773 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11067 T1761 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11067 T1799 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11067 T1804 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11067 T1747 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11067 T1806 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11469 T1787 C121 P36802 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 11469 T1787 C121 P36802 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=tlog{file=./org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty3/tlog/tlog.0000000000000000000 refcount=1}}
[junit4:junit4]   2> 11469 T1787 C121 P36802 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:36792/solr/collection1/. core=collection1
[junit4:junit4]   2> 11469 T1787 C121 P36802 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 11479 T1756 C122 P36792 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 11551 T1756 C122 P36792 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@1b4b1c2b; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@1b4b1c2b; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0_Block_0.pos, _0_Block_0.tip, _0.fnm, _0_Block_0.doc, _0_Memory_0.ram, _0_Block_0.tim, _0_nrm.cfs, _0_Memory_1.ram, _0_Lucene40WithOrds_0.tii, _0_Lucene40WithOrds_0.frq, _0_nrm.cfe, segments_2, _0.fdx, _0_Lucene40WithOrds_0.prx, _0.si, _0_Lucene40WithOrds_0.tib, _0.fdt]
[junit4:junit4]   2> 11551 T1756 C122 P36792 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 11559 T1756 C122 P36792 oass.SolrIndexSearcher.<init> Opening Searcher@4855ba0c main
[junit4:junit4]   2> 11560 T1756 C122 P36792 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 11561 T1762 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4855ba0c main{StandardDirectoryReader(segments_2:3 _0(5.0):C1)}
[junit4:junit4]   2> 11561 T1756 C122 P36792 /update {waitSearcher=true&commit=true&commit_end_point=true&wt=javabin&softCommit=false&version=2} {commit=} 0 82
[junit4:junit4]   2> 11562 T1787 C121 P36802 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 11562 T1787 C121 P36802 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 11564 T1757 C122 P36792 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 11564 T1757 C122 P36792 REQ /replication {command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
[junit4:junit4]   2> 11564 T1787 C121 P36802 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4]   2> 11564 T1787 C121 P36802 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 11564 T1787 C121 P36802 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 11568 T1757 C122 P36792 REQ /replication {command=filelist&generation=2&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
[junit4:junit4]   2> 11569 T1787 C121 P36802 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 17
[junit4:junit4]   2> 11572 T1787 C121 P36802 oash.SnapPuller.fetchLatestIndex Starting download to ./org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty3/index.20120915091644934 fullCopy=true
[junit4:junit4]   2> 11575 T1757 C122 P36792 REQ /replication {file=_0_Block_0.tip&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11579 T1757 C122 P36792 REQ /replication {file=_0_Block_0.pos&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11583 T1757 C122 P36792 REQ /replication {file=_0_Block_0.doc&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11586 T1757 C122 P36792 REQ /replication {file=_0.fnm&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11589 T1757 C122 P36792 REQ /replication {file=_0_Block_0.tim&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11592 T1757 C122 P36792 REQ /replication {file=_0_Memory_0.ram&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11596 T1757 C122 P36792 REQ /replication {file=_0_nrm.cfs&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11599 T1757 C122 P36792 REQ /replication {file=_0_Memory_1.ram&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11603 T1757 C122 P36792 REQ /replication {file=_0_Lucene40WithOrds_0.tii&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11606 T1757 C122 P36792 REQ /replication {file=_0_Lucene40WithOrds_0.frq&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11614 T1757 C122 P36792 REQ /replication {file=_0_nrm.cfe&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=1 
[junit4:junit4]   2> 11618 T1757 C122 P36792 REQ /replication {file=segments_2&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11622 T1757 C122 P36792 REQ /replication {file=_0.fdx&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11626 T1757 C122 P36792 REQ /replication {file=_0_Lucene40WithOrds_0.prx&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11630 T1757 C122 P36792 REQ /replication {file=_0.si&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11634 T1757 C122 P36792 REQ /replication {file=_0_Lucene40WithOrds_0.tib&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11638 T1757 C122 P36792 REQ /replication {file=_0.fdt&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11639 T1787 C121 P36802 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 11644 T1787 C121 P36802 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20120915091644934
[junit4:junit4]   2> 11645 T1787 C121 P36802 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 11645 T1787 C121 P36802 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 11645 T1787 C121 P36802 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4]   2> 11648 T1787 C121 P36802 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=./org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty3/index/ new=./org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty3/index.20120915091644934
[junit4:junit4]   2> 11649 T1787 C121 P36802 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty3/index.20120915091644934 forceNew:true
[junit4:junit4]   2> 11655 T1787 C121 P36802 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty3/index.20120915091644934 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7773ff0e; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0_Block_0.pos, _0_Block_0.tip, _0.fnm, _0_Block_0.doc, _0_Memory_0.ram, _0_Block_0.tim, _0_nrm.cfs, _0_Memory_1.ram, _0_Lucene40WithOrds_0.tii, _0_Lucene40WithOrds_0.frq, _0_nrm.cfe, segments_2, _0.fdx, _0_Lucene40WithOrds_0.prx, _0.si, _0_Lucene40WithOrds_0.tib, _0.fdt]
[junit4:junit4]   2> 11655 T1787 C121 P36802 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 11655 T1787 C121 P36802 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 11658 T1787 C121 P36802 oass.SolrIndexSearcher.<init> Opening Searcher@763d979a main
[junit4:junit4]   2> 11660 T1786 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@763d979a main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C1)}
[junit4:junit4]   2> 11661 T1786 oasc.CachingDirectoryFactory.close Closing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty3/index
[junit4:junit4]   2> 11661 T1786 oash.SnapPuller$2.onClose removing old index directory ./org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty3/index
[junit4:junit4]   2> 11663 T1787 C121 P36802 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 11664 T1787 C121 P36802 oass.SolrIndexSearcher.<init> Opening Searcher@2e9e3459 main
[junit4:junit4]   2> 11664 T1727 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 11664 T1787 C121 P36802 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 11665 T1786 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2e9e3459 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C1)}
[junit4:junit4]   2> 11671 T1787 C121 P36802 oasc.RecoveryStrategy.replay Replaying buffered documents. core=collection1
[junit4:junit4]   2> 11671 T1809 C121 P36802 oasu.UpdateLog$LogReplayer.doReplay WARNING Starting log replay tlog{file=./org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty3/tlog/tlog.0000000000000000000 refcount=2} active=true starting pos=429
[junit4:junit4]   2> 11674 T1809 C121 P36802 oasu.DirectUpdateHandler2.commit start commit{flags=2,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 11674 T1809 C121 P36802 oass.SolrIndexSearcher.<init> Opening Searcher@7529e704 main
[junit4:junit4]   2> 11675 T1809 C121 P36802 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 11676 T1786 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7529e704 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C1)}
[junit4:junit4]   2> 11676 T1809 C121 P36802 oasu.UpdateLog$LogReplayer.run WARNING Log replay finished. recoveryInfo=RecoveryInfo{adds=0 deletes=0 deleteByQuery=0 errors=0 positionOfStart=429}
[junit4:junit4]   2> 11677 T1787 C121 P36802 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 11678 T1787 C121 P36802 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 12074 T1748 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12088 T1785 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12088 T1806 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12088 T1804 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12088 T1747 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12088 T1761 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12088 T1799 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12088 T1773 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12666 T1727 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2>  C123_STATE=coll:collection1 core:collection1 props:{shard=shard2, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:36807_solr, base_url=http://127.0.0.1:36807/solr}
[junit4:junit4]   2> 13572 T1801 C123 P36807 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 13572 T1801 C123 P36807 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 13572 T1801 C123 P36807 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:36799/solr/collection1/. core=collection1
[junit4:junit4]   2> 13572 T1801 C123 P36807 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 13587 T1767 C124 P36799 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 13592 T1767 C124 P36799 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@45cf7f34; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 13592 T1767 C124 P36799 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 13593 T1767 C124 P36799 oass.SolrIndexSearcher.<init> Opening Searcher@3a163097 main
[junit4:junit4]   2> 13593 T1767 C124 P36799 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 13594 T1774 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3a163097 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 13595 T1767 C124 P36799 /update {waitSearcher=true&commit=true&commit_end_point=true&wt=javabin&softCommit=false&version=2} {commit=} 0 8
[junit4:junit4]   2> 13595 T1801 C123 P36807 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 13596 T1801 C123 P36807 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 13597 T1768 C124 P36799 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 13597 T1768 C124 P36799 REQ /replication {command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
[junit4:junit4]   2> 13601 T1801 C123 P36807 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@7a30e1fb; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 13601 T1801 C123 P36807 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 13602 T1801 C123 P36807 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 13609 T1801 C123 P36807 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@7a30e1fb; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@7a30e1fb; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 13610 T1801 C123 P36807 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 13612 T1801 C123 P36807 oass.SolrIndexSearcher.<init> Opening Searcher@7af882eb main
[junit4:junit4]   2> 13612 T1801 C123 P36807 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 13613 T1800 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7af882eb main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 13614 T1801 C123 P36807 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 13614 T1801 C123 P36807 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 13615 T1801 C123 P36807 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 13668 T1727 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 14099 T1748 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 14112 T1773 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14112 T1799 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14112 T1747 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14112 T1806 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14112 T1804 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14112 T1761 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14112 T1785 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14670 T1727 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 14673 T1739 C125 P36777 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 14773 T1739 C125 P36777 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@24b1cddb; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@24b1cddb; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0_Block_0.pos, _0_Block_0.tip, _0.fnm, _0_Block_0.doc, _0_Memory_0.ram, _0_Block_0.tim, _0_nrm.cfs, _0_Memory_1.ram, _0_Lucene40WithOrds_0.tii, _0_Lucene40WithOrds_0.frq, _0_nrm.cfe, segments_2, _0.fdx, _0_Lucene40WithOrds_0.prx, _0.si, _0_Lucene40WithOrds_0.tib, _0.fdt]
[junit4:junit4]   2> 14774 T1739 C125 P36777 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 14783 T1739 C125 P36777 oass.SolrIndexSearcher.<init> Opening Searcher@61d9d3e7 main
[junit4:junit4]   2> 14784 T1739 C125 P36777 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 14784 T1750 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@61d9d3e7 main{StandardDirectoryReader(segments_2:3 _0(5.0):C1)}
[junit4:junit4]   2> 14785 T1739 C125 P36777 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 112
[junit4:junit4]   2> 14787 T1755 C122 P36792 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 14795 T1755 C122 P36792 oass.SolrIndexSearcher.<init> Opening Searcher@670768d main
[junit4:junit4]   2> 14795 T1755 C122 P36792 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 14796 T1762 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@670768d main{StandardDirectoryReader(segments_2:3 _0(5.0):C1)}
[junit4:junit4]   2> 14797 T1755 C122 P36792 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:36802/solr/collection1/, StdNode: http://127.0.0.1:36799/solr/collection1/, StdNode: http://127.0.0.1:36807/solr/collection1/]
[junit4:junit4]   2> 14799 T1769 C124 P36799 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2>  C121_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:36802_solr, base_url=http://127.0.0.1:36802/solr}
[junit4:junit4]   2> 14799 T1777 C121 P36802 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 14801 T1777 C121 P36802 oass.SolrIndexSearcher.<init> Opening Searcher@7a8488f3 main
[junit4:junit4]   2> 14801 T1777 C121 P36802 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 14802 T1786 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7a8488f3 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C1)}
[junit4:junit4]   2> 14803 T1777 C121 P36802 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&expungeDeletes=false&softCommit=false&version=2} {commit=} 0 4
[junit4:junit4]   2> 14803 T1769 C124 P36799 oass.SolrIndexSearcher.<init> Opening Searcher@190b99e1 main
[junit4:junit4]   2> 14804 T1769 C124 P36799 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 14804 T1774 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@190b99e1 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 14805 T1769 C124 P36799 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&expungeDeletes=false&softCommit=false&version=2} {commit=} 0 7
[junit4:junit4]   2>  C123_STATE=coll:collection1 core:collection1 props:{shard=shard2, roles=null, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:36807_solr, base_url=http://127.0.0.1:36807/solr}
[junit4:junit4]   2> 14808 T1791 C123 P36807 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 14812 T1791 C123 P36807 oass.SolrIndexSearcher.<init> Opening Searcher@2edbb2cb main
[junit4:junit4]   2> 14812 T1791 C123 P36807 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 14813 T1800 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2edbb2cb main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 14813 T1791 C123 P36807 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&expungeDeletes=false&softCommit=false&version=2} {commit=} 0 5
[junit4:junit4]   2> 14814 T1755 C122 P36792 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 27
[junit4:junit4]   2> 14820 T1740 C125 P36777 REQ /select {fl=id,score&shard.url=127.0.0.1:36777/solr/collection1/&NOW=1347718608182&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 14823 T1740 C125 P36777 REQ /select {shard.url=127.0.0.1:36777/solr/collection1/&NOW=1347718608182&q=*:*&ids=1&distrib=false&isShard=true&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 14824 T1739 C125 P36777 REQ /select {wt=javabin&q=*:*&version=2} hits=1 status=0 QTime=7 
[junit4:junit4]   2> 14825 T1727 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:36773/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@19b83e58
[junit4:junit4]   2> 14825 T1813 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:36773
[junit4:junit4]   2> 14825 T1727 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 14826 T1813 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:36773, initiating session
[junit4:junit4]   2> 14827 T1729 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:36831
[junit4:junit4]   2> 14827 T1729 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:36831
[junit4:junit4]   2> 14828 T1731 oazs.NIOServerCnxn.finishSessionInit Established session 0x139ca49bb5e0009 with negotiated timeout 10000 for client /140.211.11.196:36831
[junit4:junit4]   2> 14828 T1813 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:36773, sessionid = 0x139ca49bb5e0009, negotiated timeout = 10000
[junit4:junit4]   2> 14828 T1814 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19b83e58 name:ZooKeeperConnection Watcher:127.0.0.1:36773/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 14828 T1727 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 14829 T1727 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 14830 T1732 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x139ca49bb5e0009
[junit4:junit4]   2> 14831 T1814 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 14831 T1727 oaz.ZooKeeper.close Session: 0x139ca49bb5e0009 closed
[junit4:junit4]   2> 14831 T1729 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:36831 which had sessionid 0x139ca49bb5e0009
[junit4:junit4]   2> 14833 T1758 C122 P36792 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 14835 T1770 C124 P36799 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 14838 T1766 C124 P36799 REQ /select {fl=id,score&shard.url=127.0.0.1:36799/solr/collection1/|127.0.0.1:36807/solr/collection1/&NOW=1347718608201&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 14838 T1759 C122 P36792 REQ /select {fl=id,score&shard.url=127.0.0.1:36792/solr/collection1/|127.0.0.1:36802/solr/collection1/&NOW=1347718608201&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 14840 T1759 C122 P36792 REQ /select {shard.url=127.0.0.1:36792/solr/collection1/|127.0.0.1:36802/solr/collection1/&NOW=1347718608201&q=*:*&ids=1&distrib=false&isShard=true&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 14841 T1771 C124 P36799 REQ /select {wt=javabin&q=*:*&version=2} hits=1 status=0 QTime=5 
[junit4:junit4]   2> 14846 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[2 (1413185387320311808)]} 0 3
[junit4:junit4]   2> 14860 T1791 C123 P36807 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:36799/solr/collection1/&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 14861 T1769 C124 P36799 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=10 
[junit4:junit4]   2> 14861 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[2]} 0 12
[junit4:junit4]   2> 14866 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[3 (1413185387342331904)]} 0 2
[junit4:junit4]   2> 14873 T1791 C123 P36807 REQ /update {distrib.from=http://127.0.0.1:36799/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14874 T1771 C124 P36799 /update {wt=javabin&version=2} {add=[3 (1413185387346526208)]} 0 6
[junit4:junit4]   2> 14879 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[4 (1413185387355963392)]} 0 2
[junit4:junit4]   2> 14890 T1777 C121 P36802 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 14891 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[4 (1413185387361206272)]} 0 9
[junit4:junit4]   2> 14895 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[5 (1413185387373789184)]} 0 1
[junit4:junit4]   2> 14904 T1791 C123 P36807 REQ /update {distrib.from=http://127.0.0.1:36799/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 14904 T1771 C124 P36799 /update {wt=javabin&version=2} {add=[5 (1413185387377983488)]} 0 6
[junit4:junit4]   2> 14908 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[6 (1413185387387420672)]} 0 1
[junit4:junit4]   2> 14917 T1791 C123 P36807 REQ /update {distrib.from=http://127.0.0.1:36799/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 14918 T1771 C124 P36799 /update {wt=javabin&version=2} {add=[6 (1413185387391614976)]} 0 7
[junit4:junit4]   2> 14921 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[7 (1413185387401052160)]} 0 1
[junit4:junit4]   2> 14930 T1791 C123 P36807 REQ /update {distrib.from=http://127.0.0.1:36799/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 14931 T1771 C124 P36799 /update {wt=javabin&version=2} {add=[7 (1413185387405246464)]} 0 7
[junit4:junit4]   2> 14934 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[8 (1413185387414683648)]} 0 1
[junit4:junit4]   2> 14942 T1777 C121 P36802 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 14942 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[8 (1413185387418877952)]} 0 5
[junit4:junit4]   2> 14946 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[9 (1413185387427266560)]} 0 1
[junit4:junit4]   2> 14956 T1791 C123 P36807 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:36799/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 14957 T1769 C124 P36799 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 14958 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[9]} 0 9
[junit4:junit4]   2> 14961 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[10 (1413185387442995200)]} 0 1
[junit4:junit4]   2> 14968 T1777 C121 P36802 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14969 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[10 (1413185387447189504)]} 0 5
[junit4:junit4]   2> 14981 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[11 (1413185387455578112)]} 0 9
[junit4:junit4]   2> 14990 T1777 C121 P36802 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:36792/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14990 T1754 C122 P36792 REQ /update {distrib.from=http://127.0.0.1:36799/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 14991 T1771 C124 P36799 /update {wt=javabin&version=2} {add=[11]} 0 7
[junit4:junit4]   2> 14996 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[12 (1413185387478646784)]} 0 2
[junit4:junit4]   2> 15005 T1777 C121 P36802 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:36792/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15006 T1754 C122 P36792 REQ /update {distrib.from=http://127.0.0.1:36799/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 15006 T1771 C124 P36799 /update {wt=javabin&version=2} {add=[12]} 0 7
[junit4:junit4]   2> 15010 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[13 (1413185387494375424)]} 0 1
[junit4:junit4]   2> 15020 T1777 C121 P36802 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:36792/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15021 T1754 C122 P36792 REQ /update {distrib.from=http://127.0.0.1:36799/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 15021 T1771 C124 P36799 /update {wt=javabin&version=2} {add=[13]} 0 8
[junit4:junit4]   2> 15025 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[14 (1413185387510104064)]} 0 1
[junit4:junit4]   2> 15040 T1777 C121 P36802 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15041 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[14 (1413185387514298368)]} 0 13
[junit4:junit4]   2> 15046 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[15 (1413185387532124160)]} 0 1
[junit4:junit4]   2> 15054 T1777 C121 P36802 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15055 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[15 (1413185387536318464)]} 0 6
[junit4:junit4]   2> 15060 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[16 (1413185387545755648)]} 0 2
[junit4:junit4]   2> 15067 T1777 C121 P36802 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15068 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[16 (1413185387549949952)]} 0 6
[junit4:junit4]   2> 15073 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[17 (1413185387558338560)]} 0 3
[junit4:junit4]   2> 15089 T1791 C123 P36807 REQ /update {distrib.from=http://127.0.0.1:36799/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 15090 T1771 C124 P36799 /update {wt=javabin&version=2} {add=[17 (1413185387565678592)]} 0 14
[junit4:junit4]   2> 15094 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[100 (1413185387583504384)]} 0 1
[junit4:junit4]   2> 15124 T1777 C121 P36802 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=16 
[junit4:junit4]   2> 15125 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[100 (1413185387586650112)]} 0 28
[junit4:junit4]   2> 15129 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[101 (1413185387619155968)]} 0 1
[junit4:junit4]   2> 15139 T1777 C121 P36802 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 15140 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[101 (1413185387623350272)]} 0 8
[junit4:junit4]   2> 15143 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[102 (1413185387633836032)]} 0 1
[junit4:junit4]   2> 15154 T1777 C121 P36802 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:36792/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15155 T1754 C122 P36792 REQ /update {distrib.from=http://127.0.0.1:36799/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 15155 T1771 C124 P36799 /update {wt=javabin&version=2} {add=[102]} 0 9
[junit4:junit4]   2> 15170 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[103 (1413185387650613248)]} 0 12
[junit4:junit4]   2> 15180 T1791 C123 P36807 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:36799/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15181 T1769 C124 P36799 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 15181 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[103]} 0 8
[junit4:junit4]   2> 15186 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[104 (1413185387677876224)]} 0 2
[junit4:junit4]   2> 15193 T1791 C123 P36807 REQ /update {distrib.from=http://127.0.0.1:36799/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15194 T1771 C124 P36799 /update {wt=javabin&version=2} {add=[104 (1413185387683119104)]} 0 5
[junit4:junit4]   2> 15197 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[105 (1413185387690459136)]} 0 1
[junit4:junit4]   2> 15231 T1791 C123 P36807 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:36799/solr/collection1/&wt=javabin&version=2} status=0 QTime=11 
[junit4:junit4]   2> 15232 T1769 C124 P36799 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=30 
[junit4:junit4]   2> 15233 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[105]} 0 33
[junit4:junit4]   2> 15237 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[106 (1413185387732402176)]} 0 1
[junit4:junit4]   2> 15246 T1791 C123 P36807 REQ /update {distrib.from=http://127.0.0.1:36799/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15247 T1771 C124 P36799 /update {wt=javabin&version=2} {add=[106 (1413185387736596480)]} 0 7
[junit4:junit4]   2> 15250 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[107 (1413185387746033664)]} 0 1
[junit4:junit4]   2> 15258 T1777 C121 P36802 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15259 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[107 (1413185387750227968)]} 0 6
[junit4:junit4]   2> 15264 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[108 (1413185387759665152)]} 0 2
[junit4:junit4]   2> 15274 T1777 C121 P36802 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:36792/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15275 T1754 C122 P36792 REQ /update {distrib.from=http://127.0.0.1:36799/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 15275 T1771 C124 P36799 /update {wt=javabin&version=2} {add=[108]} 0 8
[junit4:junit4]   2> 15280 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[109 (1413185387776442368)]} 0 2
[junit4:junit4]   2> 15288 T1777 C121 P36802 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15289 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[109 (1413185387780636672)]} 0 7
[junit4:junit4]   2> 15293 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[110 (1413185387791122432)]} 0 1
[junit4:junit4]   2> 15304 T1777 C121 P36802 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:36792/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15305 T1754 C122 P36792 REQ /update {distrib.from=http://127.0.0.1:36799/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 15305 T1771 C124 P36799 /update {wt=javabin&version=2} {add=[110]} 0 9
[junit4:junit4]   2> 15309 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[111 (1413185387807899648)]} 0 1
[junit4:junit4]   2> 15319 T1777 C121 P36802 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:36792/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15319 T1754 C122 P36792 REQ /update {distrib.from=http://127.0.0.1:36799/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 15320 T1771 C124 P36799 /update {wt=javabin&version=2} {add=[111]} 0 8
[junit4:junit4]   2> 15324 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[112 (1413185387823628288)]} 0 1
[junit4:junit4]   2> 15333 T1791 C123 P36807 REQ /update {distrib.from=http://127.0.0.1:36799/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15334 T1771 C124 P36799 /update {wt=javabin&version=2} {add=[112 (1413185387827822592)]} 0 7
[junit4:junit4]   2> 15346 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[113 (1413185387838308352)]} 0 9
[junit4:junit4]   2> 15355 T1777 C121 P36802 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15356 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[113 (1413185387850891264)]} 0 7
[junit4:junit4]   2> 15361 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[114 (1413185387861377024)]} 0 2
[junit4:junit4]   2> 15369 T1777 C121 P36802 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15370 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[114 (1413185387866619904)]} 0 6
[junit4:junit4]   2> 15374 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[115 (1413185387876057088)]} 0 1
[junit4:junit4]   2> 15383 T1791 C123 P36807 REQ /update {distrib.from=http://127.0.0.1:36799/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15384 T1771 C124 P36799 /update {wt=javabin&version=2} {add=[115 (1413185387880251392)]} 0 7
[junit4:junit4]   2> 15388 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[116 (1413185387890737152)]} 0 1
[junit4:junit4]   2> 15398 T1791 C123 P36807 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:36799/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15399 T1769 C124 P36799 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 15400 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[116]} 0 9
[junit4:junit4]   2> 15405 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[117 (1413185387907514368)]} 0 2
[junit4:junit4]   2> 15415 T1791 C123 P36807 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:36799/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15416 T1769 C124 P36799 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 15416 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[117]} 0 8
[junit4:junit4]   2> 15420 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[118 (1413185387924291584)]} 0 1
[junit4:junit4]   2> 15445 T1777 C121 P36802 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=11 
[junit4:junit4]   2> 15446 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[118 (1413185387928485888)]} 0 23
[junit4:junit4]   2> 15450 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[119 (1413185387955748864)]} 0 1
[junit4:junit4]   2> 15461 T1791 C123 P36807 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:36799/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15462 T1769 C124 P36799 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 15462 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[119]} 0 9
[junit4:junit4]   2> 15466 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[120 (1413185387972526080)]} 0 1
[junit4:junit4]   2> 15476 T1791 C123 P36807 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:36799/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15476 T1769 C124 P36799 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 15477 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[120]} 0 8
[junit4:junit4]   2> 15481 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[121 (1413185387987206144)]} 0 2
[junit4:junit4]   2> 15490 T1791 C123 P36807 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:36799/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15490 T1769 C124 P36799 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 15491 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[121]} 0 8
[junit4:junit4]   2> 15496 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[122 (1413185388002934784)]} 0 2
[junit4:junit4]   2> 15505 T1777 C121 P36802 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 15506 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[122 (1413185388007129088)]} 0 8
[junit4:junit4]   2> 15521 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[123 (1413185388017614848)]} 0 13
[junit4:junit4]   2> 15530 T1777 C121 P36802 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15530 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[123 (1413185388034392064)]} 0 6
[junit4:junit4]   2> 15535 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[124 (1413185388043829248)]} 0 2
[junit4:junit4]   2> 15544 T1777 C121 P36802 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15545 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[124 (1413185388049072128)]} 0 7
[junit4:junit4]   2> 15550 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[125 (1413185388060606464)]} 0 2
[junit4:junit4]   2> 15558 T1777 C121 P36802 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15559 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[125 (1413185388065849344)]} 0 6
[junit4:junit4]   2> 15564 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[126 (1413185388074237952)]} 0 2
[junit4:junit4]   2> 15575 T1791 C123 P36807 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:36799/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15576 T1769 C124 P36799 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 15576 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[126]} 0 9
[junit4:junit4]   2> 15581 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[127 (1413185388092063744)]} 0 2
[junit4:junit4]   2> 15620 T1791 C123 P36807 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:36799/solr/collection1/&wt=javabin&version=2} status=0 QTime=11 
[junit4:junit4]   2> 15621 T1769 C124 P36799 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=34 
[junit4:junit4]   2> 15621 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[127]} 0 37
[junit4:junit4]   2> 15625 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[128 (1413185388139249664)]} 0 1
[junit4:junit4]   2> 15635 T1791 C123 P36807 REQ /update {distrib.from=http://127.0.0.1:36799/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15636 T1771 C124 P36799 /update {wt=javabin&version=2} {add=[128 (1413185388143443968)]} 0 8
[junit4:junit4]   2> 15640 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[129 (1413185388154978304)]} 0 1
[junit4:junit4]   2> 15648 T1777 C121 P36802 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15649 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[129 (1413185388159172608)]} 0 6
[junit4:junit4]   2> 15652 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[130 (1413185388167561216)]} 0 1
[junit4:junit4]   2> 15661 T1791 C123 P36807 REQ /update {distrib.from=http://127.0.0.1:36799/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15661 T1771 C124 P36799 /update {wt=javabin&version=2} {add=[130 (1413185388171755520)]} 0 6
[junit4:junit4]   2> 15666 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[131 (1413185388181192704)]} 0 2
[junit4:junit4]   2> 15674 T1791 C123 P36807 REQ /update {distrib.from=http://127.0.0.1:36799/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15675 T1771 C124 P36799 /update {wt=javabin&version=2} {add=[131 (1413185388186435584)]} 0 6
[junit4:junit4]   2> 15679 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[132 (1413185388195872768)]} 0 1
[junit4:junit4]   2> 15689 T1777 C121 P36802 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:36792/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15689 T1754 C122 P36792 REQ /update {distrib.from=http://127.0.0.1:36799/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 15690 T1771 C124 P36799 /update {wt=javabin&version=2} {add=[132]} 0 8
[junit4:junit4]   2> 15700 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[133 (1413185388211601408)]} 0 7
[junit4:junit4]   2> 15709 T1777 C121 P36802 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:36792/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15710 T1754 C122 P36792 REQ /update {distrib.from=http://127.0.0.1:36799/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 15710 T1771 C124 P36799 /update {wt=javabin&version=2} {add=[133]} 0 7
[junit4:junit4]   2> 15715 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[134 (1413185388232572928)]} 0 2
[junit4:junit4]   2> 15728 T1791 C123 P36807 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:36799/solr/collection1/&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 15728 T1769 C124 P36799 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=8 
[junit4:junit4]   2> 15729 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[134]} 0 11
[junit4:junit4]   2> 15733 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[135 (1413185388252495872)]} 0 1
[junit4:junit4]   2> 15741 T1777 C121 P36802 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15741 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[135 (1413185388256690176)]} 0 5
[junit4:junit4]   2> 15745 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[136 (1413185388265078784)]} 0 1
[junit4:junit4]   2> 15753 T1791 C123 P36807 REQ /update {distrib.from=http://127.0.0.1:36799/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15753 T1771 C124 P36799 /update {wt=javabin&version=2} {add=[136 (1413185388269273088)]} 0 5
[junit4:junit4]   2> 15758 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[137 (1413185388277661696)]} 0 1
[junit4:junit4]   2> 15767 T1791 C123 P36807 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:36799/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15768 T1769 C124 P36799 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 15768 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[137]} 0 8
[junit4:junit4]   2> 15772 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[138 (1413185388293390336)]} 0 1
[junit4:junit4]   2> 15781 T1777 C121 P36802 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:36792/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15782 T1754 C122 P36792 REQ /update {distrib.from=http://127.0.0.1:36799/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 15782 T1771 C124 P36799 /update {wt=javabin&version=2} {add=[138]} 0 7
[junit4:junit4]   2> 15787 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[139 (1413185388309118976)]} 0 1
[junit4:junit4]   2> 15794 T1791 C123 P36807 REQ /update {distrib.from=http://127.0.0.1:36799/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15795 T1771 C124 P36799 /update {wt=javabin&version=2} {add=[139 (1413185388313313280)]} 0 5
[junit4:junit4]   2> 15798 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[140 (1413185388320653312)]} 0 1
[junit4:junit4]   2> 15807 T1791 C123 P36807 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:36799/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15808 T1769 C124 P36799 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 15808 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[140]} 0 7
[junit4:junit4]   2> 15812 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[141 (1413185388335333376)]} 0 1
[junit4:junit4]   2> 15820 T1791 C123 P36807 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:36799/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15821 T1769 C124 P36799 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 15821 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[141]} 0 7
[junit4:junit4]   2> 15825 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[142 (1413185388348964864)]} 0 1
[junit4:junit4]   2> 15843 T1791 C123 P36807 REQ /update {distrib.from=http://127.0.0.1:36799/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 15843 T1771 C124 P36799 /update {wt=javabin&version=2} {add=[142 (1413185388352110592)]} 0 16
[junit4:junit4]   2> 15854 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[143 (1413185388372033536)]} 0 8
[junit4:junit4]   2> 15862 T1791 C123 P36807 REQ /update {distrib.from=http://127.0.0.1:36799/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15863 T1771 C124 P36799 /update {wt=javabin&version=2} {add=[143 (1413185388382519296)]} 0 7
[junit4:junit4]   2> 15868 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[144 (1413185388393005056)]} 0 2
[junit4:junit4]   2> 15877 T1791 C123 P36807 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:36799/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15878 T1769 C124 P36799 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 15878 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[144]} 0 7
[junit4:junit4]   2> 15882 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[145 (1413185388408733696)]} 0 1
[junit4:junit4]   2> 15891 T1791 C123 P36807 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:36799/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15892 T1769 C124 P36799 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 15892 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[145]} 0 7
[junit4:junit4]   2> 15896 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[146 (1413185388423413760)]} 0 1
[junit4:junit4]   2> 15915 T1777 C121 P36802 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 15916 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[146 (1413185388427608064)]} 0 17
[junit4:junit4]   2> 15920 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[147 (1413185388448579584)]} 0 1
[junit4:junit4]   2> 15929 T1791 C123 P36807 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:36799/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15930 T1769 C124 P36799 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 15931 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[147]} 0 8
[junit4:junit4]   2> 15934 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[148 (1413185388463259648)]} 0 1
[junit4:junit4]   2> 15943 T1777 C121 P36802 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15944 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[148 (1413185388467453952)]} 0 7
[junit4:junit4]   2> 15948 T1739 C125 P36777 /update {wt=javabin&version=2} {add=[149 (1413185388477939712)]} 0 1
[junit4:junit4]   2> 15958 T1791 C123 P36807 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:36799/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15959 T1769 C124 P36799 REQ /update {distrib.from=http://127.0.0.1:36792/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 15959 T1755 C122 P36792 /update {wt=javabin&version=2} {add=[149]} 0 8
[junit4:junit4]   2> 15960 T1727 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):1440
[junit4:junit4]   2> 15961 T1727 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 15963 T1739 C125 P36777 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 16476 T1739 C125 P36777 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@24b1cddb; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0_Block_0.pos, _0_Block_0.tip, _0.fnm, _0_Block_0.doc, _0_Memory_0.ram, _0_Block_0.tim, _0_nrm.cfs, _0_Memory_1.ram, _0_Lucene40WithOrds_0.tii, _0_Lucene40WithOrds_0.frq, _0_nrm.cfe, segments_2, _0.fdx, _0_Lucene40WithOrds_0.prx, _0.si, _0_Lucene40WithOrds_0.tib, _0.fdt]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@24b1cddb; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_3,generation=3,filenames=[_5_nrm.cfe, _2_Block_0.pos, _5_Memory_0.ram, _7.si, _3.fdt, _7_Memory_0.ram, _7.fnm, _0_Lucene40WithOrds_0.tii, _6_Block_0.pos, _0_Lucene40WithOrds_0.frq, _2_Memory_1.ram, _1_Lucene40WithOrds_0.tib, _1_Lucene40WithOrds_0.tii, _0_Lucene40WithOrds_0.tib, _1_Block_0.pos, _1_Block_0.tip, _1_Lucene40WithOrds_0.frq, _1_Block_0.tim, _0_Memory_0.ram, _2.fdt, _7.fdx, _7_Memory_1.ram, _2.fdx, _7.fdt, _3_Block_0.pos, _3_Block_0.doc, _1.fdx, _1.fdt, _5_nrm.cfs, _7_Block_0.pos, _3.si, _6.fdt, _2.si, _6_Memory_0.ram, _2_Block_0.tim, _2_Block_0.tip, _6.fdx, _1_Lucene40WithOrds_0.prx, _3.fnm, _0_Memory_1.ram, _5_Block_0.tim, _2_nrm.cfe, _1_Memory_0.ram, _2_nrm.cfs, _5_Block_0.doc, _4_Block_0.pos, _3_Block_0.tip, _4_Block_0.tip, _2_Lucene40WithOrds_0.frq, _1_Memory_1.ram, _2.fnm, _3.fdx, _1.si, _6.fnm, _6.si, _0_Lucene40WithOrds_0.prx, _3_Memory_1.ram, _3_nrm.cfe, _0_Block_0.tip, _5.fdt, _0_Block_0.tim, _7_Block_0.tim, _4.fnm, _4_nrm.cfe, _7_Block_0.tip, _1.fnm, _4.fdx, _3_Block_0.tim, _1_Block_0.doc, _0.fnm, _4_Block_0.tim, _6_Block_0.doc, _4_Memory_1.ram, _5.si, _3_nrm.cfs, _5_Memory_1.ram, _4_Memory_0.ram, _4_nrm.cfs, _5_Block_0.tip, _7_Block_0.doc, _0_Block_0.pos, _6_Memory_1.ram, _4_Block_0.doc, _6_nrm.cfs, _2_Lucene40WithOrds_0.prx, _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, _2_Lucene40WithOrds_0.tii, _0_nrm.cfe, _6_Block_0.tip, _5.fdx, _2_Lucene40WithOrds_0.tib, _0.fdx, _6_Block_0.tim, _2_Block_0.doc, segments_3, _0.fdt]
[junit4:junit4]   2> 16477 T1739 C125 P36777 oasc.SolrDeletionPolicy.updateCommits newest commit = 3
[junit4:junit4]   2> 16515 T1739 C125 P36777 oass.SolrIndexSearcher.<init> Opening Searcher@6fa271a5 main
[junit4:junit4]   2> 16516 T1739 C125 P36777 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 16517 T1750 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6fa271a5 main{StandardDirectoryReader(segments_3:17 _0(5.0):C1 _1(5.0):C10 _2(5.0):C10 _3(5.0):C10 _4(5.0):C10 _5(5.0):C10 _6(5.0):C10 _7(5.0):C6)}
[junit4:junit4]   2> 16518 T1739 C125 P36777 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 555
[junit4:junit4]   2> 16521 T1755 C122 P36792 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 16755 T1755 C122 P36792 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@1b4b1c2b; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0_Block_0.pos, _0_Block_0.tip, _0.fnm, _0_Block_0.doc, _0_Memory_0.ram, _0_Block_0.tim, _0_nrm.cfs, _0_Memory_1.ram, _0_Lucene40WithOrds_0.tii, _0_Lucene40WithOrds_0.frq, _0_nrm.cfe, segments_2, _0.fdx, _0_Lucene40WithOrds_0.prx, _0.si, _0_Lucene40WithOrds_0.tib, _0.fdt]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@1b4b1c2b; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_3,generation=3,filenames=[_3_nrm.cfe, _0_Block_0.tip, _2_Block_0.pos, _0_Block_0.tim, _4_nrm.cfe, _4.fnm, _3.fdt, _1.fnm, _4.fdx, _0_Lucene40WithOrds_0.tii, _3_Block_0.tim, _0_Lucene40WithOrds_0.frq, _1_Lucene40WithOrds_0.tib, _2_Memory_1.ram, _1_Lucene40WithOrds_0.tii, _0_Lucene40WithOrds_0.tib, _1_Block_0.doc, _1_Block_0.tip, _1_Block_0.pos, _1_Lucene40WithOrds_0.frq, _4_Block_0.tim, _0.fnm, _1_Block_0.tim, _0_Memory_0.ram, _2.fdt, _4_Memory_1.ram, _2.fdx, _3_Block_0.pos, _3_Block_0.doc, _3_nrm.cfs, _1.fdx, _1.fdt, _4_Memory_0.ram, _4_nrm.cfs, _3.si, _2.si, _0_Block_0.pos, _2_Block_0.tim, _2_Block_0.tip, _1_Lucene40WithOrds_0.prx, _3.fnm, _0_Memory_1.ram, _4_Block_0.doc, _1_Memory_0.ram, _2_nrm.cfe, _2_Memory_0.ram, _3_Memory_0.ram, _0.si, _2_nrm.cfs, _4_Block_0.pos, _3_Block_0.tip, _1_nrm.cfs, _0_Block_0.doc, _4_Block_0.tip, _1_Memory_1.ram, _4.si, _4.fdt, _0_nrm.cfs, _1_nrm.cfe, _2.fnm, _3.fdx, _1.si, _0_nrm.cfe, _0.fdx, _0_Lucene40WithOrds_0.prx, _2_Block_0.doc, _3_Memory_1.ram, _0.fdt, segments_3]
[junit4:junit4]   2> 16756 T1755 C122 P36792 oasc.SolrDeletionPolicy.updateCommits newest commit = 3
[junit4:junit4]   2> 16781 T1755 C122 P36792 oass.SolrIndexSearcher.<init> Opening Searcher@2fdc2d72 main
[junit4:junit4]   2> 16782 T1755 C122 P36792 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 16783 T1762 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2fdc2d72 main{StandardDirectoryReader(segments_3:11 _0(5.0):C1 _1(5.0):C10 _2(5.0):C10 _3(5.0):C10 _4(5.0):C1)}
[junit4:junit4]   2> 16784 T1755 C122 P36792 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:36802/solr/collection1/, StdNode: http://127.0.0.1:36799/solr/collection1/, StdNode: http://127.0.0.1:36807/solr/collection1/]
[junit4:junit4]   2> 16786 T1769 C124 P36799 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 16786 T1791 C123 P36807 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 16786 T1777 C121 P36802 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 17171 T1777 C121 P36802 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347718593367/jetty3/index.20120915091644934 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7773ff0e; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0_Block_0.pos, _0_Block_0.tip, _0.fnm, _0_Block_0.doc, _0_Memory_0.ram, _0_Block_0.tim, _0_nrm.cfs, _0_Memory_1.ram, _0_Lucene40WithOrds_0.tii, _0_Lucene40WithOrds_0.frq, _0_nrm.cfe, segments_2, _0.fdx, _0_Lucene40WithOrds_0.prx, _0.si, _0_Lucene40WithOrds_0.tib, _0.fdt]
[junit4:junit4]   2> 		commit{d

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

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> 183900 T1799 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 183902 T1799 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> 183902 T1799 oasu.DefaultSolrCoreState.decref SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 183904 T1799 oasu.DefaultSolrCoreState.decref Closing SolrCoreState - canceling any ongoing recovery
[junit4:junit4]   2> 183904 T1799 oasc.LeaderElector$1.process WARNING  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard2/election/88324085735358470-127.0.0.1:36807_solr_collection1-n_0000000004
[junit4:junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:118)
[junit4:junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
[junit4:junit4]   2> 	at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:734)
[junit4:junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:178)
[junit4:junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:175)
[junit4:junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:67)
[junit4:junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:175)
[junit4:junit4]   2> 	at org.apache.solr.cloud.ElectionContext.cancelElection(ElectionContext.java:60)
[junit4:junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:151)
[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.joinElection(LeaderElector.java:275)
[junit4:junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.rejoinLeaderElection(ElectionContext.java:326)
[junit4:junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:204)
[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> 183905 T1799 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 183905 T1799 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 183905 T1799 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 183905 T1799 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 183906 T1799 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5de0e371 name:ZooKeeperConnection Watcher:127.0.0.1:36773/solr got event WatchedEvent state:Disconnected type:None path:null path:null type:None
[junit4:junit4]   2> 183906 T1799 oascc.ConnectionManager.process Client->ZooKeeper status change trigger but we are already closed
[junit4:junit4]   2> 183906 T1799 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> NOTE: test params are: codec=Lucene40: {n_f1=PostingsFormat(name=Memory doPackFST= false), foo_b=PostingsFormat(name=Lucene40WithOrds), foo_d=Block(blocksize=128), foo_f=PostingsFormat(name=Lucene40WithOrds), n_tl1=PostingsFormat(name=Memory doPackFST= false), n_d1=PostingsFormat(name=Memory doPackFST= true), rnd_b=Block(blocksize=128), intDefault=PostingsFormat(name=Memory doPackFST= false), n_td1=PostingsFormat(name=Memory doPackFST= false), id=Block(blocksize=128), timestamp=PostingsFormat(name=Memory doPackFST= true), range_facet_sl=Block(blocksize=128), range_facet_si=PostingsFormat(name=Memory doPackFST= true), oddField_s=Block(blocksize=128), multiDefault=PostingsFormat(name=Memory doPackFST= true), n_tf1=PostingsFormat(name=Memory doPackFST= true), n_dt1=PostingsFormat(name=Memory doPackFST= false), n_ti1=Block(blocksize=128), range_facet_l=PostingsFormat(name=Memory doPackFST= true), text=PostingsFormat(name=Lucene40WithOrds), _version_=PostingsFormat(name=Memory doPackFST= false), SubjectTerms_mfacet=PostingsFormat(name=Memory doPackFST= false), a_t=PostingsFormat(name=Memory doPackFST= true), n_tdt1=PostingsFormat(name=Memory doPackFST= false), other_tl1=PostingsFormat(name=Memory doPackFST= false), n_l1=PostingsFormat(name=Memory doPackFST= true), a_si=PostingsFormat(name=Memory doPackFST= false)}, sim=DefaultSimilarity, locale=ar_BH, timezone=America/Indiana/Tell_City
[junit4:junit4]   2> NOTE: FreeBSD 9.0-RELEASE amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=1,free=134680472,total=288030720
[junit4:junit4]   2> NOTE: All tests run in this JVM: [SolrCoreTest, TestLRUCache, QueryEqualityTest, TestBM25SimilarityFactory, TestWriterPerf, TestOmitPositions, IndexReaderFactoryTest, SuggesterTSTTest, TestRealTimeGet, TestPluginEnable, OutputWriterTest, SolrInfoMBeanTest, TestRemoteStreaming, TestPhraseSuggestions, TestStressRecovery, TestArbitraryIndexDir, TestUtils, IndexSchemaRuntimeFieldTest, LukeRequestHandlerTest, TermVectorComponentTest, TestQuerySenderListener, TestFunctionQuery, DocumentAnalysisRequestHandlerTest, TestReversedWildcardFilterFactory, TestMergePolicyConfig, DirectSolrSpellCheckerTest, SuggesterTest, TestDocSet, SyncSliceTest, DisMaxRequestHandlerTest, DistributedQueryElevationComponentTest, TestStressLucene, TestDistributedGrouping, HighlighterTest, TestDistributedSearch, TestPropInject, XsltUpdateRequestHandlerTest, UUIDFieldTest, TestUpdate, EchoParamsTest, TestQueryUtils, IndexSchemaTest, BasicFunctionalityTest, DebugComponentTest, TestCSVLoader, BasicZkTest, PathHierarchyTokenizerFactoryTest, FullSolrCloudDistribCmdsTest, TestSolrDeletionPolicy1, TestSurroundQueryParser, StatsComponentTest, TestHashPartitioner, TimeZoneUtilsTest, XmlUpdateRequestHandlerTest, URLClassifyProcessorTest, TestBinaryField, TestReplicationHandler, DistributedSpellCheckComponentTest, TestRandomFaceting, TestJoin, SignatureUpdateProcessorFactoryTest, TestBinaryResponseWriter, SampleTest, PolyFieldTest, MoreLikeThisHandlerTest, BinaryUpdateRequestHandlerTest, TermsComponentTest, StandardRequestHandlerTest, FieldAnalysisRequestHandlerTest, TestSolrQueryParser, TestValueSourceCache, ReturnFieldsTest, RequiredFieldsTest, UpdateParamsTest, ShowFileRequestHandlerTest, NotRequiredUniqueKeyTest, BadIndexSchemaTest, UpdateRequestProcessorFactoryTest, BadComponentTest, TestSolrDeletionPolicy2, DefaultValueUpdateProcessorTest, TestCollationField, MultiTermTest, TestSolrCoreProperties, TestLMDirichletSimilarityFactory, LegacyHTMLStripCharFilterTest, TestDFRSimilarityFactory, TestCodecSupport, OpenExchangeRatesOrgProviderTest, FileUtilsTest, DateFieldTest, TestBadConfig, TestDocumentBuilder, TestCharFilters, BasicDistributedZk2Test]
[junit4:junit4] Completed on J1 in 184.02s, 1 test, 1 failure <<< FAILURES!

[...truncated 5 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/build.xml:32: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build.xml:146: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/lucene/module-build.xml:63: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/lucene/common-build.xml:1133: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/lucene/common-build.xml:810: There were test failures: 228 suites, 923 tests, 1 failure, 6 ignored (1 assumption)

Total time: 29 minutes 4 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