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-java7 - Build # 3207 - Still Failing
Date Sat, 15 Sep 2012 06:38:17 GMT
Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-java7/3207/

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([E89117C82B74F8C2:697799D05C2B98FE]: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:601)
	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:722)




Build Log:
[...truncated 8279 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4:junit4]   2> 3 T2250 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1347690828275
[junit4:junit4]   2> 4 T2250 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 6 T2251 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4]   2> 7 T2251 oazs.NIOServerCnxn$Factory.<init> binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 7 T2251 oazsp.FileTxnSnapLog.save Snapshotting: 0
[junit4:junit4]   2> 105 T2250 oasc.ZkTestServer.run start zk server on port:25746
[junit4:junit4]   2> 105 T2250 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:25746 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@7b2bde4d
[junit4:junit4]   2> 106 T2256 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:25746
[junit4:junit4]   2> 106 T2250 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 107 T2256 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:25746, initiating session
[junit4:junit4]   2> 107 T2252 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:21620
[junit4:junit4]   2> 108 T2252 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:21620
[junit4:junit4]   2> 108 T2254 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 111 T2254 oazs.NIOServerCnxn.finishSessionInit Established session 0x139c8a211f70000 with negotiated timeout 10000 for client /140.211.11.196:21620
[junit4:junit4]   2> 111 T2256 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:25746, sessionid = 0x139c8a211f70000, negotiated timeout = 10000
[junit4:junit4]   2> 112 T2257 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7b2bde4d name:ZooKeeperConnection Watcher:127.0.0.1:25746 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 112 T2250 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 112 T2250 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 131 T2255 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x139c8a211f70000
[junit4:junit4]   2> 143 T2257 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 144 T2252 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:21620 which had sessionid 0x139c8a211f70000
[junit4:junit4]   2> 143 T2250 oaz.ZooKeeper.close Session: 0x139c8a211f70000 closed
[junit4:junit4]   2> 144 T2250 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:25746/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@1d4a22b
[junit4:junit4]   2> 145 T2258 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:25746
[junit4:junit4]   2> 145 T2250 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 146 T2258 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:25746, initiating session
[junit4:junit4]   2> 146 T2252 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:26691
[junit4:junit4]   2> 146 T2252 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:26691
[junit4:junit4]   2> 147 T2254 oazs.NIOServerCnxn.finishSessionInit Established session 0x139c8a211f70001 with negotiated timeout 10000 for client /140.211.11.196:26691
[junit4:junit4]   2> 147 T2258 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:25746, sessionid = 0x139c8a211f70001, negotiated timeout = 10000
[junit4:junit4]   2> 148 T2259 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d4a22b name:ZooKeeperConnection Watcher:127.0.0.1:25746/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 148 T2250 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 148 T2250 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 159 T2250 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 162 T2250 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 164 T2250 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 167 T2250 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 168 T2250 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 172 T2250 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4]   2> 173 T2250 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 276 T2250 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 277 T2250 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 280 T2250 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4]   2> 281 T2250 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 283 T2250 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4]   2> 284 T2250 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 286 T2250 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4]   2> 287 T2250 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 290 T2250 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 290 T2250 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 293 T2250 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 294 T2250 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 296 T2250 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 297 T2250 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 300 T2250 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4]   2> 300 T2250 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 303 T2255 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x139c8a211f70001
[junit4:junit4]   2> 310 T2259 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 310 T2250 oaz.ZooKeeper.close Session: 0x139c8a211f70001 closed
[junit4:junit4]   2> 311 T2252 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:26691 which had sessionid 0x139c8a211f70001
[junit4:junit4]   2> 312 T2250 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 316 T2250 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:60384
[junit4:junit4]   2> 317 T2250 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 317 T2250 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 318 T2250 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 350 T2250 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 350 T2250 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 351 T2250 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 351 T2250 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/solr.xml
[junit4:junit4]   2> 351 T2250 oasc.CoreContainer.<init> New CoreContainer 1837682708
[junit4:junit4]   2> 352 T2250 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 352 T2250 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 379 T2250 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 398 T2250 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:25746/solr
[junit4:junit4]   2> 398 T2250 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:25746/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@5baf3ae1
[junit4:junit4]   2> 399 T2269 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:25746
[junit4:junit4]   2> 399 T2250 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 401 T2269 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:25746, initiating session
[junit4:junit4]   2> 401 T2252 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:46931
[junit4:junit4]   2> 401 T2252 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:46931
[junit4:junit4]   2> 403 T2254 oazs.NIOServerCnxn.finishSessionInit Established session 0x139c8a211f70002 with negotiated timeout 5000 for client /140.211.11.196:46931
[junit4:junit4]   2> 403 T2269 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:25746, sessionid = 0x139c8a211f70002, negotiated timeout = 5000
[junit4:junit4]   2> 403 T2270 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5baf3ae1 name:ZooKeeperConnection Watcher:127.0.0.1:25746/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 404 T2250 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 405 T2255 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c8a211f70002 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 415 T2250 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 417 T2250 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:60384_solr
[junit4:junit4]   2> 417 T2255 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c8a211f70002 type:delete cxid:0x7 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:60384_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:60384_solr
[junit4:junit4]   2> 419 T2250 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:60384_solr
[junit4:junit4]   2> 421 T2250 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 422 T2250 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 422 T2250 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 423 T2250 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 423 T2250 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 424 T2250 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 424 T2250 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 425 T2250 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 425 T2250 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 426 T2250 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 442 T2250 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 447 T2255 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c8a211f70002 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> 459 T2250 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 461 T2250 oasc.Overseer.start Overseer (id=88322266122092546-127.0.0.1:60384_solr-n_0000000000) starting
[junit4:junit4]   2> 462 T2255 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c8a211f70002 type:create cxid:0x1a zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 463 T2255 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c8a211f70002 type:create cxid:0x1b zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 465 T2255 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c8a211f70002 type:create cxid:0x1c zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 477 T2255 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c8a211f70002 type:create cxid:0x1d zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 478 T2272 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 478 T2250 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 487 T2250 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 489 T2271 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 494 T2250 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1
[junit4:junit4]   2> 495 T2250 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 495 T2250 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 496 T2250 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 497 T2250 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4]   2> 499 T2250 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4]   2> 499 T2250 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 553 T2250 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 626 T2250 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 727 T2250 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 736 T2250 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 1012 T3 oasc.CoreContainer.finalize SEVERE CoreContainer was not shutdown prior to finalize(), indicates a bug -- POSSIBLE RESOURCE LEAK!!!  instance=378813303
[junit4:junit4]   2> 1195 T2250 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 1202 T2250 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 1205 T2250 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 1213 T2250 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1217 T2250 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1220 T2250 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1221 T2250 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1222 T2250 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/control/data/
[junit4:junit4]   2> 1222 T2250 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7639fabd
[junit4:junit4]   2> 1223 T2250 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/control/data/index/
[junit4:junit4]   2> 1224 T2250 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/control/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 1225 T2250 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/control/data/index forceNew:false
[junit4:junit4]   2> 1231 T2250 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-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c784399; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 1231 T2250 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 1232 T2250 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 1234 T2250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 1234 T2250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 1235 T2250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 1235 T2250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 1236 T2250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 1236 T2250 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 1237 T2250 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 1237 T2250 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 1238 T2250 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 1238 T2250 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 1239 T2250 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 1239 T2250 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 1240 T2250 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 1240 T2250 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 1240 T2250 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 1241 T2250 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 1241 T2250 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1242 T2250 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1242 T2250 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1243 T2250 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1243 T2250 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1244 T2250 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1244 T2250 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1244 T2250 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 1245 T2250 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 1247 T2250 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 1251 T2250 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 1252 T2250 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> 1254 T2250 oass.SolrIndexSearcher.<init> Opening Searcher@6774f36d main
[junit4:junit4]   2> 1255 T2250 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 1256 T2250 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 1256 T2250 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 1262 T2250 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 1338 T2273 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6774f36d main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 1342 T2255 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c8a211f70002 type:create cxid:0x53 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer/queue Error:KeeperErrorCode = NoNode for /solr/overseer/queue
[junit4:junit4]   2> 1354 T2250 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 1355 T2250 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:60384/solr shardId:control_shard
[junit4:junit4]   2> 1356 T2250 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/control_shard/election
[junit4:junit4]   2> 1369 T2255 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c8a211f70002 type:delete cxid:0x62 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/collections/control_collection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/control_collection/leaders
[junit4:junit4]   2> 1377 T2250 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 1377 T2255 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c8a211f70002 type:create cxid:0x63 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 1494 T2271 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 1494 T2255 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c8a211f70002 type:create cxid:0x6a zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer/queue-work Error:KeeperErrorCode = NoNode for /solr/overseer/queue-work
[junit4:junit4]   2> 1551 T2270 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 1880 T2250 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 1881 T2250 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 1882 T2250 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:60384/solr/collection1/
[junit4:junit4]   2> 1882 T2250 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 1883 T2250 oasc.SyncStrategy.syncToMe http://127.0.0.1:60384/solr/collection1/ has no replicas
[junit4:junit4]   2> 1883 T2250 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:60384/solr/collection1/
[junit4:junit4]   2> 1884 T2250 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/control_shard
[junit4:junit4]   2> 1887 T2255 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c8a211f70002 type:create cxid:0x88 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2056 T2271 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2080 T2270 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 2128 T2250 oasc.ZkController.register We are http://127.0.0.1:60384/solr/collection1/ and leader is http://127.0.0.1:60384/solr/collection1/
[junit4:junit4]   2> 2128 T2250 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:60384/solr
[junit4:junit4]   2> 2129 T2250 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 2130 T2250 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2131 T2250 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1
[junit4:junit4]   2> 2131 T2250 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 2132 T2250 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 2145 T2250 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 2148 T2250 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:37536
[junit4:junit4]   2> 2148 T2250 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 2149 T2250 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 2149 T2250 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 2180 T2250 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 2181 T2250 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 2181 T2250 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 2181 T2250 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/solr.xml
[junit4:junit4]   2> 2182 T2250 oasc.CoreContainer.<init> New CoreContainer 1039830962
[junit4:junit4]   2> 2182 T2250 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 2183 T2250 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 2208 T2250 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 2220 T2250 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:25746/solr
[junit4:junit4]   2> 2221 T2250 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:25746/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@4dbb9da3
[junit4:junit4]   2> 2221 T2283 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:25746
[junit4:junit4]   2> 2221 T2250 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 2223 T2283 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:25746, initiating session
[junit4:junit4]   2> 2223 T2252 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:44034
[junit4:junit4]   2> 2223 T2252 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:44034
[junit4:junit4]   2> 2225 T2254 oazs.NIOServerCnxn.finishSessionInit Established session 0x139c8a211f70003 with negotiated timeout 5000 for client /140.211.11.196:44034
[junit4:junit4]   2> 2225 T2283 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:25746, sessionid = 0x139c8a211f70003, negotiated timeout = 5000
[junit4:junit4]   2> 2225 T2284 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4dbb9da3 name:ZooKeeperConnection Watcher:127.0.0.1:25746/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 2225 T2250 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 2226 T2255 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c8a211f70003 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2227 T2255 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c8a211f70003 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2240 T2250 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37536_solr
[junit4:junit4]   2> 2241 T2255 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c8a211f70003 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:37536_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:37536_solr
[junit4:junit4]   2> 2242 T2250 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:37536_solr
[junit4:junit4]   2> 2252 T2270 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 2253 T2250 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 2254 T2250 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 2254 T2250 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 2255 T2250 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 2255 T2250 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 2256 T2250 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 2256 T2250 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 2257 T2250 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 2257 T2250 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 2258 T2250 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 2272 T2250 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 2279 T2250 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1
[junit4:junit4]   2> 2280 T2250 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 2281 T2250 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 2281 T2250 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 2282 T2250 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4]   2> 2284 T2250 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4]   2> 2285 T2250 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 2340 T2250 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 2416 T2250 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 2517 T2250 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 2524 T2250 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 2584 T2271 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2595 T2270 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 2595 T2284 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 3162 T2250 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 3180 T2250 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 3184 T2250 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 3196 T2250 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 3201 T2250 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 3206 T2250 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 3207 T2250 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 3208 T2250 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty1/
[junit4:junit4]   2> 3209 T2250 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7639fabd
[junit4:junit4]   2> 3210 T2250 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty1/index/
[junit4:junit4]   2> 3211 T2250 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 3212 T2250 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty1/index forceNew:false
[junit4:junit4]   2> 3219 T2250 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-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@185a9dc8; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 3220 T2250 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 3221 T2250 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 3224 T2250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 3225 T2250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 3225 T2250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 3226 T2250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 3227 T2250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 3228 T2250 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 3228 T2250 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 3229 T2250 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 3230 T2250 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 3231 T2250 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 3232 T2250 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 3232 T2250 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 3233 T2250 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 3234 T2250 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 3234 T2250 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 3235 T2250 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 3236 T2250 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3237 T2250 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3237 T2250 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3238 T2250 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3239 T2250 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3240 T2250 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3240 T2250 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 3241 T2250 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 3242 T2250 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 3246 T2250 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 3251 T2250 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 3252 T2250 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> 3256 T2250 oass.SolrIndexSearcher.<init> Opening Searcher@117be34a main
[junit4:junit4]   2> 3258 T2250 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 3259 T2250 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 3259 T2250 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 3267 T2250 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 3344 T2285 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@117be34a main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 3600 T2271 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3635 T2270 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 3635 T2284 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 3853 T2250 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 3854 T2250 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:37536/solr shardId:shard1
[junit4:junit4]   2> 3855 T2250 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 3860 T2255 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c8a211f70003 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> 3861 T2250 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 3862 T2255 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c8a211f70003 type:create cxid:0x44 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3864 T2250 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 3864 T2250 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 3865 T2250 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:37536/solr/collection1/
[junit4:junit4]   2> 3865 T2250 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 3866 T2250 oasc.SyncStrategy.syncToMe http://127.0.0.1:37536/solr/collection1/ has no replicas
[junit4:junit4]   2> 3866 T2250 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:37536/solr/collection1/
[junit4:junit4]   2> 3867 T2250 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 3871 T2255 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c8a211f70003 type:create cxid:0x4e zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4140 T2271 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4157 T2284 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4157 T2270 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4179 T2250 oasc.ZkController.register We are http://127.0.0.1:37536/solr/collection1/ and leader is http://127.0.0.1:37536/solr/collection1/
[junit4:junit4]   2> 4180 T2250 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:37536/solr
[junit4:junit4]   2> 4180 T2250 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 4182 T2250 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4183 T2250 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1
[junit4:junit4]   2> 4184 T2250 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 4184 T2250 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 4202 T2250 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 4205 T2250 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:50781
[junit4:junit4]   2> 4206 T2250 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 4206 T2250 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 4207 T2250 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 4255 T2250 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 4256 T2250 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 4256 T2250 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 4257 T2250 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/solr.xml
[junit4:junit4]   2> 4257 T2250 oasc.CoreContainer.<init> New CoreContainer 718484024
[junit4:junit4]   2> 4258 T2250 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 4258 T2250 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 4296 T2250 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 4314 T2250 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:25746/solr
[junit4:junit4]   2> 4315 T2250 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:25746/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@35e42a8e
[junit4:junit4]   2> 4316 T2295 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:25746
[junit4:junit4]   2> 4316 T2250 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 4317 T2295 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:25746, initiating session
[junit4:junit4]   2> 4317 T2252 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:21050
[junit4:junit4]   2> 4317 T2252 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:21050
[junit4:junit4]   2> 4319 T2254 oazs.NIOServerCnxn.finishSessionInit Established session 0x139c8a211f70004 with negotiated timeout 5000 for client /140.211.11.196:21050
[junit4:junit4]   2> 4319 T2295 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:25746, sessionid = 0x139c8a211f70004, negotiated timeout = 5000
[junit4:junit4]   2> 4319 T2296 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@35e42a8e name:ZooKeeperConnection Watcher:127.0.0.1:25746/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 4319 T2250 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 4320 T2255 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c8a211f70004 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4321 T2255 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c8a211f70004 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4322 T2250 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50781_solr
[junit4:junit4]   2> 4323 T2255 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c8a211f70004 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:50781_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:50781_solr
[junit4:junit4]   2> 4324 T2250 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50781_solr
[junit4:junit4]   2> 4325 T2284 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 4325 T2270 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 4326 T2250 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 4327 T2250 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 4327 T2250 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 4328 T2250 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 4328 T2250 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 4329 T2250 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 4329 T2250 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 4330 T2250 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 4330 T2250 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 4331 T2250 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 4344 T2250 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 4351 T2250 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1
[junit4:junit4]   2> 4352 T2250 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 4352 T2250 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 4353 T2250 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 4354 T2250 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4]   2> 4356 T2250 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4]   2> 4356 T2250 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 4412 T2250 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 4487 T2250 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 4589 T2250 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 4596 T2250 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 4661 T2271 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4673 T2296 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4673 T2284 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4673 T2270 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5205 T2250 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 5216 T2250 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 5221 T2250 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 5231 T2250 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 5236 T2250 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 5241 T2250 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 5242 T2250 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 5243 T2250 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty2/
[junit4:junit4]   2> 5244 T2250 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7639fabd
[junit4:junit4]   2> 5245 T2250 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty2/index/
[junit4:junit4]   2> 5246 T2250 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 5247 T2250 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty2/index forceNew:false
[junit4:junit4]   2> 5253 T2250 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-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@5bb53a9e; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 5254 T2250 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 5255 T2250 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 5257 T2250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 5258 T2250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 5259 T2250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 5259 T2250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 5260 T2250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 5260 T2250 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 5261 T2250 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 5262 T2250 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 5262 T2250 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 5263 T2250 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 5264 T2250 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 5265 T2250 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 5265 T2250 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 5266 T2250 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 5266 T2250 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 5267 T2250 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 5268 T2250 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5268 T2250 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5269 T2250 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5270 T2250 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5270 T2250 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5271 T2250 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5272 T2250 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5273 T2250 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 5273 T2250 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 5277 T2250 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 5281 T2250 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 5283 T2250 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> 5286 T2250 oass.SolrIndexSearcher.<init> Opening Searcher@1e7ae111 main
[junit4:junit4]   2> 5288 T2250 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 5288 T2250 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 5289 T2250 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 5306 T2250 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 5382 T2297 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1e7ae111 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 5678 T2271 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 5691 T2270 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5691 T2284 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5692 T2296 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5892 T2250 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 5893 T2250 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:50781/solr shardId:shard2
[junit4:junit4]   2> 5894 T2250 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4]   2> 5907 T2255 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c8a211f70004 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> 5908 T2250 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 5909 T2255 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c8a211f70004 type:create cxid:0x43 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 5916 T2250 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 5917 T2250 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 5917 T2250 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50781/solr/collection1/
[junit4:junit4]   2> 5918 T2250 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 5918 T2250 oasc.SyncStrategy.syncToMe http://127.0.0.1:50781/solr/collection1/ has no replicas
[junit4:junit4]   2> 5919 T2250 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50781/solr/collection1/
[junit4:junit4]   2> 5919 T2250 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4]   2> 5922 T2255 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c8a211f70004 type:create cxid:0x4c zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 6195 T2271 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6214 T2284 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6214 T2270 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6214 T2296 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6231 T2250 oasc.ZkController.register We are http://127.0.0.1:50781/solr/collection1/ and leader is http://127.0.0.1:50781/solr/collection1/
[junit4:junit4]   2> 6231 T2250 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50781/solr
[junit4:junit4]   2> 6232 T2250 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 6234 T2250 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6235 T2250 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1
[junit4:junit4]   2> 6235 T2250 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 6236 T2250 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 6249 T2250 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 6253 T2250 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:39603
[junit4:junit4]   2> 6254 T2250 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 6254 T2250 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 6254 T2250 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 6291 T2250 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 6292 T2250 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 6292 T2250 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 6293 T2250 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/solr.xml
[junit4:junit4]   2> 6293 T2250 oasc.CoreContainer.<init> New CoreContainer 1341151349
[junit4:junit4]   2> 6294 T2250 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 6294 T2250 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 6323 T2250 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 6337 T2250 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:25746/solr
[junit4:junit4]   2> 6338 T2250 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:25746/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@6db2a333
[junit4:junit4]   2> 6339 T2307 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:25746
[junit4:junit4]   2> 6349 T2250 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 6349 T2307 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:25746, initiating session
[junit4:junit4]   2> 6350 T2252 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:30331
[junit4:junit4]   2> 6350 T2252 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:30331
[junit4:junit4]   2> 6352 T2254 oazs.NIOServerCnxn.finishSessionInit Established session 0x139c8a211f70005 with negotiated timeout 5000 for client /140.211.11.196:30331
[junit4:junit4]   2> 6352 T2307 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:25746, sessionid = 0x139c8a211f70005, negotiated timeout = 5000
[junit4:junit4]   2> 6353 T2308 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6db2a333 name:ZooKeeperConnection Watcher:127.0.0.1:25746/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 6353 T2250 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 6353 T2255 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c8a211f70005 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 6363 T2255 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c8a211f70005 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 6364 T2250 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39603_solr
[junit4:junit4]   2> 6365 T2255 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c8a211f70005 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:39603_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:39603_solr
[junit4:junit4]   2> 6370 T2250 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:39603_solr
[junit4:junit4]   2> 6372 T2270 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 6372 T2296 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 6372 T2284 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 6373 T2250 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 6373 T2250 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 6374 T2250 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 6374 T2250 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 6375 T2250 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 6376 T2250 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 6376 T2250 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 6377 T2250 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 6378 T2250 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 6378 T2250 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 6393 T2250 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 6401 T2250 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1
[junit4:junit4]   2> 6401 T2250 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 6402 T2250 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 6403 T2250 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 6404 T2250 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4]   2> 6406 T2250 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4]   2> 6407 T2250 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 6462 T2250 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 6535 T2250 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 6636 T2250 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 6642 T2250 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 6727 T2271 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6783 T2284 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6783 T2308 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6783 T2270 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6783 T2296 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7203 T2250 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 7213 T2250 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 7218 T2250 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 7228 T2250 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 7232 T2250 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 7237 T2250 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 7238 T2250 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 7239 T2250 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty3/
[junit4:junit4]   2> 7239 T2250 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7639fabd
[junit4:junit4]   2> 7240 T2250 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty3/index/
[junit4:junit4]   2> 7241 T2250 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 7242 T2250 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty3/index forceNew:false
[junit4:junit4]   2> 7248 T2250 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-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty3/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@6eba038; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 7249 T2250 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 7250 T2250 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 7252 T2250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 7253 T2250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 7253 T2250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 7254 T2250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 7255 T2250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 7255 T2250 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 7256 T2250 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 7256 T2250 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 7257 T2250 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 7258 T2250 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 7258 T2250 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 7259 T2250 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 7260 T2250 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 7260 T2250 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 7261 T2250 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 7261 T2250 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 7262 T2250 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7263 T2250 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7263 T2250 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7264 T2250 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7265 T2250 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7265 T2250 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7266 T2250 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7266 T2250 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 7267 T2250 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 7271 T2250 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 7275 T2250 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 7276 T2250 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> 7280 T2250 oass.SolrIndexSearcher.<init> Opening Searcher@5ec2ae1 main
[junit4:junit4]   2> 7281 T2250 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 7282 T2250 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 7283 T2250 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 7290 T2250 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 7341 T2309 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5ec2ae1 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 7791 T2271 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7806 T2284 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7806 T2296 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7806 T2308 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7806 T2270 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7848 T2250 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 7848 T2250 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:39603/solr shardId:shard1
[junit4:junit4]   2> 7851 T2250 oasc.ZkController.register We are http://127.0.0.1:39603/solr/collection1/ and leader is http://127.0.0.1:37536/solr/collection1/
[junit4:junit4]   2> 7851 T2250 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:39603/solr
[junit4:junit4]   2> 7851 T2250 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 7852 T2250 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C192 name=collection1 org.apache.solr.core.SolrCore@5ab3c798 url=http://127.0.0.1:39603/solr/collection1 node=127.0.0.1:39603_solr
[junit4:junit4]   2> 7853 T2310 C192 P39603 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 7854 T2310 C192 P39603 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 7853 T2250 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7855 T2310 C192 P39603 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:37536/solr/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 7855 T2310 C192 P39603 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:39603/solr START replicas=[http://127.0.0.1:37536/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 7855 T2310 C192 P39603 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 7856 T2310 C192 P39603 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 7855 T2250 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1
[junit4:junit4]   2> 7856 T2310 C192 P39603 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 7856 T2250 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 7857 T2310 C192 P39603 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 7857 T2250 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C193 name=collection1 org.apache.solr.core.SolrCore@10f092cc url=http://127.0.0.1:37536/solr/collection1 node=127.0.0.1:37536_solr
[junit4:junit4]   2> 7864 T2276 C193 P37536 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=0 
[junit4:junit4]   2> 7880 T2250 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 7882 T2250 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:36687
[junit4:junit4]   2> 7883 T2250 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 7883 T2250 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 7884 T2250 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 7919 T2250 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 7919 T2250 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 7920 T2250 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 7920 T2250 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/solr.xml
[junit4:junit4]   2> 7921 T2250 oasc.CoreContainer.<init> New CoreContainer 202390483
[junit4:junit4]   2> 7921 T2250 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 7922 T2250 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 7950 T2250 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 7964 T2250 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:25746/solr
[junit4:junit4]   2> 7965 T2250 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:25746/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@7cb5c30a
[junit4:junit4]   2> 7966 T2321 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:25746
[junit4:junit4]   2> 7966 T2250 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 7967 T2321 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:25746, initiating session
[junit4:junit4]   2> 7968 T2252 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:63763
[junit4:junit4]   2> 7968 T2252 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:63763
[junit4:junit4]   2> 7970 T2254 oazs.NIOServerCnxn.finishSessionInit Established session 0x139c8a211f70006 with negotiated timeout 5000 for client /140.211.11.196:63763
[junit4:junit4]   2> 7970 T2321 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:25746, sessionid = 0x139c8a211f70006, negotiated timeout = 5000
[junit4:junit4]   2> 7970 T2322 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7cb5c30a name:ZooKeeperConnection Watcher:127.0.0.1:25746/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 7971 T2250 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 7971 T2255 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c8a211f70006 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7977 T2255 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c8a211f70006 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7988 T2250 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36687_solr
[junit4:junit4]   2> 7989 T2255 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139c8a211f70006 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:36687_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:36687_solr
[junit4:junit4]   2> 7996 T2250 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:36687_solr
[junit4:junit4]   2> 7998 T2308 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 7998 T2284 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 7998 T2296 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 7998 T2270 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 7999 T2250 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 8000 T2250 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 8000 T2250 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 8000 T2250 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 8001 T2250 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 8001 T2250 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 8001 T2250 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 8002 T2250 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 8002 T2250 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 8002 T2250 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 8012 T2250 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 8017 T2250 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1
[junit4:junit4]   2> 8018 T2250 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 8018 T2250 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 8018 T2250 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 8019 T2250 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4]   2> 8020 T2250 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4]   2> 8021 T2250 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 8057 T2250 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 8106 T2250 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 8207 T2250 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 8212 T2250 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 8310 T2271 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8323 T2322 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8323 T2284 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8323 T2296 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8323 T2270 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8323 T2308 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8650 T2250 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 8659 T2250 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 8662 T2250 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 8671 T2250 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 8676 T2250 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 8680 T2250 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 8681 T2250 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 8682 T2250 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty4/
[junit4:junit4]   2> 8682 T2250 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7639fabd
[junit4:junit4]   2> 8683 T2250 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty4/index/
[junit4:junit4]   2> 8684 T2250 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 8685 T2250 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty4/index forceNew:false
[junit4:junit4]   2> 8690 T2250 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-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@1b7b89b9; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 8691 T2250 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 8691 T2250 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 8694 T2250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 8694 T2250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 8694 T2250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 8695 T2250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 8696 T2250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 8696 T2250 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 8696 T2250 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 8697 T2250 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 8698 T2250 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 8698 T2250 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 8699 T2250 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 8699 T2250 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 8700 T2250 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 8700 T2250 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 8701 T2250 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 8701 T2250 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 8702 T2250 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8702 T2250 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8703 T2250 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8703 T2250 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8704 T2250 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8704 T2250 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8705 T2250 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8705 T2250 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 8706 T2250 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 8709 T2250 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 8712 T2250 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 8713 T2250 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> 8716 T2250 oass.SolrIndexSearcher.<init> Opening Searcher@53f7be45 main
[junit4:junit4]   2> 8718 T2250 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 8718 T2250 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 8719 T2250 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 8724 T2250 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 8780 T2323 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@53f7be45 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 8832 T2271 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8842 T2322 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8842 T2284 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8842 T2308 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8842 T2296 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8842 T2270 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9288 T2250 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 9288 T2250 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:36687/solr shardId:shard2
[junit4:junit4]   2> 9291 T2250 oasc.ZkController.register We are http://127.0.0.1:36687/solr/collection1/ and leader is http://127.0.0.1:50781/solr/collection1/
[junit4:junit4]   2> 9292 T2250 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:36687/solr
[junit4:junit4]   2> 9292 T2250 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 9292 T2250 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C194 name=collection1 org.apache.solr.core.SolrCore@62599683 url=http://127.0.0.1:36687/solr/collection1 node=127.0.0.1:36687_solr
[junit4:junit4]   2> 9294 T2324 C194 P36687 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 9294 T2250 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9295 T2324 C194 P36687 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 9295 T2250 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1
[junit4:junit4]   2> 9296 T2250 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 9296 T2324 C194 P36687 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:50781/solr/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 9296 T2250 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 9296 T2324 C194 P36687 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:36687/solr START replicas=[http://127.0.0.1:50781/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 9297 T2324 C194 P36687 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 9298 T2324 C194 P36687 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 9299 T2324 C194 P36687 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 9299 T2324 C194 P36687 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C195 name=collection1 org.apache.solr.core.SolrCore@66fcc15 url=http://127.0.0.1:50781/solr/collection1 node=127.0.0.1:50781_solr
[junit4:junit4]   2> 9306 T2288 C195 P50781 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=0 
[junit4:junit4]   2> 9313 T2250 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:25746/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@34acf078
[junit4:junit4]   2> 9314 T2326 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:25746
[junit4:junit4]   2> 9314 T2250 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 9315 T2326 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:25746, initiating session
[junit4:junit4]   2> 9315 T2252 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:37218
[junit4:junit4]   2> 9315 T2252 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:37218
[junit4:junit4]   2> 9317 T2254 oazs.NIOServerCnxn.finishSessionInit Established session 0x139c8a211f70007 with negotiated timeout 10000 for client /140.211.11.196:37218
[junit4:junit4]   2> 9317 T2326 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:25746, sessionid = 0x139c8a211f70007, negotiated timeout = 10000
[junit4:junit4]   2> 9318 T2327 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@34acf078 name:ZooKeeperConnection Watcher:127.0.0.1:25746/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 9318 T2250 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 9319 T2250 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 9320 T2250 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   2> 9320 T2250 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 9328 T2250 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> ASYNC  NEW_CORE C196 name=collection1 org.apache.solr.core.SolrCore@1d98f986 url=http://127.0.0.1:60384/solr/collection1 node=127.0.0.1:60384_solr
[junit4:junit4]   2> 9338 T2262 C196 P60384 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-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c784399; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 9339 T2262 C196 P60384 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 9343 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[1 (1413156267733549056)]} 0 8
[junit4:junit4]   2> 9344 T2250 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:25746/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@4664ab0a
[junit4:junit4]   2> 9344 T2328 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:25746
[junit4:junit4]   2> 9344 T2250 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 9345 T2328 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:25746, initiating session
[junit4:junit4]   2> 9346 T2252 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:35189
[junit4:junit4]   2> 9346 T2252 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:35189
[junit4:junit4]   2> 9346 T2271 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9347 T2254 oazs.NIOServerCnxn.finishSessionInit Established session 0x139c8a211f70008 with negotiated timeout 10000 for client /140.211.11.196:35189
[junit4:junit4]   2> 9347 T2328 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:25746, sessionid = 0x139c8a211f70008, negotiated timeout = 10000
[junit4:junit4]   2> 9348 T2329 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4664ab0a name:ZooKeeperConnection Watcher:127.0.0.1:25746/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 9348 T2250 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 9349 T2250 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 9358 T2270 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9358 T2322 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9358 T2308 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9358 T2296 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9358 T2327 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9358 T2284 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9358 T2329 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9365 T2278 C193 P37536 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-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@185a9dc8; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 9366 T2278 C193 P37536 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2>  C192_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:39603_solr, base_url=http://127.0.0.1:39603/solr}
[junit4:junit4]   2> 9382 T2300 C192 P39603 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-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty3/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@6eba038; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 9383 T2300 C192 P39603 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 9388 T2300 C192 P39603 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:37536/solr/collection1/&wt=javabin&version=2} status=0 QTime=10 
[junit4:junit4]   2> 9388 T2278 C193 P37536 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=26 
[junit4:junit4]   2> 9389 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[1]} 0 30
[junit4:junit4]   2> 9390 T2250 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):1440
[junit4:junit4]   2> 9390 T2250 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 10392 T2250 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 10882 T2310 C192 P39603 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 10882 T2310 C192 P39603 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=tlog{file=./org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty3/tlog/tlog.0000000000000000000 refcount=1}}
[junit4:junit4]   2> 10883 T2310 C192 P39603 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:37536/solr/collection1/. core=collection1
[junit4:junit4]   2> 10883 T2310 C192 P39603 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 10894 T2279 C193 P37536 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 10954 T2279 C193 P37536 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-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@185a9dc8; 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-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@185a9dc8; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0_Block_0.tip, _0_Block_0.pos, _0.fnm, _0_Block_0.doc, _0_Block_0.tim, _0_Memory_0.ram, _0_MockVariableIntBlock_0.doc, _0_nrm.cfs, _0_MockVariableIntBlock_0.skp, _0_MockVariableIntBlock_0.pyl, _0_Lucene40WithOrds_0.tii, _0_Lucene40WithOrds_0.frq, _0_MockVariableIntBlock_0.tib, _0_MockVariableIntBlock_0.frq, _0_nrm.cfe, _0_MockVariableIntBlock_0.pos, segments_2, _0.fdx, _0_Lucene40WithOrds_0.prx, _0.si, _0_Lucene40WithOrds_0.tib, _0_MockVariableIntBlock_0.tii, _0.fdt]
[junit4:junit4]   2> 10956 T2279 C193 P37536 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 10979 T2279 C193 P37536 oass.SolrIndexSearcher.<init> Opening Searcher@607db378 main
[junit4:junit4]   2> 10981 T2279 C193 P37536 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 10982 T2285 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@607db378 main{StandardDirectoryReader(segments_2:3 _0(5.0):C1)}
[junit4:junit4]   2> 10982 T2279 C193 P37536 /update {waitSearcher=true&commit=true&commit_end_point=true&wt=javabin&softCommit=false&version=2} {commit=} 0 88
[junit4:junit4]   2> 10983 T2310 C192 P39603 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 10983 T2310 C192 P39603 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 10985 T2280 C193 P37536 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 10986 T2280 C193 P37536 REQ /replication {command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
[junit4:junit4]   2> 10986 T2310 C192 P39603 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4]   2> 10986 T2310 C192 P39603 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 10986 T2310 C192 P39603 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 10991 T2280 C193 P37536 REQ /replication {command=filelist&generation=2&wt=javabin&qt=/replication&version=2} status=0 QTime=3 
[junit4:junit4]   2> 10991 T2310 C192 P39603 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 23
[junit4:junit4]   2> 10996 T2310 C192 P39603 oash.SnapPuller.fetchLatestIndex Starting download to ./org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty3/index.20120915023359263 fullCopy=true
[junit4:junit4]   2> 10999 T2280 C193 P37536 REQ /replication {file=_0_Block_0.pos&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11004 T2280 C193 P37536 REQ /replication {file=_0_Block_0.tip&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11008 T2280 C193 P37536 REQ /replication {file=_0_Block_0.doc&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11012 T2280 C193 P37536 REQ /replication {file=_0.fnm&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11016 T2280 C193 P37536 REQ /replication {file=_0_MockVariableIntBlock_0.doc&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11020 T2280 C193 P37536 REQ /replication {file=_0_Memory_0.ram&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11024 T2280 C193 P37536 REQ /replication {file=_0_Block_0.tim&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11028 T2280 C193 P37536 REQ /replication {file=_0_MockVariableIntBlock_0.skp&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11029 T2310 C192 P39603 oash.SnapPuller$FileFetcher.fetchPackets WARNING No content recieved for file: {name=_0_MockVariableIntBlock_0.skp, lastmodified=1347690839000, size=0}
[junit4:junit4]   2> 11033 T2280 C193 P37536 REQ /replication {file=_0_nrm.cfs&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11060 T2280 C193 P37536 REQ /replication {file=_0_MockVariableIntBlock_0.pyl&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11062 T2310 C192 P39603 oash.SnapPuller$FileFetcher.fetchPackets WARNING No content recieved for file: {name=_0_MockVariableIntBlock_0.pyl, lastmodified=1347690839000, size=0}
[junit4:junit4]   2> 11065 T2280 C193 P37536 REQ /replication {file=_0_Lucene40WithOrds_0.tii&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11069 T2280 C193 P37536 REQ /replication {file=_0_Lucene40WithOrds_0.frq&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11074 T2280 C193 P37536 REQ /replication {file=_0_MockVariableIntBlock_0.tib&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11078 T2280 C193 P37536 REQ /replication {file=_0_nrm.cfe&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11082 T2280 C193 P37536 REQ /replication {file=_0_MockVariableIntBlock_0.frq&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11086 T2280 C193 P37536 REQ /replication {file=segments_2&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11090 T2280 C193 P37536 REQ /replication {file=_0_MockVariableIntBlock_0.pos&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11094 T2280 C193 P37536 REQ /replication {file=_0.fdx&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11099 T2280 C193 P37536 REQ /replication {file=_0_Lucene40WithOrds_0.prx&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11103 T2280 C193 P37536 REQ /replication {file=_0.si&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11121 T2280 C193 P37536 REQ /replication {file=_0_Lucene40WithOrds_0.tib&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11125 T2280 C193 P37536 REQ /replication {file=_0.fdt&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11129 T2280 C193 P37536 REQ /replication {file=_0_MockVariableIntBlock_0.tii&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11130 T2310 C192 P39603 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 11138 T2310 C192 P39603 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20120915023359263
[junit4:junit4]   2> 11139 T2310 C192 P39603 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 11139 T2310 C192 P39603 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 11140 T2310 C192 P39603 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4]   2> 11144 T2310 C192 P39603 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=./org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty3/index/ new=./org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty3/index.20120915023359263
[junit4:junit4]   2> 11145 T2310 C192 P39603 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty3/index.20120915023359263 forceNew:true
[junit4:junit4]   2> 11155 T2310 C192 P39603 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-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty3/index.20120915023359263 lockFactory=org.apache.lucene.store.NativeFSLockFactory@41c20ff8; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0_Block_0.tip, _0_Block_0.pos, _0.fnm, _0_Block_0.doc, _0_Block_0.tim, _0_Memory_0.ram, _0_MockVariableIntBlock_0.doc, _0_nrm.cfs, _0_MockVariableIntBlock_0.skp, _0_MockVariableIntBlock_0.pyl, _0_Lucene40WithOrds_0.tii, _0_Lucene40WithOrds_0.frq, _0_MockVariableIntBlock_0.tib, _0_nrm.cfe, _0_MockVariableIntBlock_0.frq, _0_MockVariableIntBlock_0.pos, segments_2, _0.fdx, _0_Lucene40WithOrds_0.prx, _0.si, _0_Lucene40WithOrds_0.tib, _0.fdt, _0_MockVariableIntBlock_0.tii]
[junit4:junit4]   2> 11156 T2310 C192 P39603 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 11156 T2310 C192 P39603 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 11160 T2310 C192 P39603 oass.SolrIndexSearcher.<init> Opening Searcher@61737aac main
[junit4:junit4]   2> 11162 T2309 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@61737aac main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C1)}
[junit4:junit4]   2> 11162 T2309 oasc.CachingDirectoryFactory.close Closing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty3/index
[junit4:junit4]   2> 11163 T2309 oash.SnapPuller$2.onClose removing old index directory ./org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty3/index
[junit4:junit4]   2> 11165 T2310 C192 P39603 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 11166 T2310 C192 P39603 oass.SolrIndexSearcher.<init> Opening Searcher@401afd32 main
[junit4:junit4]   2> 11166 T2310 C192 P39603 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 11168 T2309 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@401afd32 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C1)}
[junit4:junit4]   2> 11168 T2310 C192 P39603 oasc.RecoveryStrategy.replay Replaying buffered documents. core=collection1
[junit4:junit4]   2> 11168 T2333 C192 P39603 oasu.UpdateLog$LogReplayer.doReplay WARNING Starting log replay tlog{file=./org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty3/tlog/tlog.0000000000000000000 refcount=2} active=true starting pos=431
[junit4:junit4]   2> 11169 T2333 C192 P39603 oasu.DirectUpdateHandler2.commit start commit{flags=2,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 11170 T2333 C192 P39603 oass.SolrIndexSearcher.<init> Opening Searcher@2ecd104 main
[junit4:junit4]   2> 11171 T2333 C192 P39603 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 11172 T2309 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2ecd104 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C1)}
[junit4:junit4]   2> 11173 T2333 C192 P39603 oasu.UpdateLog$LogReplayer.run WARNING Log replay finished. recoveryInfo=RecoveryInfo{adds=0 deletes=0 deleteByQuery=0 errors=0 positionOfStart=431}
[junit4:junit4]   2> 11173 T2310 C192 P39603 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 11174 T2310 C192 P39603 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 11367 T2271 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 11370 T2284 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11370 T2270 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11370 T2308 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11370 T2296 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11371 T2329 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11370 T2322 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11370 T2327 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11394 T2250 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2>  C194_STATE=coll:collection1 core:collection1 props:{shard=shard2, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:36687_solr, base_url=http://127.0.0.1:36687/solr}
[junit4:junit4]   2> 12318 T2324 C194 P36687 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 12318 T2324 C194 P36687 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 12318 T2324 C194 P36687 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:50781/solr/collection1/. core=collection1
[junit4:junit4]   2> 12318 T2324 C194 P36687 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 12330 T2291 C195 P50781 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 12333 T2291 C195 P50781 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-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@5bb53a9e; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 12334 T2291 C195 P50781 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 12335 T2291 C195 P50781 oass.SolrIndexSearcher.<init> Opening Searcher@5916d3c3 main
[junit4:junit4]   2> 12335 T2291 C195 P50781 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 12337 T2297 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5916d3c3 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 12337 T2291 C195 P50781 /update {waitSearcher=true&commit=true&commit_end_point=true&wt=javabin&softCommit=false&version=2} {commit=} 0 7
[junit4:junit4]   2> 12338 T2324 C194 P36687 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 12338 T2324 C194 P36687 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 12340 T2292 C195 P50781 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 12341 T2292 C195 P50781 REQ /replication {command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
[junit4:junit4]   2> 12344 T2324 C194 P36687 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-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@1b7b89b9; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 12344 T2324 C194 P36687 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 12345 T2324 C194 P36687 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 12347 T2324 C194 P36687 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-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@1b7b89b9; 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-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@1b7b89b9; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 12348 T2324 C194 P36687 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 12350 T2324 C194 P36687 oass.SolrIndexSearcher.<init> Opening Searcher@4277d18b main
[junit4:junit4]   2> 12350 T2324 C194 P36687 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 12351 T2323 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4277d18b main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 12352 T2324 C194 P36687 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 12352 T2324 C194 P36687 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 12366 T2324 C194 P36687 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 12376 T2271 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12379 T2308 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12379 T2327 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12379 T2296 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12379 T2322 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12379 T2270 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12379 T2329 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12379 T2284 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 12396 T2250 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12399 T2262 C196 P60384 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 12425 T2262 C196 P60384 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-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c784399; 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-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c784399; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0_Block_0.tip, _0_Block_0.pos, _0.fnm, _0_Block_0.doc, _0_Block_0.tim, _0_Memory_0.ram, _0_MockVariableIntBlock_0.doc, _0_nrm.cfs, _0_MockVariableIntBlock_0.skp, _0_MockVariableIntBlock_0.pyl, _0_Lucene40WithOrds_0.tii, _0_Lucene40WithOrds_0.frq, _0_MockVariableIntBlock_0.tib, _0_MockVariableIntBlock_0.frq, _0_nrm.cfe, _0_MockVariableIntBlock_0.pos, segments_2, _0.fdx, _0_Lucene40WithOrds_0.prx, _0.si, _0_Lucene40WithOrds_0.tib, _0_MockVariableIntBlock_0.tii, _0.fdt]
[junit4:junit4]   2> 12425 T2262 C196 P60384 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 12436 T2262 C196 P60384 oass.SolrIndexSearcher.<init> Opening Searcher@22c2cece main
[junit4:junit4]   2> 12436 T2262 C196 P60384 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 12438 T2273 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@22c2cece main{StandardDirectoryReader(segments_2:3 _0(5.0):C1)}
[junit4:junit4]   2> 12438 T2262 C196 P60384 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 39
[junit4:junit4]   2> 12441 T2281 C193 P37536 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 12447 T2281 C193 P37536 oass.SolrIndexSearcher.<init> Opening Searcher@761adf86 main
[junit4:junit4]   2> 12447 T2281 C193 P37536 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 12449 T2285 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@761adf86 main{StandardDirectoryReader(segments_2:3 _0(5.0):C1)}
[junit4:junit4]   2> 12450 T2281 C193 P37536 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:39603/solr/collection1/, StdNode: http://127.0.0.1:50781/solr/collection1/, StdNode: http://127.0.0.1:36687/solr/collection1/]
[junit4:junit4]   2> 12452 T2293 C195 P50781 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2>  C192_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:39603_solr, base_url=http://127.0.0.1:39603/solr}
[junit4:junit4]   2> 12453 T2300 C192 P39603 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 12455 T2293 C195 P50781 oass.SolrIndexSearcher.<init> Opening Searcher@37a78ef7 main
[junit4:junit4]   2> 12455 T2293 C195 P50781 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 12455 T2300 C192 P39603 oass.SolrIndexSearcher.<init> Opening Searcher@54eda429 main
[junit4:junit4]   2> 12456 T2300 C192 P39603 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 12457 T2297 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@37a78ef7 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 12457 T2309 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@54eda429 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C1)}
[junit4:junit4]   2> 12457 T2293 C195 P50781 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&expungeDeletes=false&softCommit=false&version=2} {commit=} 0 5
[junit4:junit4]   2> 12457 T2300 C192 P39603 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&expungeDeletes=false&softCommit=false&version=2} {commit=} 0 4
[junit4:junit4]   2>  C194_STATE=coll:collection1 core:collection1 props:{shard=shard2, roles=null, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:36687_solr, base_url=http://127.0.0.1:36687/solr}
[junit4:junit4]   2> 12459 T2314 C194 P36687 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 12461 T2314 C194 P36687 oass.SolrIndexSearcher.<init> Opening Searcher@76e2f3c2 main
[junit4:junit4]   2> 12461 T2314 C194 P36687 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 12463 T2323 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@76e2f3c2 main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 12463 T2314 C194 P36687 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&expungeDeletes=false&softCommit=false&version=2} {commit=} 0 4
[junit4:junit4]   2> 12464 T2281 C193 P37536 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 23
[junit4:junit4]   2> 12469 T2263 C196 P60384 REQ /select {fl=id,score&shard.url=127.0.0.1:60384/solr/collection1/&NOW=1347690840737&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 12472 T2263 C196 P60384 REQ /select {shard.url=127.0.0.1:60384/solr/collection1/&NOW=1347690840737&q=*:*&ids=1&distrib=false&isShard=true&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 12473 T2262 C196 P60384 REQ /select {wt=javabin&q=*:*&version=2} hits=1 status=0 QTime=7 
[junit4:junit4]   2> 12474 T2250 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:25746/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@7e34d0ff
[junit4:junit4]   2> 12475 T2337 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:25746
[junit4:junit4]   2> 12475 T2250 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 12475 T2337 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:25746, initiating session
[junit4:junit4]   2> 12476 T2252 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:56262
[junit4:junit4]   2> 12476 T2252 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:56262
[junit4:junit4]   2> 12478 T2337 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:25746, sessionid = 0x139c8a211f70009, negotiated timeout = 10000
[junit4:junit4]   2> 12478 T2254 oazs.NIOServerCnxn.finishSessionInit Established session 0x139c8a211f70009 with negotiated timeout 10000 for client /140.211.11.196:56262
[junit4:junit4]   2> 12478 T2338 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7e34d0ff name:ZooKeeperConnection Watcher:127.0.0.1:25746/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 12478 T2250 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 12479 T2250 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 12480 T2255 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x139c8a211f70009
[junit4:junit4]   2> 12481 T2338 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 12481 T2252 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:56262 which had sessionid 0x139c8a211f70009
[junit4:junit4]   2> 12481 T2250 oaz.ZooKeeper.close Session: 0x139c8a211f70009 closed
[junit4:junit4]   2> 12483 T2282 C193 P37536 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 12486 T2294 C195 P50781 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 12492 T2289 C195 P50781 REQ /select {fl=id,score&shard.url=127.0.0.1:50781/solr/collection1/|127.0.0.1:36687/solr/collection1/&NOW=1347690840760&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 12492 T2277 C193 P37536 REQ /select {fl=id,score&shard.url=127.0.0.1:37536/solr/collection1/|127.0.0.1:39603/solr/collection1/&NOW=1347690840760&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 12495 T2277 C193 P37536 REQ /select {shard.url=127.0.0.1:37536/solr/collection1/|127.0.0.1:39603/solr/collection1/&NOW=1347690840760&q=*:*&ids=1&distrib=false&isShard=true&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 12497 T2315 C194 P36687 REQ /select {wt=javabin&q=*:*&version=2} hits=1 status=0 QTime=7 
[junit4:junit4]   2> 12503 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[2 (1413156271051243520)]} 0 4
[junit4:junit4]   2> 12517 T2314 C194 P36687 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 12517 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[2 (1413156271058583552)]} 0 11
[junit4:junit4]   2> 12521 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[3 (1413156271073263616)]} 0 1
[junit4:junit4]   2> 12532 T2314 C194 P36687 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:50781/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 12533 T2293 C195 P50781 REQ /update {distrib.from=http://127.0.0.1:37536/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 12533 T2281 C193 P37536 /update {wt=javabin&version=2} {add=[3]} 0 9
[junit4:junit4]   2> 12537 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[4 (1413156271090040832)]} 0 1
[junit4:junit4]   2> 12549 T2300 C192 P39603 REQ /update {distrib.from=http://127.0.0.1:37536/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 12549 T2281 C193 P37536 /update {wt=javabin&version=2} {add=[4 (1413156271094235136)]} 0 9
[junit4:junit4]   2> 12553 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[5 (1413156271106818048)]} 0 1
[junit4:junit4]   2> 12562 T2314 C194 P36687 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 12563 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[5 (1413156271111012352)]} 0 7
[junit4:junit4]   2> 12567 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[6 (1413156271121498112)]} 0 1
[junit4:junit4]   2> 12577 T2314 C194 P36687 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:50781/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 12578 T2293 C195 P50781 REQ /update {distrib.from=http://127.0.0.1:37536/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 12579 T2281 C193 P37536 /update {wt=javabin&version=2} {add=[6]} 0 9
[junit4:junit4]   2> 12582 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[7 (1413156271137226752)]} 0 1
[junit4:junit4]   2> 12592 T2314 C194 P36687 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:50781/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 12593 T2293 C195 P50781 REQ /update {distrib.from=http://127.0.0.1:37536/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 12593 T2281 C193 P37536 /update {wt=javabin&version=2} {add=[7]} 0 8
[junit4:junit4]   2> 12597 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[8 (1413156271152955392)]} 0 1
[junit4:junit4]   2> 12605 T2300 C192 P39603 REQ /update {distrib.from=http://127.0.0.1:37536/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 12606 T2281 C193 P37536 /update {wt=javabin&version=2} {add=[8 (1413156271157149696)]} 0 6
[junit4:junit4]   2> 12609 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[9 (1413156271165538304)]} 0 1
[junit4:junit4]   2> 12619 T2314 C194 P36687 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 12620 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[9 (1413156271170781184)]} 0 8
[junit4:junit4]   2> 12624 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[10 (1413156271181266944)]} 0 1
[junit4:junit4]   2> 12634 T2300 C192 P39603 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:37536/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 12634 T2278 C193 P37536 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 12635 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[10]} 0 8
[junit4:junit4]   2> 12647 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[11 (1413156271196995584)]} 0 9
[junit4:junit4]   2> 12658 T2300 C192 P39603 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:37536/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 12659 T2278 C193 P37536 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 12659 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[11]} 0 9
[junit4:junit4]   2> 12664 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[12 (1413156271222161408)]} 0 2
[junit4:junit4]   2> 12674 T2300 C192 P39603 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:37536/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 12675 T2278 C193 P37536 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 12675 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[12]} 0 8
[junit4:junit4]   2> 12679 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[13 (1413156271238938624)]} 0 1
[junit4:junit4]   2> 12688 T2300 C192 P39603 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:37536/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 12688 T2278 C193 P37536 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 12689 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[13]} 0 7
[junit4:junit4]   2> 12693 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[14 (1413156271253618688)]} 0 1
[junit4:junit4]   2> 12700 T2300 C192 P39603 REQ /update {distrib.from=http://127.0.0.1:37536/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 12700 T2281 C193 P37536 /update {wt=javabin&version=2} {add=[14 (1413156271256764416)]} 0 5
[junit4:junit4]   2> 12704 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[15 (1413156271265153024)]} 0 1
[junit4:junit4]   2> 12711 T2300 C192 P39603 REQ /update {distrib.from=http://127.0.0.1:37536/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 12711 T2281 C193 P37536 /update {wt=javabin&version=2} {add=[15 (1413156271268298752)]} 0 5
[junit4:junit4]   2> 12715 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[16 (1413156271276687360)]} 0 1
[junit4:junit4]   2> 12724 T2300 C192 P39603 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:37536/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 12725 T2278 C193 P37536 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 12725 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[16]} 0 8
[junit4:junit4]   2> 12731 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[17 (1413156271291367424)]} 0 3
[junit4:junit4]   2> 12746 T2314 C194 P36687 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:50781/solr/collection1/&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 12746 T2293 C195 P50781 REQ /update {distrib.from=http://127.0.0.1:37536/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=10 
[junit4:junit4]   2> 12747 T2281 C193 P37536 /update {wt=javabin&version=2} {add=[17]} 0 14
[junit4:junit4]   2> 12751 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[100 (1413156271314436096)]} 0 1
[junit4:junit4]   2> 12774 T2300 C192 P39603 REQ /update {distrib.from=http://127.0.0.1:37536/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=9 
[junit4:junit4]   2> 12775 T2281 C193 P37536 /update {wt=javabin&version=2} {add=[100 (1413156271317581824)]} 0 22
[junit4:junit4]   2> 12779 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[101 (1413156271342747648)]} 0 2
[junit4:junit4]   2> 12789 T2300 C192 P39603 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:37536/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 12789 T2278 C193 P37536 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 12789 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[101]} 0 8
[junit4:junit4]   2> 12793 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[102 (1413156271358476288)]} 0 1
[junit4:junit4]   2> 12801 T2300 C192 P39603 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:37536/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 12801 T2278 C193 P37536 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 12802 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[102]} 0 7
[junit4:junit4]   2> 12821 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[103 (1413156271373156352)]} 0 16
[junit4:junit4]   2> 12831 T2314 C194 P36687 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:50781/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 12832 T2293 C195 P50781 REQ /update {distrib.from=http://127.0.0.1:37536/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 12832 T2281 C193 P37536 /update {wt=javabin&version=2} {add=[103]} 0 8
[junit4:junit4]   2> 12837 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[104 (1413156271403565056)]} 0 2
[junit4:junit4]   2> 12845 T2314 C194 P36687 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:50781/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 12845 T2293 C195 P50781 REQ /update {distrib.from=http://127.0.0.1:37536/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 12846 T2281 C193 P37536 /update {wt=javabin&version=2} {add=[104]} 0 7
[junit4:junit4]   2> 12850 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[105 (1413156271418245120)]} 0 1
[junit4:junit4]   2> 12875 T2314 C194 P36687 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:50781/solr/collection1/&wt=javabin&version=2} status=0 QTime=9 
[junit4:junit4]   2> 12876 T2293 C195 P50781 REQ /update {distrib.from=http://127.0.0.1:37536/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=21 
[junit4:junit4]   2> 12877 T2281 C193 P37536 /update {wt=javabin&version=2} {add=[105]} 0 24
[junit4:junit4]   2> 12882 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[106 (1413156271450750976)]} 0 2
[junit4:junit4]   2> 12891 T2314 C194 P36687 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 12892 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[106 (1413156271454945280)]} 0 8
[junit4:junit4]   2> 12895 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[107 (1413156271465431040)]} 0 1
[junit4:junit4]   2> 12904 T2300 C192 P39603 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:37536/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 12904 T2278 C193 P37536 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 12905 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[107]} 0 7
[junit4:junit4]   2> 12908 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[108 (1413156271479062528)]} 0 1
[junit4:junit4]   2> 12915 T2300 C192 P39603 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:37536/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 12915 T2278 C193 P37536 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 12916 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[108]} 0 6
[junit4:junit4]   2> 12919 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[109 (1413156271490596864)]} 0 1
[junit4:junit4]   2> 12925 T2300 C192 P39603 REQ /update {distrib.from=http://127.0.0.1:37536/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 12925 T2281 C193 P37536 /update {wt=javabin&version=2} {add=[109 (1413156271493742592)]} 0 4
[junit4:junit4]   2> 12929 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[110 (1413156271501082624)]} 0 1
[junit4:junit4]   2> 12935 T2300 C192 P39603 REQ /update {distrib.from=http://127.0.0.1:37536/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 12936 T2281 C193 P37536 /update {wt=javabin&version=2} {add=[110 (1413156271504228352)]} 0 4
[junit4:junit4]   2> 12939 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[111 (1413156271511568384)]} 0 1
[junit4:junit4]   2> 12947 T2300 C192 P39603 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:37536/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 12948 T2278 C193 P37536 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 12948 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[111]} 0 7
[junit4:junit4]   2> 12952 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[112 (1413156271525199872)]} 0 1
[junit4:junit4]   2> 12959 T2314 C194 P36687 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 12959 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[112 (1413156271529394176)]} 0 4
[junit4:junit4]   2> 12970 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[113 (1413156271536734208)]} 0 8
[junit4:junit4]   2> 12979 T2300 C192 P39603 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:37536/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 12979 T2278 C193 P37536 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 12980 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[113]} 0 7
[junit4:junit4]   2> 12983 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[114 (1413156271557705728)]} 0 1
[junit4:junit4]   2> 12990 T2300 C192 P39603 REQ /update {distrib.from=http://127.0.0.1:37536/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 12990 T2281 C193 P37536 /update {wt=javabin&version=2} {add=[114 (1413156271561900032)]} 0 4
[junit4:junit4]   2> 12994 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[115 (1413156271569240064)]} 0 1
[junit4:junit4]   2> 13000 T2314 C194 P36687 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 13000 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[115 (1413156271572385792)]} 0 4
[junit4:junit4]   2> 13004 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[116 (1413156271579725824)]} 0 1
[junit4:junit4]   2> 13010 T2314 C194 P36687 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 13010 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[116 (1413156271582871552)]} 0 4
[junit4:junit4]   2> 13012 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[117 (1413156271589163008)]} 0 0
[junit4:junit4]   2> 13019 T2314 C194 P36687 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 13019 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[117 (1413156271592308736)]} 0 4
[junit4:junit4]   2> 13022 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[118 (1413156271599648768)]} 0 0
[junit4:junit4]   2> 13043 T2300 C192 P39603 REQ /update {distrib.from=http://127.0.0.1:37536/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=8 
[junit4:junit4]   2> 13043 T2281 C193 P37536 /update {wt=javabin&version=2} {add=[118 (1413156271602794496)]} 0 18
[junit4:junit4]   2> 13047 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[119 (1413156271624814592)]} 0 1
[junit4:junit4]   2> 13053 T2314 C194 P36687 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 13053 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[119 (1413156271627960320)]} 0 4
[junit4:junit4]   2> 13057 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[120 (1413156271635300352)]} 0 1
[junit4:junit4]   2> 13063 T2314 C194 P36687 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 13063 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[120 (1413156271638446080)]} 0 4
[junit4:junit4]   2> 13065 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[121 (1413156271644737536)]} 0 0
[junit4:junit4]   2> 13074 T2314 C194 P36687 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:50781/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 13074 T2293 C195 P50781 REQ /update {distrib.from=http://127.0.0.1:37536/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 13075 T2281 C193 P37536 /update {wt=javabin&version=2} {add=[121]} 0 7
[junit4:junit4]   2> 13078 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[122 (1413156271657320448)]} 0 1
[junit4:junit4]   2> 13084 T2300 C192 P39603 REQ /update {distrib.from=http://127.0.0.1:37536/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 13085 T2281 C193 P37536 /update {wt=javabin&version=2} {add=[122 (1413156271660466176)]} 0 5
[junit4:junit4]   2> 13095 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[123 (1413156271667806208)]} 0 8
[junit4:junit4]   2> 13102 T2300 C192 P39603 REQ /update {distrib.from=http://127.0.0.1:37536/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 13102 T2281 C193 P37536 /update {wt=javabin&version=2} {add=[123 (1413156271679340544)]} 0 4
[junit4:junit4]   2> 13106 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[124 (1413156271686680576)]} 0 1
[junit4:junit4]   2> 13113 T2300 C192 P39603 REQ /update {distrib.from=http://127.0.0.1:37536/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 13113 T2281 C193 P37536 /update {wt=javabin&version=2} {add=[124 (1413156271690874880)]} 0 4
[junit4:junit4]   2> 13117 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[125 (1413156271698214912)]} 0 1
[junit4:junit4]   2> 13125 T2300 C192 P39603 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:37536/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 13125 T2278 C193 P37536 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 13126 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[125]} 0 7
[junit4:junit4]   2> 13129 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[126 (1413156271710797824)]} 0 1
[junit4:junit4]   2> 13135 T2314 C194 P36687 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 13135 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[126 (1413156271713943552)]} 0 4
[junit4:junit4]   2> 13139 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[127 (1413156271721283584)]} 0 1
[junit4:junit4]   2> 13165 T2314 C194 P36687 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:50781/solr/collection1/&wt=javabin&version=2} status=0 QTime=8 
[junit4:junit4]   2> 13165 T2293 C195 P50781 REQ /update {distrib.from=http://127.0.0.1:37536/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=22 
[junit4:junit4]   2> 13166 T2281 C193 P37536 /update {wt=javabin&version=2} {add=[127]} 0 25
[junit4:junit4]   2> 13170 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[128 (1413156271753789440)]} 0 1
[junit4:junit4]   2> 13180 T2314 C194 P36687 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:50781/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 13181 T2293 C195 P50781 REQ /update {distrib.from=http://127.0.0.1:37536/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 13181 T2281 C193 P37536 /update {wt=javabin&version=2} {add=[128]} 0 9
[junit4:junit4]   2> 13185 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[129 (1413156271769518080)]} 0 1
[junit4:junit4]   2> 13191 T2300 C192 P39603 REQ /update {distrib.from=http://127.0.0.1:37536/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 13191 T2281 C193 P37536 /update {wt=javabin&version=2} {add=[129 (1413156271772663808)]} 0 4
[junit4:junit4]   2> 13194 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[130 (1413156271778955264)]} 0 1
[junit4:junit4]   2> 13200 T2314 C194 P36687 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 13201 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[130 (1413156271782100992)]} 0 5
[junit4:junit4]   2> 13204 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[131 (1413156271789441024)]} 0 1
[junit4:junit4]   2> 13212 T2314 C194 P36687 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:50781/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 13212 T2293 C195 P50781 REQ /update {distrib.from=http://127.0.0.1:37536/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 13213 T2281 C193 P37536 /update {wt=javabin&version=2} {add=[131]} 0 7
[junit4:junit4]   2> 13216 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[132 (1413156271802023936)]} 0 1
[junit4:junit4]   2> 13224 T2300 C192 P39603 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:37536/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 13224 T2278 C193 P37536 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 13224 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[132]} 0 6
[junit4:junit4]   2> 13235 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[133 (1413156271814606848)]} 0 8
[junit4:junit4]   2> 13242 T2300 C192 P39603 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:37536/solr/collection1/&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 13243 T2278 C193 P37536 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 13243 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[133]} 0 6
[junit4:junit4]   2> 13247 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[134 (1413156271834529792)]} 0 1
[junit4:junit4]   2> 13256 T2314 C194 P36687 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:50781/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 13256 T2293 C195 P50781 REQ /update {distrib.from=http://127.0.0.1:37536/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 13257 T2281 C193 P37536 /update {wt=javabin&version=2} {add=[134]} 0 7
[junit4:junit4]   2> 13259 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[135 (1413156271848161280)]} 0 0
[junit4:junit4]   2> 13265 T2300 C192 P39603 REQ /update {distrib.from=http://127.0.0.1:37536/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 13266 T2281 C193 P37536 /update {wt=javabin&version=2} {add=[135 (1413156271851307008)]} 0 4
[junit4:junit4]   2> 13268 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[136 (1413156271857598464)]} 0 0
[junit4:junit4]   2> 13277 T2314 C194 P36687 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:50781/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 13277 T2293 C195 P50781 REQ /update {distrib.from=http://127.0.0.1:37536/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 13278 T2281 C193 P37536 /update {wt=javabin&version=2} {add=[136]} 0 7
[junit4:junit4]   2> 13280 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[137 (1413156271870181376)]} 0 0
[junit4:junit4]   2> 13287 T2314 C194 P36687 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 13287 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[137 (1413156271873327104)]} 0 4
[junit4:junit4]   2> 13291 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[138 (1413156271880667136)]} 0 1
[junit4:junit4]   2> 13299 T2300 C192 P39603 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:37536/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 13299 T2278 C193 P37536 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 13300 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[138]} 0 7
[junit4:junit4]   2> 13303 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[139 (1413156271893250048)]} 0 1
[junit4:junit4]   2> 13308 T2314 C194 P36687 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 13309 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[139 (1413156271896395776)]} 0 4
[junit4:junit4]   2> 13312 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[140 (1413156271902687232)]} 0 1
[junit4:junit4]   2> 13319 T2314 C194 P36687 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:50781/solr/collection1/&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 13320 T2293 C195 P50781 REQ /update {distrib.from=http://127.0.0.1:37536/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 13320 T2281 C193 P37536 /update {wt=javabin&version=2} {add=[140]} 0 6
[junit4:junit4]   2> 13324 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[141 (1413156271915270144)]} 0 1
[junit4:junit4]   2> 13330 T2314 C194 P36687 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 13331 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[141 (1413156271919464448)]} 0 4
[junit4:junit4]   2> 13334 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[142 (1413156271925755904)]} 0 1
[junit4:junit4]   2> 13354 T2314 C194 P36687 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=8 
[junit4:junit4]   2> 13354 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[142 (1413156271928901632)]} 0 18
[junit4:junit4]   2> 13365 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[143 (1413156271950921728)]} 0 8
[junit4:junit4]   2> 13374 T2314 C194 P36687 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 13374 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[143 (1413156271962456064)]} 0 6
[junit4:junit4]   2> 13379 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[144 (1413156271971893248)]} 0 2
[junit4:junit4]   2> 13387 T2314 C194 P36687 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:50781/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 13387 T2293 C195 P50781 REQ /update {distrib.from=http://127.0.0.1:37536/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 13387 T2281 C193 P37536 /update {wt=javabin&version=2} {add=[144]} 0 6
[junit4:junit4]   2> 13391 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[145 (1413156271985524736)]} 0 1
[junit4:junit4]   2> 13400 T2314 C194 P36687 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:50781/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 13400 T2293 C195 P50781 REQ /update {distrib.from=http://127.0.0.1:37536/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 13401 T2281 C193 P37536 /update {wt=javabin&version=2} {add=[145]} 0 7
[junit4:junit4]   2> 13404 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[146 (1413156271999156224)]} 0 1
[junit4:junit4]   2> 13425 T2300 C192 P39603 REQ /update {distrib.from=http://127.0.0.1:37536/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=8 
[junit4:junit4]   2> 13425 T2281 C193 P37536 /update {wt=javabin&version=2} {add=[146 (1413156272003350528)]} 0 18
[junit4:junit4]   2> 13429 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[147 (1413156272025370624)]} 0 1
[junit4:junit4]   2> 13438 T2314 C194 P36687 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:50781/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 13438 T2293 C195 P50781 REQ /update {distrib.from=http://127.0.0.1:37536/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 13439 T2281 C193 P37536 /update {wt=javabin&version=2} {add=[147]} 0 7
[junit4:junit4]   2> 13442 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[148 (1413156272039002112)]} 0 1
[junit4:junit4]   2> 13450 T2300 C192 P39603 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:37536/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 13451 T2278 C193 P37536 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 13451 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[148]} 0 7
[junit4:junit4]   2> 13455 T2262 C196 P60384 /update {wt=javabin&version=2} {add=[149 (1413156272052633600)]} 0 1
[junit4:junit4]   2> 13461 T2314 C194 P36687 REQ /update {distrib.from=http://127.0.0.1:50781/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=0 
[junit4:junit4]   2> 13461 T2290 C195 P50781 /update {wt=javabin&version=2} {add=[149 (1413156272055779328)]} 0 4
[junit4:junit4]   2> 13461 T2250 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):1440
[junit4:junit4]   2> 13462 T2250 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 13465 T2262 C196 P60384 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 13754 T2262 C196 P60384 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-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c784399; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[_0_Block_0.tip, _0_Block_0.pos, _0.fnm, _0_Block_0.doc, _0_Block_0.tim, _0_Memory_0.ram, _0_MockVariableIntBlock_0.doc, _0_nrm.cfs, _0_MockVariableIntBlock_0.skp, _0_MockVariableIntBlock_0.pyl, _0_Lucene40WithOrds_0.tii, _0_Lucene40WithOrds_0.frq, _0_MockVariableIntBlock_0.tib, _0_MockVariableIntBlock_0.frq, _0_nrm.cfe, _0_MockVariableIntBlock_0.pos, segments_2, _0.fdx, _0_Lucene40WithOrds_0.prx, _0.si, _0_Lucene40WithOrds_0.tib, _0_MockVariableIntBlock_0.tii, _0.fdt]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347690828274/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c784399; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_3,generation=3,filenames=[_5_nrm.cfe, _5_Memory_0.ram, _2_Block_0.pos, _3_MockVariableIntBlock_0.frq, _7.si, _3.fdt, _5_Lucene40WithOrds_0.tib, _4_MockVariableIntBlock_0.tii, _7_Memory_0.ram, _7.fnm, _6_Block_0.pos, _0_Lucene40WithOrds_0.tii, _5_Lucene40WithOrds_0.tii, _0_Lucene40WithOrds_0.frq, _1_Lucene40WithOrds_0.tib, _7_Lucene40WithOrds_0.frq, _5_MockVariableIntBlock_0.tii, _1_Lucene40WithOrds_0.tii, _0_Lucene40WithOrds_0.tib, _6_MockVariableIntBlock_0.tii, _1_Block_0.pos, _1_Block_0.tip, _1_Lucene40WithOrds_0.frq, _6_MockVariableIntBlock_0.tib, _1_Block_0.tim, _1_MockVariableIntBlock_0.tii, _0_Memory_0.ram, _4_MockVariableIntBlock_0.doc, _2.fdt, _7.fdx, _7_MockVariableIntBlock_0.frq, _2.fdx, _7.fdt, _1_MockVariableIntBlock_0.tib, _3_Block_0.pos, _3_Block_0.doc, _1.fdx, _4_MockVariableIntBlock_0.tib, _5_nrm.cfs, _1.fdt, _0_MockVariableIntBlock_0.frq, _7_Block_0.pos, _3.si, _6.fdt, _2_MockVariableIntBlock_0.skp, _5_Lucene40WithOrds_0.prx, _6_Memory_0.ram, _2.si, _1_MockVariableIntBlock_0.skp, _7_MockVariableIntBlock_0.pos, _4_Lucene40WithOrds_0.tib, _2_Block_0.tim, _2_MockVariableIntBlock_0.pyl, _4_Lucene40WithOrds_0.tii, _0_MockVariableIntBlock_0.doc, _6.fdx, _2_Block_0.tip, _1_Lucene40WithOrds_0.prx, _1_MockVariableIntBlock_0.pyl, _3.fnm, _5_Block_0.tim, _2_MockVariableIntBlock_0.doc, _3_MockVariableIntBlock_0.tii, _0_MockVariableIntBlock_0.pyl, _1_Memory_0.ram, _2_nrm.cfe, _1_MockVariableIntBlock_0.doc, _0_MockVariableIntBlock_0.pos, _7_MockVariableIntBlock_0.skp, _2_nrm.cfs, _5_Block_0.doc, _4_Block_0.pos, _3_Block_0.tip, _7_MockVariableIntBlock_0.pyl, _2_MockVariableIntBlock_0.tii, _4_Block_0.tip, _5_MockVariableIntBlock_0.tib, _2_Lucene40WithOrds_0.frq, _2_MockVariableIntBlock_0.tib, _1_MockVariableIntBlock_0.pos, _4_MockVariableIntBlock_0.frq, _5_MockVariableIntBlock_0.frq, _2.fnm, _3.fdx, _1.si, _3_MockVariableIntBlock_0.pyl, _6.si, _6.fnm, _0_Lucene40WithOrds_0.prx, _7_MockVariableIntBlock_0.tib, _3_Lucene40WithOrds_0.prx, _3_MockVariableIntBlock_0.pos, _3_nrm.cfe, _0_Block_0.tip, _5.fdt, _5_MockVariableIntBlock_0.pyl, _0_Block_0.tim, _3_Lucene40WithOrds_0.tii, _7_Block_0.tim, _6_Lucene40WithOrds_0.prx, _4_nrm.cfe, _4.fnm, _0_MockVariableIntBlock_0.skp, _7_Block_0.tip, _7_MockVariableIntBlock_0.doc, _1.fnm, _3_Lucene40WithOrds_0.tib, _4.fdx, _3_Block_0.tim, _7_MockVariableIntBlock_0.tii, _6_MockVariableIntBlock_0.frq, _1_Block_0.doc, _6_MockVariableIntBlock_0.doc, _2_MockVariableIntBlock_0.pos, _6_Lucene40WithOrds_0.frq, _5_MockVariableIntBlock_0.pos, _0.fnm, _4_Block_0.tim, _6_Block_0.doc, _3_MockVariableIntBlock_0.doc, _7_Lucene40WithOrds_0.tib, _6_Lucene40WithOrds_0.tii, _5.si, _5_Lucene40WithOrds_0.frq, _3_nrm.cfs, _7_Lucene40WithOrds_0.tii, _4_MockVariableIntBlock_0.pyl, _4_Lucene40WithOrds_0.prx, _6_Lucene40WithOrds_0.tib, _4_Memory_0.ram, _4_nrm.cfs, _3_MockVariableIntBlock_0.tib, _5_Block_0.tip, _7_Block_0.doc, _5_MockVariableIntBlock_0.doc, _0_Block_0.pos, _6_MockVariableIntBlock_0.pyl, _4_Lucene40WithOrds_0.frq, _2_MockVariableIntBlock_0.frq, _4_Block_0.doc, _6_nrm.cfs, _4_MockVariableIntBlock_0.skp, _2_Lucene40WithOrds_0.prx, _7_nrm.cfs, _0_MockVariableIntBlock_0.tib, _5_MockVariableIntBlock_0.skp, _6_MockVariableIntBlock_0.pos, _5_Block_0.pos, _4_MockVariableIntBlock_0.pos, _7_Lucene40WithOrds_0.prx, _2_Memory_0.ram, _0.si, _3_Memory_0.ram, _0_MockVariableIntBlock_0.tii, _1_nrm.cfs, _5.fnm, _0_Block_0.doc, _7_nrm.cfe, _6_nrm.cfe, _4.si, _4.fdt, _0_nrm.cfs, _3_Lucene40WithOrds_0.frq, _6_MockVariableIntBlock_0.skp, _1_nrm.cfe, _1_MockVariableIntBlock_0.frq, _2_Lucene40WithOrds_0.tii, _6_Block_0.tip, _0_nrm.cfe, _5.fdx, _0.fdx, _2_Lucene40WithOrds_0.tib, _6_Block_0.tim, _2_Block_0.doc, _3_MockVariableIntBlock_0.skp, segments_3, _0.fdt]
[junit4:junit4]   2> 13755 T2262 C196 P60384 oasc.SolrDeletionPolicy.updateCommits newest commit = 3
[junit4:junit4]   2> 13817 T2262 C196 P60384 oass.SolrIndexSearcher.<init> Opening Searcher@520cb2e5 main
[junit4:junit4]   2> 13818 T2262 C196

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

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> 181559 T2322 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 181563 T2322 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> 181564 T2322 oasu.DefaultSolrCoreState.decref SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 181567 T2322 oasu.DefaultSolrCoreState.decref Closing SolrCoreState - canceling any ongoing recovery
[junit4:junit4]   2> 181567 T2322 oasc.LeaderElector$1.process WARNING  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard2/election/88322266122092550-127.0.0.1:36687_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> 181568 T2322 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 181569 T2322 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 181569 T2322 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 181569 T2322 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 181569 T2322 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7cb5c30a name:ZooKeeperConnection Watcher:127.0.0.1:25746/solr got event WatchedEvent state:Disconnected type:None path:null path:null type:None
[junit4:junit4]   2> 181569 T2322 oascc.ConnectionManager.process Client->ZooKeeper status change trigger but we are already closed
[junit4:junit4]   2> 181570 T2322 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> NOTE: test params are: codec=Lucene40: {n_f1=MockVariableIntBlock(baseBlockSize=1), foo_b=PostingsFormat(name=Memory doPackFST= false), foo_d=Block(blocksize=128), foo_f=PostingsFormat(name=Memory doPackFST= false), n_tl1=MockVariableIntBlock(baseBlockSize=1), n_d1=PostingsFormat(name=Lucene40WithOrds), rnd_b=Block(blocksize=128), intDefault=PostingsFormat(name=Lucene40WithOrds), n_td1=MockVariableIntBlock(baseBlockSize=1), timestamp=PostingsFormat(name=Lucene40WithOrds), id=Block(blocksize=128), range_facet_sl=PostingsFormat(name=Memory doPackFST= false), range_facet_si=MockVariableIntBlock(baseBlockSize=1), oddField_s=PostingsFormat(name=Memory doPackFST= false), multiDefault=MockVariableIntBlock(baseBlockSize=1), n_tf1=PostingsFormat(name=Lucene40WithOrds), n_dt1=MockVariableIntBlock(baseBlockSize=1), n_ti1=Block(blocksize=128), range_facet_l=PostingsFormat(name=Lucene40WithOrds), text=PostingsFormat(name=Memory doPackFST= false), _version_=PostingsFormat(name=Lucene40WithOrds), SubjectTerms_mfacet=PostingsFormat(name=Lucene40WithOrds), a_t=PostingsFormat(name=Lucene40WithOrds), n_tdt1=PostingsFormat(name=Lucene40WithOrds), other_tl1=PostingsFormat(name=Lucene40WithOrds), n_l1=PostingsFormat(name=Lucene40WithOrds), a_si=MockVariableIntBlock(baseBlockSize=1)}, sim=DefaultSimilarity, locale=en_NZ, timezone=America/Port-au-Prince
[junit4:junit4]   2> NOTE: FreeBSD 9.0-RELEASE amd64/Oracle Corporation 1.7.0_06 (64-bit)/cpus=16,threads=1,free=354390568,total=536870912
[junit4:junit4]   2> NOTE: All tests run in this JVM: [TestSolrDeletionPolicy2, StatsComponentTest, TestOmitPositions, DirectUpdateHandlerTest, TestValueSourceCache, IndexSchemaRuntimeFieldTest, TestFoldingMultitermQuery, LukeRequestHandlerTest, FieldMutatingUpdateProcessorTest, TestDistributedSearch, ClusterStateUpdateTest, PrimitiveFieldTypeTest, ScriptEngineTest, BadIndexSchemaTest, TestPhraseSuggestions, ZkNodePropsTest, OutputWriterTest, TestFunctionQuery, StatelessScriptUpdateProcessorFactoryTest, TestArbitraryIndexDir, TestJmxIntegration, TestRecovery, TermVectorComponentTest, TestDFRSimilarityFactory, UpdateParamsTest, DocumentAnalysisRequestHandlerTest, TestWriterPerf, TestSurroundQueryParser, TestCodecSupport, TestReload, DirectSolrSpellCheckerTest, TestHashPartitioner, QueryEqualityTest, TestDocSet, PeerSyncTest, TestMergePolicyConfig, HighlighterTest, EchoParamsTest, TestQueryUtils, TestStressLucene, TestPropInjectDefaults, TimeZoneUtilsTest, TestUpdate, IndexSchemaTest, XsltUpdateRequestHandlerTest, QueryParsingTest, SoftAutoCommitTest, LeaderElectionTest, TestLRUCache, TestFastWriter, ZkSolrClientTest, TestSolrXMLSerializer, TestRemoteStreaming, DistributedQueryElevationComponentTest, TestCSVLoader, RecoveryZkTest, OverseerTest, FullSolrCloudDistribCmdsTest, TestReplicationHandler, TestRealTimeGet, TestDistributedGrouping, SpellCheckCollatorTest, AutoCommitTest, BasicZkTest, WordBreakSolrSpellCheckerTest, DistributedTermsComponentTest, SolrCoreTest, TestRangeQuery, TestMultiCoreConfBootstrap, SimpleFacetsTest, TestCoreContainer, TestGroupingSearch, ConvertedLegacyTest, QueryElevationComponentTest, SortByFunctionTest, BasicFunctionalityTest, SignatureUpdateProcessorFactoryTest, TestBinaryResponseWriter, SampleTest, TestTrie, TestWordDelimiterFilterFactory, PolyFieldTest, SpatialFilterTest, MoreLikeThisHandlerTest, DisMaxRequestHandlerTest, SolrInfoMBeanTest, XmlUpdateRequestHandlerTest, PingRequestHandlerTest, DirectUpdateHandlerOptimizeTest, TestReversedWildcardFilterFactory, DebugComponentTest, RequestHandlersTest, RequiredFieldsTest, LoggingHandlerTest, SuggesterTest, ShowFileRequestHandlerTest, TestSolrDeletionPolicy1, TestIndexingPerformance, BadComponentTest, TestXIncludeConfig, TestCollationField, IndexReaderFactoryTest, MultiTermTest, TestConfig, TestLMDirichletSimilarityFactory, TestPluginEnable, LegacyHTMLStripCharFilterTest, PluginInfoTest, PrimUtilsTest, OpenExchangeRatesOrgProviderTest, FileUtilsTest, SpellingQueryConverterTest, TestBadConfig, BasicDistributedZk2Test]
[junit4:junit4] Completed on J1 in 181.70s, 1 test, 1 failure <<< FAILURES!

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

Total time: 31 minutes 33 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