lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache Jenkins Server <jenk...@builds.apache.org>
Subject [JENKINS] Lucene-Solr-Tests-trunk-Java6 - Build # 15259 - Failure
Date Tue, 18 Sep 2012 11:28:38 GMT
Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-Java6/15259/

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




Build Log:
[...truncated 7003 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4:junit4]   2> 7 T95 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1347966789597
[junit4:junit4]   2> 9 T95 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 11 T96 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4]   2> 12 T96 oazs.NIOServerCnxn$Factory.<init> binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 13 T96 oazsp.FileTxnSnapLog.save Snapshotting: 0
[junit4:junit4]   2> 110 T95 oasc.ZkTestServer.run start zk server on port:31500
[junit4:junit4]   2> 110 T95 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:31500 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@3fdfbc7f
[junit4:junit4]   2> 111 T101 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:31500
[junit4:junit4]   2> 111 T95 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 113 T101 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:31500, initiating session
[junit4:junit4]   2> 113 T97 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:32372
[junit4:junit4]   2> 114 T97 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:32372
[junit4:junit4]   2> 114 T99 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 118 T99 oazs.NIOServerCnxn.finishSessionInit Established session 0x139d914e7e20000 with negotiated timeout 10000 for client /140.211.11.196:32372
[junit4:junit4]   2> 119 T101 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:31500, sessionid = 0x139d914e7e20000, negotiated timeout = 10000
[junit4:junit4]   2> 119 T102 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3fdfbc7f name:ZooKeeperConnection Watcher:127.0.0.1:31500 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 120 T95 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 120 T95 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 136 T100 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x139d914e7e20000
[junit4:junit4]   2> 138 T102 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 138 T97 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:32372 which had sessionid 0x139d914e7e20000
[junit4:junit4]   2> 138 T95 oaz.ZooKeeper.close Session: 0x139d914e7e20000 closed
[junit4:junit4]   2> 139 T95 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:31500/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@1cf6e5e9
[junit4:junit4]   2> 140 T103 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:31500
[junit4:junit4]   2> 140 T95 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 141 T103 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:31500, initiating session
[junit4:junit4]   2> 142 T97 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:12623
[junit4:junit4]   2> 142 T97 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:12623
[junit4:junit4]   2> 144 T99 oazs.NIOServerCnxn.finishSessionInit Established session 0x139d914e7e20001 with negotiated timeout 10000 for client /140.211.11.196:12623
[junit4:junit4]   2> 145 T103 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:31500, sessionid = 0x139d914e7e20001, negotiated timeout = 10000
[junit4:junit4]   2> 145 T104 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1cf6e5e9 name:ZooKeeperConnection Watcher:127.0.0.1:31500/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 145 T95 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 146 T95 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 151 T95 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 160 T95 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 163 T95 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 168 T95 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 169 T95 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 182 T95 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4]   2> 183 T95 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 289 T95 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 290 T95 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 303 T95 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4]   2> 304 T95 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 309 T95 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4]   2> 310 T95 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 314 T95 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4]   2> 315 T95 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 319 T95 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 320 T95 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 324 T95 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 325 T95 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 333 T95 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 334 T95 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 338 T95 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4]   2> 339 T95 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 343 T100 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x139d914e7e20001
[junit4:junit4]   2> 344 T104 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 345 T97 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:12623 which had sessionid 0x139d914e7e20001
[junit4:junit4]   2> 344 T95 oaz.ZooKeeper.close Session: 0x139d914e7e20001 closed
[junit4:junit4]   2> 919 T95 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 1207 T95 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:38887
[junit4:junit4]   2> 1234 T95 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 1234 T95 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 1235 T95 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 1264 T95 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 1265 T95 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 1265 T95 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 1266 T95 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/solr.xml
[junit4:junit4]   2> 1266 T95 oasc.CoreContainer.<init> New CoreContainer 2029686239
[junit4:junit4]   2> 1267 T95 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 1267 T95 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 1301 T95 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 1314 T95 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:31500/solr
[junit4:junit4]   2> 1315 T95 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:31500/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@194bf8af
[junit4:junit4]   2> 1316 T115 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:31500
[junit4:junit4]   2> 1316 T95 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 1318 T115 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:31500, initiating session
[junit4:junit4]   2> 1318 T97 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:44340
[junit4:junit4]   2> 1319 T97 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:44340
[junit4:junit4]   2> 1328 T99 oazs.NIOServerCnxn.finishSessionInit Established session 0x139d914e7e20002 with negotiated timeout 5000 for client /140.211.11.196:44340
[junit4:junit4]   2> 1328 T115 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:31500, sessionid = 0x139d914e7e20002, negotiated timeout = 5000
[junit4:junit4]   2> 1329 T116 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@194bf8af name:ZooKeeperConnection Watcher:127.0.0.1:31500/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 1330 T95 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 1332 T100 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139d914e7e20002 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 1340 T95 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 1343 T95 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38887_solr
[junit4:junit4]   2> 1344 T100 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139d914e7e20002 type:delete cxid:0x7 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:38887_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:38887_solr
[junit4:junit4]   2> 1345 T95 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:38887_solr
[junit4:junit4]   2> 1353 T95 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 1353 T95 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 1354 T95 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 1354 T95 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 1354 T95 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 1355 T95 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 1355 T95 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 1355 T95 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 1356 T95 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 1356 T95 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 1367 T95 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 1379 T100 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139d914e7e20002 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> 1385 T95 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 1388 T95 oasc.Overseer.start Overseer (id=88340351523356674-127.0.0.1:38887_solr-n_0000000000) starting
[junit4:junit4]   2> 1389 T100 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139d914e7e20002 type:create cxid:0x1a zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 1390 T100 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139d914e7e20002 type:create cxid:0x1b zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 1399 T100 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139d914e7e20002 type:create cxid:0x1c zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 1400 T100 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139d914e7e20002 type:create cxid:0x1d zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 1407 T118 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 1407 T95 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 1410 T95 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 1416 T117 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 1416 T95 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1
[junit4:junit4]   2> 1417 T95 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 1418 T95 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 1419 T95 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 1420 T95 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4]   2> 1421 T95 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 1422 T95 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4]   2> 1504 T95 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 1594 T95 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 1695 T95 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 1712 T95 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 2215 T95 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 2226 T95 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 2230 T95 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 2254 T95 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 2259 T95 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 2263 T95 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 2266 T95 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 2268 T95 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test-files/solr/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/control/data/
[junit4:junit4]   2> 2269 T95 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@427be8c2
[junit4:junit4]   2> 2294 T95 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/control/data/index/
[junit4:junit4]   2> 2295 T95 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/control/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 2296 T95 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/control/data/index forceNew:false
[junit4:junit4]   2> 2301 T95 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/control/data/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 2302 T95 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 2302 T95 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 2305 T95 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 2305 T95 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 2306 T95 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 2307 T95 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 2308 T95 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 2308 T95 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 2309 T95 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 2310 T95 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 2310 T95 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 2311 T95 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 2312 T95 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 2313 T95 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 2313 T95 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 2314 T95 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 2314 T95 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 2315 T95 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 2316 T95 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2316 T95 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2317 T95 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2318 T95 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2318 T95 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2319 T95 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2320 T95 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2321 T95 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 2321 T95 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 2324 T95 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 2328 T95 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 2330 T95 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> 2334 T95 oass.SolrIndexSearcher.<init> Opening Searcher@5ee7dfd0 main
[junit4:junit4]   2> 2335 T95 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 2336 T95 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 2336 T95 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 2352 T95 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 2415 T119 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5ee7dfd0 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 2422 T100 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139d914e7e20002 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> 2435 T95 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 2435 T95 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:38887/solr shardId:control_shard
[junit4:junit4]   2> 2436 T95 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/control_shard/election
[junit4:junit4]   2> 2452 T100 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139d914e7e20002 type:delete cxid:0x65 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/collections/control_collection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/control_collection/leaders
[junit4:junit4]   2> 2453 T95 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 2454 T100 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139d914e7e20002 type:create cxid:0x66 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2938 T117 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2939 T100 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139d914e7e20002 type:create cxid:0x6d zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer/queue-work Error:KeeperErrorCode = NoNode for /solr/overseer/queue-work
[junit4:junit4]   2> 2961 T116 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 3459 T95 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 3460 T95 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 3460 T95 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:38887/solr/collection1/
[junit4:junit4]   2> 3461 T95 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 3461 T95 oasc.SyncStrategy.syncToMe http://127.0.0.1:38887/solr/collection1/ has no replicas
[junit4:junit4]   2> 3462 T95 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:38887/solr/collection1/
[junit4:junit4]   2> 3463 T95 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/control_shard
[junit4:junit4]   2> 3480 T100 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139d914e7e20002 type:create cxid:0x8e zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3983 T117 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4058 T116 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4096 T95 oasc.ZkController.register We are http://127.0.0.1:38887/solr/collection1/ and leader is http://127.0.0.1:38887/solr/collection1/
[junit4:junit4]   2> 4096 T95 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:38887/solr
[junit4:junit4]   2> 4097 T95 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 4140 T95 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4142 T95 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1
[junit4:junit4]   2> 4142 T95 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 4211 T95 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 4390 T95 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 4393 T95 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:27077
[junit4:junit4]   2> 4394 T95 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 4395 T95 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty1-1347966793825
[junit4:junit4]   2> 4395 T95 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty1-1347966793825/'
[junit4:junit4]   2> 4431 T95 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 4432 T95 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 4432 T95 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty1-1347966793825
[junit4:junit4]   2> 4433 T95 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty1-1347966793825/solr.xml
[junit4:junit4]   2> 4434 T95 oasc.CoreContainer.<init> New CoreContainer 911091865
[junit4:junit4]   2> 4434 T95 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty1-1347966793825/'
[junit4:junit4]   2> 4435 T95 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty1-1347966793825/'
[junit4:junit4]   2> 4462 T95 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 4479 T95 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:31500/solr
[junit4:junit4]   2> 4480 T95 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:31500/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@5bd18ac9
[junit4:junit4]   2> 4481 T129 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:31500
[junit4:junit4]   2> 4481 T95 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 4483 T129 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:31500, initiating session
[junit4:junit4]   2> 4483 T97 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:63553
[junit4:junit4]   2> 4483 T97 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:63553
[junit4:junit4]   2> 4488 T99 oazs.NIOServerCnxn.finishSessionInit Established session 0x139d914e7e20003 with negotiated timeout 5000 for client /140.211.11.196:63553
[junit4:junit4]   2> 4489 T129 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:31500, sessionid = 0x139d914e7e20003, negotiated timeout = 5000
[junit4:junit4]   2> 4489 T130 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5bd18ac9 name:ZooKeeperConnection Watcher:127.0.0.1:31500/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 4489 T95 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 4491 T100 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139d914e7e20003 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4499 T100 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139d914e7e20003 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4500 T95 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:27077_solr
[junit4:junit4]   2> 4501 T100 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139d914e7e20003 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:27077_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:27077_solr
[junit4:junit4]   2> 4502 T95 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:27077_solr
[junit4:junit4]   2> 4511 T116 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 4512 T95 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 4512 T95 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 4513 T95 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 4513 T95 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 4514 T95 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 4514 T95 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 4515 T95 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 4515 T95 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 4516 T95 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 4516 T95 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 4541 T95 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 4548 T95 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty1-1347966793825/collection1
[junit4:junit4]   2> 4549 T95 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 4550 T95 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 4551 T95 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 4553 T95 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty1-1347966793825/collection1/'
[junit4:junit4]   2> 4554 T95 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/solrtest-jetty1-1347966793825/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 4555 T95 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/solrtest-jetty1-1347966793825/collection1/lib/README' to classloader
[junit4:junit4]   2> 4584 T117 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4598 T130 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4598 T116 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4618 T95 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 4696 T95 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 4797 T95 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 4820 T95 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 5502 T95 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 5518 T95 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 5522 T95 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 5551 T95 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 5558 T95 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 5564 T95 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 5566 T95 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 5569 T95 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty1-1347966793825/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty1/
[junit4:junit4]   2> 5570 T95 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@427be8c2
[junit4:junit4]   2> 5572 T95 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty1/index/
[junit4:junit4]   2> 5572 T95 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 5573 T95 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty1/index forceNew:false
[junit4:junit4]   2> 5590 T95 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty1/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 5590 T95 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 5591 T95 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 5595 T95 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 5596 T95 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 5596 T95 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 5597 T95 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 5599 T95 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 5599 T95 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 5600 T95 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 5601 T95 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 5602 T95 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 5604 T95 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 5605 T95 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 5606 T95 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 5607 T95 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 5608 T95 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 5608 T95 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 5609 T95 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 5611 T95 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5612 T95 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5613 T95 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5614 T95 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5615 T95 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5616 T95 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5617 T95 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5618 T95 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 5619 T95 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 5623 T95 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 5628 T95 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 5630 T95 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> 5634 T95 oass.SolrIndexSearcher.<init> Opening Searcher@4dfbbcea main
[junit4:junit4]   2> 5636 T95 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 5636 T95 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 5638 T95 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 5646 T95 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 5705 T131 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4dfbbcea main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 6111 T117 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6130 T130 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6130 T116 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6218 T95 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 6218 T95 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:27077/solr shardId:shard1
[junit4:junit4]   2> 6220 T95 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 6238 T100 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139d914e7e20003 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> 6239 T95 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 6240 T100 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139d914e7e20003 type:create cxid:0x44 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 6249 T95 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 6250 T95 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 6250 T95 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:27077/solr/collection1/
[junit4:junit4]   2> 6251 T95 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 6251 T95 oasc.SyncStrategy.syncToMe http://127.0.0.1:27077/solr/collection1/ has no replicas
[junit4:junit4]   2> 6252 T95 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:27077/solr/collection1/
[junit4:junit4]   2> 6252 T95 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 6258 T100 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139d914e7e20003 type:create cxid:0x4e zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 6639 T117 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6678 T116 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6678 T130 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6728 T95 oasc.ZkController.register We are http://127.0.0.1:27077/solr/collection1/ and leader is http://127.0.0.1:27077/solr/collection1/
[junit4:junit4]   2> 6728 T95 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:27077/solr
[junit4:junit4]   2> 6729 T95 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 6732 T95 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6734 T95 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1
[junit4:junit4]   2> 6734 T95 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 6735 T95 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 6901 T95 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 6905 T95 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:53205
[junit4:junit4]   2> 6906 T95 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 6906 T95 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty2-1347966796341
[junit4:junit4]   2> 6907 T95 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty2-1347966796341/'
[junit4:junit4]   2> 6943 T95 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 6944 T95 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 6944 T95 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty2-1347966796341
[junit4:junit4]   2> 6945 T95 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty2-1347966796341/solr.xml
[junit4:junit4]   2> 6945 T95 oasc.CoreContainer.<init> New CoreContainer 542406720
[junit4:junit4]   2> 6947 T95 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty2-1347966796341/'
[junit4:junit4]   2> 6947 T95 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty2-1347966796341/'
[junit4:junit4]   2> 6974 T95 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 6995 T95 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:31500/solr
[junit4:junit4]   2> 6995 T95 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:31500/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@55adb150
[junit4:junit4]   2> 6997 T141 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:31500
[junit4:junit4]   2> 6997 T95 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 6998 T141 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:31500, initiating session
[junit4:junit4]   2> 6998 T97 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:62539
[junit4:junit4]   2> 6999 T97 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:62539
[junit4:junit4]   2> 7001 T99 oazs.NIOServerCnxn.finishSessionInit Established session 0x139d914e7e20004 with negotiated timeout 5000 for client /140.211.11.196:62539
[junit4:junit4]   2> 7001 T141 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:31500, sessionid = 0x139d914e7e20004, negotiated timeout = 5000
[junit4:junit4]   2> 7002 T142 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@55adb150 name:ZooKeeperConnection Watcher:127.0.0.1:31500/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 7002 T95 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 7003 T100 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139d914e7e20004 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7012 T100 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139d914e7e20004 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7013 T95 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53205_solr
[junit4:junit4]   2> 7014 T100 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139d914e7e20004 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:53205_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:53205_solr
[junit4:junit4]   2> 7016 T95 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53205_solr
[junit4:junit4]   2> 7024 T130 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 7024 T116 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 7025 T95 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 7025 T95 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 7026 T95 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 7026 T95 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 7027 T95 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 7027 T95 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 7028 T95 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 7028 T95 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 7029 T95 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 7030 T95 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 7050 T95 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 7058 T95 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty2-1347966796341/collection1
[junit4:junit4]   2> 7058 T95 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 7060 T95 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 7060 T95 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 7062 T95 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty2-1347966796341/collection1/'
[junit4:junit4]   2> 7063 T95 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/solrtest-jetty2-1347966796341/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 7064 T95 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/solrtest-jetty2-1347966796341/collection1/lib/README' to classloader
[junit4:junit4]   2> 7122 T95 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 7192 T117 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7199 T130 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7199 T142 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7199 T116 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7201 T95 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 7307 T95 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 7327 T95 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 8056 T95 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 8066 T95 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 8070 T95 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 8093 T95 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 8098 T95 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 8103 T95 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 8105 T95 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 8107 T95 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty2-1347966796341/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty2/
[junit4:junit4]   2> 8107 T95 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@427be8c2
[junit4:junit4]   2> 8108 T95 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty2/index/
[junit4:junit4]   2> 8109 T95 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 8110 T95 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty2/index forceNew:false
[junit4:junit4]   2> 8114 T95 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty2/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 8115 T95 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 8116 T95 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 8118 T95 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 8119 T95 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 8119 T95 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 8120 T95 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 8120 T95 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 8121 T95 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 8122 T95 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 8122 T95 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 8123 T95 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 8124 T95 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 8125 T95 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 8125 T95 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 8126 T95 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 8126 T95 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 8127 T95 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 8128 T95 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 8128 T95 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8129 T95 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8130 T95 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8131 T95 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8131 T95 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8132 T95 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8133 T95 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 8134 T95 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 8134 T95 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 8137 T95 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 8141 T95 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 8143 T95 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> 8146 T95 oass.SolrIndexSearcher.<init> Opening Searcher@6bd7fadd main
[junit4:junit4]   2> 8147 T95 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 8148 T95 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 8149 T95 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 8156 T95 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 8215 T143 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6bd7fadd main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 8716 T117 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8729 T130 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8729 T116 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8729 T142 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9226 T95 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 9226 T95 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:53205/solr shardId:shard2
[junit4:junit4]   2> 9228 T95 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4]   2> 9252 T100 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139d914e7e20004 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> 9253 T95 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 9254 T100 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139d914e7e20004 type:create cxid:0x43 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 9256 T95 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 9257 T95 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 9257 T95 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53205/solr/collection1/
[junit4:junit4]   2> 9258 T95 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 9258 T95 oasc.SyncStrategy.syncToMe http://127.0.0.1:53205/solr/collection1/ has no replicas
[junit4:junit4]   2> 9259 T95 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53205/solr/collection1/
[junit4:junit4]   2> 9260 T95 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4]   2> 9264 T100 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139d914e7e20004 type:create cxid:0x4c zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 9757 T117 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9828 T130 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9828 T142 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9828 T116 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9879 T95 oasc.ZkController.register We are http://127.0.0.1:53205/solr/collection1/ and leader is http://127.0.0.1:53205/solr/collection1/
[junit4:junit4]   2> 9879 T95 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53205/solr
[junit4:junit4]   2> 9880 T95 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 9883 T95 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9884 T95 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1
[junit4:junit4]   2> 9885 T95 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 9886 T95 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 10053 T95 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 10056 T95 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:28853
[junit4:junit4]   2> 10057 T95 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 10057 T95 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty3-1347966799490
[junit4:junit4]   2> 10058 T95 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty3-1347966799490/'
[junit4:junit4]   2> 10094 T95 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 10094 T95 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 10095 T95 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty3-1347966799490
[junit4:junit4]   2> 10095 T95 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty3-1347966799490/solr.xml
[junit4:junit4]   2> 10096 T95 oasc.CoreContainer.<init> New CoreContainer 1674201402
[junit4:junit4]   2> 10097 T95 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty3-1347966799490/'
[junit4:junit4]   2> 10097 T95 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty3-1347966799490/'
[junit4:junit4]   2> 10125 T95 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 10143 T95 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:31500/solr
[junit4:junit4]   2> 10144 T95 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:31500/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@29a260e7
[junit4:junit4]   2> 10145 T153 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:31500
[junit4:junit4]   2> 10145 T95 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 10147 T153 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:31500, initiating session
[junit4:junit4]   2> 10147 T97 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:38258
[junit4:junit4]   2> 10148 T97 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:38258
[junit4:junit4]   2> 10150 T99 oazs.NIOServerCnxn.finishSessionInit Established session 0x139d914e7e20005 with negotiated timeout 5000 for client /140.211.11.196:38258
[junit4:junit4]   2> 10150 T153 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:31500, sessionid = 0x139d914e7e20005, negotiated timeout = 5000
[junit4:junit4]   2> 10151 T154 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@29a260e7 name:ZooKeeperConnection Watcher:127.0.0.1:31500/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 10151 T95 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 10152 T100 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139d914e7e20005 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 10162 T100 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139d914e7e20005 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 10164 T95 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:28853_solr
[junit4:junit4]   2> 10165 T100 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139d914e7e20005 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:28853_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:28853_solr
[junit4:junit4]   2> 10166 T95 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:28853_solr
[junit4:junit4]   2> 10174 T130 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 10174 T116 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 10174 T142 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 10176 T95 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 10176 T95 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 10177 T95 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 10177 T95 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 10178 T95 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 10178 T95 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 10179 T95 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 10179 T95 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 10180 T95 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 10180 T95 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 10203 T95 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 10211 T95 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty3-1347966799490/collection1
[junit4:junit4]   2> 10212 T95 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 10213 T95 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 10213 T95 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 10215 T95 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty3-1347966799490/collection1/'
[junit4:junit4]   2> 10217 T95 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/solrtest-jetty3-1347966799490/collection1/lib/README' to classloader
[junit4:junit4]   2> 10218 T95 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/solrtest-jetty3-1347966799490/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 10280 T95 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 10337 T117 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 10356 T116 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10356 T130 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10357 T154 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10357 T142 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10367 T95 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 10468 T95 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 10479 T95 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 11129 T95 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 11138 T95 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 11141 T95 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 11161 T95 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 11166 T95 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 11170 T95 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 11172 T95 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 11174 T95 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty3-1347966799490/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty3/
[junit4:junit4]   2> 11175 T95 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@427be8c2
[junit4:junit4]   2> 11176 T95 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty3/index/
[junit4:junit4]   2> 11177 T95 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 11177 T95 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty3/index forceNew:false
[junit4:junit4]   2> 11183 T95 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty3/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 11183 T95 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 11184 T95 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 11187 T95 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 11187 T95 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 11188 T95 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 11188 T95 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 11189 T95 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 11189 T95 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 11190 T95 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 11190 T95 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 11191 T95 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 11192 T95 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 11192 T95 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 11193 T95 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 11193 T95 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 11194 T95 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 11194 T95 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 11195 T95 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 11196 T95 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 11196 T95 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 11197 T95 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 11197 T95 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 11198 T95 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 11199 T95 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 11199 T95 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 11200 T95 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 11201 T95 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 11203 T95 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 11207 T95 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 11208 T95 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> 11211 T95 oass.SolrIndexSearcher.<init> Opening Searcher@e5ddccb main
[junit4:junit4]   2> 11212 T95 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 11212 T95 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 11213 T95 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 11219 T95 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 11267 T155 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@e5ddccb main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 11366 T117 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 11379 T116 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11379 T130 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11379 T154 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11379 T142 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11775 T95 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 11775 T95 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:28853/solr shardId:shard1
[junit4:junit4]   2> 11787 T95 oasc.ZkController.register We are http://127.0.0.1:28853/solr/collection1/ and leader is http://127.0.0.1:27077/solr/collection1/
[junit4:junit4]   2> 11788 T95 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:28853/solr
[junit4:junit4]   2> 11789 T95 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 11790 T95 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C4 name=collection1 org.apache.solr.core.SolrCore@1a1feb69 url=http://127.0.0.1:28853/solr/collection1 node=127.0.0.1:28853_solr
[junit4:junit4]   2> 11796 T156 C4 P28853 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 11797 T156 C4 P28853 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 11797 T95 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 11799 T156 C4 P28853 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:27077/solr/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 11800 T95 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1
[junit4:junit4]   2> 11800 T95 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 11800 T95 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 11806 T156 C4 P28853 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&connTimeout=30000&socketTimeout=30000&retry=false
[junit4:junit4]   2> 11825 T156 C4 P28853 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:28853/solr START replicas=[http://127.0.0.1:27077/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 11825 T156 C4 P28853 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 11826 T156 C4 P28853 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 11826 T156 C4 P28853 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 11827 T156 C4 P28853 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 11884 T117 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 11903 T116 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11903 T154 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11903 T142 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11903 T130 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11973 T95 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 11980 T95 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:41457
[junit4:junit4]   2> 11981 T95 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 11982 T95 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty4-1347966801405
[junit4:junit4]   2> 11982 T95 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty4-1347966801405/'
[junit4:junit4]   2> 12263 T95 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 12264 T95 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 12264 T95 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty4-1347966801405
[junit4:junit4]   2> 12265 T95 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty4-1347966801405/solr.xml
[junit4:junit4]   2> 12266 T95 oasc.CoreContainer.<init> New CoreContainer 2052027792
[junit4:junit4]   2> 12267 T95 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty4-1347966801405/'
[junit4:junit4]   2> 12267 T95 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty4-1347966801405/'
[junit4:junit4]   2> 12565 T95 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 12693 T95 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:31500/solr
[junit4:junit4]   2> 12694 T95 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:31500/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@4136dc05
[junit4:junit4]   2> 12695 T167 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:31500
[junit4:junit4]   2> 12695 T95 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 12697 T167 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:31500, initiating session
[junit4:junit4]   2> 12697 T97 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:45045
[junit4:junit4]   2> 12698 T97 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:45045
[junit4:junit4]   2> 12726 T99 oazs.NIOServerCnxn.finishSessionInit Established session 0x139d914e7e20006 with negotiated timeout 5000 for client /140.211.11.196:45045
[junit4:junit4]   2> 12726 T167 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:31500, sessionid = 0x139d914e7e20006, negotiated timeout = 5000
[junit4:junit4]   2> 12727 T168 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4136dc05 name:ZooKeeperConnection Watcher:127.0.0.1:31500/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 12727 T95 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 12729 T100 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139d914e7e20006 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 12730 T100 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139d914e7e20006 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 12739 T95 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41457_solr
[junit4:junit4]   2> 12739 T100 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139d914e7e20006 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:41457_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:41457_solr
[junit4:junit4]   2> 12741 T95 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:41457_solr
[junit4:junit4]   2> 12744 T130 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 12744 T116 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 12744 T142 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 12744 T154 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 12745 T95 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 12746 T95 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 12746 T95 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 12747 T95 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 12747 T95 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 12748 T95 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 12748 T95 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 12749 T95 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 12749 T95 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 12750 T95 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 12773 T95 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 12824 T95 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty4-1347966801405/collection1
[junit4:junit4]   2> 12824 T95 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 12826 T95 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 12826 T95 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 12828 T95 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty4-1347966801405/collection1/'
[junit4:junit4]   2> 12830 T95 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/solrtest-jetty4-1347966801405/collection1/lib/README' to classloader
[junit4:junit4]   2> 12831 T95 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/solrtest-jetty4-1347966801405/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 13617 T95 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> ASYNC  NEW_CORE C5 name=collection1 org.apache.solr.core.SolrCore@26bd65e3 url=http://127.0.0.1:27077/solr/collection1 node=127.0.0.1:27077_solr
[junit4:junit4]   2> 13701 T123 C5 P27077 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=7 
[junit4:junit4]   2> 13942 T95 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 14043 T95 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 14056 T95 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 14661 T95 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 14669 T95 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 14672 T95 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 14692 T95 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 14697 T95 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 14701 T95 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 14702 T95 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 14704 T95 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./solrtest-jetty4-1347966801405/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty4/
[junit4:junit4]   2> 14705 T95 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@427be8c2
[junit4:junit4]   2> 14706 T95 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty4/index/
[junit4:junit4]   2> 14706 T95 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 14707 T95 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty4/index forceNew:false
[junit4:junit4]   2> 14714 T95 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty4/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 14715 T95 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 14715 T95 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 14717 T95 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 14718 T95 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 14718 T95 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 14719 T95 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 14719 T95 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 14720 T95 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 14720 T95 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 14721 T95 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 14722 T95 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 14722 T95 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 14723 T95 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 14724 T95 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 14724 T95 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 14724 T95 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 14725 T95 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 14726 T95 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 14726 T95 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 14727 T95 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 14728 T95 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 14728 T95 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 14729 T95 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 14730 T95 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 14730 T95 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 14731 T95 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 14732 T95 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 14735 T95 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 14738 T95 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 14739 T95 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> 14743 T95 oass.SolrIndexSearcher.<init> Opening Searcher@5d225fc1 main
[junit4:junit4]   2> 14744 T95 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 14744 T95 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 14745 T95 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 14750 T95 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 14799 T169 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5d225fc1 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 14926 T117 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 14938 T168 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14938 T154 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14938 T130 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14938 T142 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 14938 T116 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 15306 T95 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 15306 T95 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:41457/solr shardId:shard2
[junit4:junit4]   2> 15310 T95 oasc.ZkController.register We are http://127.0.0.1:41457/solr/collection1/ and leader is http://127.0.0.1:53205/solr/collection1/
[junit4:junit4]   2> 15311 T95 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:41457/solr
[junit4:junit4]   2> 15312 T95 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 15312 T95 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C6 name=collection1 org.apache.solr.core.SolrCore@7e480e56 url=http://127.0.0.1:41457/solr/collection1 node=127.0.0.1:41457_solr
[junit4:junit4]   2> 15313 T170 C6 P41457 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 15314 T170 C6 P41457 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 15314 T95 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 15315 T170 C6 P41457 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:53205/solr/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 15316 T170 C6 P41457 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:41457/solr START replicas=[http://127.0.0.1:53205/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 15316 T95 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1
[junit4:junit4]   2> 15316 T170 C6 P41457 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 15316 T95 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 15317 T170 C6 P41457 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 15317 T95 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 15318 T170 C6 P41457 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 15318 T170 C6 P41457 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C7 name=collection1 org.apache.solr.core.SolrCore@84e94ba url=http://127.0.0.1:53205/solr/collection1 node=127.0.0.1:53205_solr
[junit4:junit4]   2> 15327 T134 C7 P53205 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=0 
[junit4:junit4]   2> 15337 T95 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:31500/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@125b267f
[junit4:junit4]   2> 15338 T172 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:31500
[junit4:junit4]   2> 15338 T95 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 15339 T172 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:31500, initiating session
[junit4:junit4]   2> 15339 T97 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:28501
[junit4:junit4]   2> 15340 T97 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:28501
[junit4:junit4]   2> 15341 T99 oazs.NIOServerCnxn.finishSessionInit Established session 0x139d914e7e20007 with negotiated timeout 10000 for client /140.211.11.196:28501
[junit4:junit4]   2> 15341 T172 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:31500, sessionid = 0x139d914e7e20007, negotiated timeout = 10000
[junit4:junit4]   2> 15342 T173 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@125b267f name:ZooKeeperConnection Watcher:127.0.0.1:31500/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 15342 T95 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 15344 T95 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 15348 T95 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   2> 15349 T95 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 15360 T95 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> ASYNC  NEW_CORE C8 name=collection1 org.apache.solr.core.SolrCore@4587fd42 url=http://127.0.0.1:38887/solr/collection1 node=127.0.0.1:38887_solr
[junit4:junit4]   2> 15439 T108 C8 P38887 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/control/data/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 15440 T108 C8 P38887 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 15444 T117 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 15450 T108 C8 P38887 /update {wt=javabin&version=2} {add=[1 (1413445640544845824)]} 0 16
[junit4:junit4]   2> 15451 T95 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:31500/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@7ccbc403
[junit4:junit4]   2> 15452 T174 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:31500
[junit4:junit4]   2> 15452 T95 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 15453 T174 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:31500, initiating session
[junit4:junit4]   2> 15454 T97 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:62074
[junit4:junit4]   2> 15454 T97 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:62074
[junit4:junit4]   2> 15458 T130 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 15458 T116 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 15458 T173 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 15458 T142 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 15458 T154 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 15458 T168 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 15459 T99 oazs.NIOServerCnxn.finishSessionInit Established session 0x139d914e7e20008 with negotiated timeout 10000 for client /140.211.11.196:62074
[junit4:junit4]   2> 15460 T174 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:31500, sessionid = 0x139d914e7e20008, negotiated timeout = 10000
[junit4:junit4]   2> 15460 T175 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7ccbc403 name:ZooKeeperConnection Watcher:127.0.0.1:31500/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 15460 T95 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 15462 T95 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 15482 T124 C5 P27077 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty1/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 15482 T124 C5 P27077 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2>  C4_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:28853_solr, base_url=http://127.0.0.1:28853/solr}
[junit4:junit4]   2> 15519 T146 C4 P28853 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty3/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 15519 T146 C4 P28853 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 15530 T146 C4 P28853 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=15 
[junit4:junit4]   2> 15531 T124 C5 P27077 /update {wt=javabin&version=2} {add=[1 (1413445640590983168)]} 0 58
[junit4:junit4]   2> 15532 T95 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):1800
[junit4:junit4]   2> 15533 T95 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 15931 T156 C4 P28853 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 15931 T156 C4 P28853 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=tlog{file=./org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty3/tlog/tlog.0000000000000000000 refcount=1}}
[junit4:junit4]   2> 15932 T156 C4 P28853 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:27077/solr/collection1/. core=collection1
[junit4:junit4]   2> 15932 T156 C4 P28853 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 15956 T125 C5 P27077 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 16121 T125 C5 P27077 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty1/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty1/index,segFN=segments_2,generation=2,filenames=[_0_Block_0.tip, _0_Block_0.pos, _0_Block_0.tim, _0_MockVariableIntBlock_0.doc, _0_MockVariableIntBlock_0.skp, _0_MockFixedIntBlock_0.tib, _0_Pulsing40_0.prx, _0_Pulsing40_0.frq, _0_MockVariableIntBlock_0.pyl, _0_MockFixedIntBlock_0.skp, _0_MockFixedIntBlock_0.pyl, _0_MockVariableIntBlock_0.tib, _0_MockFixedIntBlock_0.tii, _0_MockVariableIntBlock_0.pos, _0_Pulsing40_0.tip, _0.si, _0_MockVariableIntBlock_0.tii, _0.fnm, _0_Pulsing40_0.tim, _0_Block_0.doc, _0_MockFixedIntBlock_0.pos, _0_nrm.cfs, _0_MockFixedIntBlock_0.frq, _0_MockFixedIntBlock_0.doc, _0_MockVariableIntBlock_0.frq, _0_nrm.cfe, segments_2, _0.fdx, _0.fdt]
[junit4:junit4]   2> 16122 T125 C5 P27077 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 16154 T125 C5 P27077 oass.SolrIndexSearcher.<init> Opening Searcher@1e47f9d main
[junit4:junit4]   2> 16155 T125 C5 P27077 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 16159 T131 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1e47f9d main{StandardDirectoryReader(segments_2:3 _0(5.0):C1)}
[junit4:junit4]   2> 16160 T125 C5 P27077 /update {waitSearcher=true&commit=true&commit_end_point=true&wt=javabin&softCommit=false&version=2} {commit=} 0 204
[junit4:junit4]   2> 16180 T156 C4 P28853 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 16181 T156 C4 P28853 oascsi.HttpClientUtil.createClient Creating new http client, config:connTimeout=5000&socketTimeout=20000&allowCompression=false&maxConnections=10000&maxConnectionsPerHost=10000
[junit4:junit4]   2> 16206 T156 C4 P28853 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 16262 T126 C5 P27077 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 16262 T126 C5 P27077 REQ /replication {command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=54 
[junit4:junit4]   2> 16264 T156 C4 P28853 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4]   2> 16264 T156 C4 P28853 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 16264 T156 C4 P28853 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 16271 T126 C5 P27077 REQ /replication {command=filelist&generation=2&wt=javabin&qt=/replication&version=2} status=0 QTime=3 
[junit4:junit4]   2> 16273 T156 C4 P28853 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 29
[junit4:junit4]   2> 16281 T156 C4 P28853 oash.SnapPuller.fetchLatestIndex Starting download to ./org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty3/index.20120918211325862 fullCopy=true
[junit4:junit4]   2> 16286 T126 C5 P27077 REQ /replication {file=_0_Block_0.pos&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=1 
[junit4:junit4]   2> 16300 T126 C5 P27077 REQ /replication {file=_0_Block_0.tip&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=1 
[junit4:junit4]   2> 16305 T126 C5 P27077 REQ /replication {file=_0_MockVariableIntBlock_0.doc&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=1 
[junit4:junit4]   2> 16311 T126 C5 P27077 REQ /replication {file=_0_Block_0.tim&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 16316 T126 C5 P27077 REQ /replication {file=_0_MockVariableIntBlock_0.skp&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 16318 T156 C4 P28853 oash.SnapPuller$FileFetcher.fetchPackets WARNING No content recieved for file: {name=_0_MockVariableIntBlock_0.skp, lastmodified=1347966805000, size=0}
[junit4:junit4]   2> 16322 T126 C5 P27077 REQ /replication {file=_0_Pulsing40_0.prx&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 16327 T126 C5 P27077 REQ /replication {file=_0_MockFixedIntBlock_0.tib&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 16332 T126 C5 P27077 REQ /replication {file=_0_Pulsing40_0.frq&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 16338 T126 C5 P27077 REQ /replication {file=_0_MockVariableIntBlock_0.pyl&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=1 
[junit4:junit4]   2> 16339 T156 C4 P28853 oash.SnapPuller$FileFetcher.fetchPackets WARNING No content recieved for file: {name=_0_MockVariableIntBlock_0.pyl, lastmodified=1347966805000, size=0}
[junit4:junit4]   2> 16343 T126 C5 P27077 REQ /replication {file=_0_MockFixedIntBlock_0.pyl&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 16345 T156 C4 P28853 oash.SnapPuller$FileFetcher.fetchPackets WARNING No content recieved for file: {name=_0_MockFixedIntBlock_0.pyl, lastmodified=1347966805000, size=0}
[junit4:junit4]   2> 16348 T126 C5 P27077 REQ /replication {file=_0_MockFixedIntBlock_0.skp&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 16350 T156 C4 P28853 oash.SnapPuller$FileFetcher.fetchPackets WARNING No content recieved for file: {name=_0_MockFixedIntBlock_0.skp, lastmodified=1347966805000, size=0}
[junit4:junit4]   2> 16354 T126 C5 P27077 REQ /replication {file=_0_MockVariableIntBlock_0.tib&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 16360 T126 C5 P27077 REQ /replication {file=_0_MockFixedIntBlock_0.tii&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 16366 T126 C5 P27077 REQ /replication {file=_0_Pulsing40_0.tip&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=1 
[junit4:junit4]   2> 16372 T126 C5 P27077 REQ /replication {file=_0_MockVariableIntBlock_0.pos&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 16376 T126 C5 P27077 REQ /replication {file=_0.si&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 16383 T126 C5 P27077 REQ /replication {file=_0_MockVariableIntBlock_0.tii&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 16389 T126 C5 P27077 REQ /replication {file=_0_Block_0.doc&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 16394 T126 C5 P27077 REQ /replication {file=_0_Pulsing40_0.tim&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 16399 T126 C5 P27077 REQ /replication {file=_0.fnm&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 16405 T126 C5 P27077 REQ /replication {file=_0_MockFixedIntBlock_0.pos&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 16412 T126 C5 P27077 REQ /replication {file=_0_nrm.cfs&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=1 
[junit4:junit4]   2> 16417 T126 C5 P27077 REQ /replication {file=_0_MockFixedIntBlock_0.frq&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 16422 T126 C5 P27077 REQ /replication {file=_0_MockFixedIntBlock_0.doc&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 16427 T126 C5 P27077 REQ /replication {file=_0_nrm.cfe&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 16432 T126 C5 P27077 REQ /replication {file=_0_MockVariableIntBlock_0.frq&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 16444 T126 C5 P27077 REQ /replication {file=segments_2&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=1 
[junit4:junit4]   2> 16450 T126 C5 P27077 REQ /replication {file=_0.fdx&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=1 
[junit4:junit4]   2> 16455 T126 C5 P27077 REQ /replication {file=_0.fdt&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 16460 T156 C4 P28853 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 16461 T156 C4 P28853 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20120918211325862
[junit4:junit4]   2> 16468 T156 C4 P28853 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 16469 T156 C4 P28853 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 16469 T156 C4 P28853 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4]   2> 16475 T156 C4 P28853 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=./org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty3/index/ new=./org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty3/index.20120918211325862
[junit4:junit4]   2> 16476 T156 C4 P28853 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty3/index.20120918211325862 forceNew:true
[junit4:junit4]   2> 16491 T156 C4 P28853 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty3/index.20120918211325862,segFN=segments_2,generation=2,filenames=[_0_Block_0.pos, _0_Block_0.tip, _0_MockVariableIntBlock_0.doc, _0_Block_0.tim, _0_MockVariableIntBlock_0.skp, _0_Pulsing40_0.prx, _0_MockFixedIntBlock_0.tib, _0_Pulsing40_0.frq, _0_MockVariableIntBlock_0.pyl, _0_MockFixedIntBlock_0.pyl, _0_MockFixedIntBlock_0.skp, _0_MockVariableIntBlock_0.tib, _0_MockFixedIntBlock_0.tii, _0_MockVariableIntBlock_0.pos, _0_Pulsing40_0.tip, _0.si, _0_MockVariableIntBlock_0.tii, _0.fnm, _0_Pulsing40_0.tim, _0_Block_0.doc, _0_MockFixedIntBlock_0.pos, _0_nrm.cfs, _0_MockFixedIntBlock_0.frq, _0_MockFixedIntBlock_0.doc, _0_nrm.cfe, _0_MockVariableIntBlock_0.frq, segments_2, _0.fdx, _0.fdt]
[junit4:junit4]   2> 16492 T156 C4 P28853 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 16492 T156 C4 P28853 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 16502 T156 C4 P28853 oass.SolrIndexSearcher.<init> Opening Searcher@3bcb55c5 main
[junit4:junit4]   2> 16505 T155 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3bcb55c5 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C1)}
[junit4:junit4]   2> 16506 T155 oasc.CachingDirectoryFactory.close Closing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty3/index
[junit4:junit4]   2> 16507 T155 oash.SnapPuller$2.onClose removing old index directory ./org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty3/index
[junit4:junit4]   2> 16509 T156 C4 P28853 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=false,waitSearcher=false,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 16510 T156 C4 P28853 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 16516 T156 C4 P28853 oasc.RecoveryStrategy.replay Replaying buffered documents. core=collection1
[junit4:junit4]   2> 16516 T178 C4 P28853 oasu.UpdateLog$LogReplayer.doReplay WARNING Starting log replay tlog{file=./org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty3/tlog/tlog.0000000000000000000 refcount=2} active=true starting pos=434
[junit4:junit4]   2> 16520 T178 C4 P28853 oasu.DirectUpdateHandler2.commit start commit{flags=2,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 16522 T178 C4 P28853 oass.SolrIndexSearcher.<init> Opening Searcher@6b7b9f29 main
[junit4:junit4]   2> 16523 T178 C4 P28853 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 16525 T155 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6b7b9f29 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C1)}
[junit4:junit4]   2> 16526 T178 C4 P28853 oasu.UpdateLog$LogReplayer.run WARNING Log replay finished. recoveryInfo=RecoveryInfo{adds=0 deletes=0 deleteByQuery=0 errors=0 positionOfStart=434}
[junit4:junit4]   2> 16526 T156 C4 P28853 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 16528 T156 C4 P28853 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 16535 T95 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 16970 T117 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 16985 T130 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 16985 T175 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 16985 T142 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 16985 T154 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 16985 T116 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 16985 T173 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 16985 T168 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 17537 T95 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2>  C6_STATE=coll:collection1 core:collection1 props:{shard=shard2, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:41457_solr, base_url=http://127.0.0.1:41457/solr}
[junit4:junit4]   2> 18335 T170 C6 P41457 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 18335 T170 C6 P41457 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 18335 T170 C6 P41457 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:53205/solr/collection1/. core=collection1
[junit4:junit4]   2> 18336 T170 C6 P41457 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 18352 T136 C7 P53205 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 18357 T136 C7 P53205 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty2/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 18357 T136 C7 P53205 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 18359 T136 C7 P53205 oass.SolrIndexSearcher.<init> Opening Searcher@3e1af961 main
[junit4:junit4]   2> 18359 T136 C7 P53205 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 18362 T143 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3e1af961 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 18362 T136 C7 P53205 /update {waitSearcher=true&commit=true&commit_end_point=true&wt=javabin&softCommit=false&version=2} {commit=} 0 10
[junit4:junit4]   2> 18363 T170 C6 P41457 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 18364 T170 C6 P41457 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 18366 T137 C7 P53205 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 18366 T137 C7 P53205 REQ /replication {command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
[junit4:junit4]   2> 18371 T170 C6 P41457 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty4/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 18372 T170 C6 P41457 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 18372 T170 C6 P41457 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 18375 T170 C6 P41457 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty4/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty4/index,segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 18375 T170 C6 P41457 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 18379 T170 C6 P41457 oass.SolrIndexSearcher.<init> Opening Searcher@6fec9818 main
[junit4:junit4]   2> 18379 T170 C6 P41457 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 18381 T169 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6fec9818 main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 18382 T170 C6 P41457 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 18382 T170 C6 P41457 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 18389 T170 C6 P41457 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 18496 T117 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 18534 T168 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 18535 T142 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 18535 T154 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 18535 T175 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 18534 T116 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 18534 T130 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 18534 T173 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 18545 T95 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 18549 T108 C8 P38887 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 18606 T108 C8 P38887 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/control/data/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/control/data/index,segFN=segments_2,generation=2,filenames=[_0_Block_0.tip, _0_Block_0.pos, _0_Block_0.tim, _0_MockVariableIntBlock_0.doc, _0_MockVariableIntBlock_0.skp, _0_MockFixedIntBlock_0.tib, _0_Pulsing40_0.prx, _0_Pulsing40_0.frq, _0_MockVariableIntBlock_0.pyl, _0_MockFixedIntBlock_0.skp, _0_MockFixedIntBlock_0.pyl, _0_MockVariableIntBlock_0.tib, _0_MockFixedIntBlock_0.tii, _0_MockVariableIntBlock_0.pos, _0_Pulsing40_0.tip, _0.si, _0_MockVariableIntBlock_0.tii, _0.fnm, _0_Pulsing40_0.tim, _0_Block_0.doc, _0_MockFixedIntBlock_0.pos, _0_nrm.cfs, _0_MockFixedIntBlock_0.frq, _0_MockFixedIntBlock_0.doc, _0_MockVariableIntBlock_0.frq, _0_nrm.cfe, segments_2, _0.fdx, _0.fdt]
[junit4:junit4]   2> 18607 T108 C8 P38887 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 18624 T108 C8 P38887 oass.SolrIndexSearcher.<init> Opening Searcher@5b5bae99 main
[junit4:junit4]   2> 18625 T108 C8 P38887 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 18628 T119 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5b5bae99 main{StandardDirectoryReader(segments_2:3 _0(5.0):C1)}
[junit4:junit4]   2> 18629 T108 C8 P38887 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 80
[junit4:junit4]   2> 18631 T138 C7 P53205 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 18634 T138 C7 P53205 oass.SolrIndexSearcher.<init> Opening Searcher@250195d2 main
[junit4:junit4]   2> 18634 T138 C7 P53205 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 18636 T143 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@250195d2 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 18637 T138 C7 P53205 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:27077/solr/collection1/, StdNode: http://127.0.0.1:28853/solr/collection1/, StdNode: http://127.0.0.1:41457/solr/collection1/]
[junit4:junit4]   2> 18641 T127 C5 P27077 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2>  C4_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:28853_solr, base_url=http://127.0.0.1:28853/solr}
[junit4:junit4]   2> 18643 T146 C4 P28853 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 18644 T146 C4 P28853 oass.SolrIndexSearcher.<init> Opening Searcher@68d2ce63 main
[junit4:junit4]   2> 18645 T146 C4 P28853 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 18648 T155 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@68d2ce63 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C1)}
[junit4:junit4]   2> 18648 T146 C4 P28853 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&expungeDeletes=false&softCommit=false&version=2} {commit=} 0 6
[junit4:junit4]   2>  C6_STATE=coll:collection1 core:collection1 props:{shard=shard2, roles=null, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:41457_solr, base_url=http://127.0.0.1:41457/solr}
[junit4:junit4]   2> 18655 T160 C6 P41457 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 18656 T127 C5 P27077 oass.SolrIndexSearcher.<init> Opening Searcher@69af4318 main
[junit4:junit4]   2> 18657 T127 C5 P27077 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 18659 T160 C6 P41457 oass.SolrIndexSearcher.<init> Opening Searcher@617746b2 main
[junit4:junit4]   2> 18660 T160 C6 P41457 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 18661 T131 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@69af4318 main{StandardDirectoryReader(segments_2:3 _0(5.0):C1)}
[junit4:junit4]   2> 18661 T169 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@617746b2 main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 18662 T160 C6 P41457 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&expungeDeletes=false&softCommit=false&version=2} {commit=} 0 7
[junit4:junit4]   2> 18662 T127 C5 P27077 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&expungeDeletes=false&softCommit=false&version=2} {commit=} 0 21
[junit4:junit4]   2> 18663 T138 C7 P53205 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 32
[junit4:junit4]   2> 18765 T110 C8 P38887 REQ /select {fl=id,score&shard.url=127.0.0.1:38887/solr/collection1/&NOW=1347966808271&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=1 status=0 QTime=78 
[junit4:junit4]   2> 18786 T110 C8 P38887 REQ /select {shard.url=127.0.0.1:38887/solr/collection1/&NOW=1347966808271&q=*:*&ids=1&distrib=false&isShard=true&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 18788 T108 C8 P38887 REQ /select {wt=javabin&q=*:*&version=2} hits=1 status=0 QTime=106 
[junit4:junit4]   2> 18790 T95 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:31500/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@54b216b3
[junit4:junit4]   2> 18791 T183 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:31500
[junit4:junit4]   2> 18791 T95 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 18792 T183 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:31500, initiating session
[junit4:junit4]   2> 18792 T97 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:47701
[junit4:junit4]   2> 18793 T97 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:47701
[junit4:junit4]   2> 18802 T99 oazs.NIOServerCnxn.finishSessionInit Established session 0x139d914e7e20009 with negotiated timeout 10000 for client /140.211.11.196:47701
[junit4:junit4]   2> 18802 T183 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:31500, sessionid = 0x139d914e7e20009, negotiated timeout = 10000
[junit4:junit4]   2> 18803 T184 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@54b216b3 name:ZooKeeperConnection Watcher:127.0.0.1:31500/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 18803 T95 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 18804 T95 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 18807 T100 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x139d914e7e20009
[junit4:junit4]   2> 18807 T184 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 18807 T95 oaz.ZooKeeper.close Session: 0x139d914e7e20009 closed
[junit4:junit4]   2> 18811 T97 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:47701 which had sessionid 0x139d914e7e20009
[junit4:junit4]   2> 18813 T128 C5 P27077 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 18817 T139 C7 P53205 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 18825 T122 C5 P27077 REQ /select {fl=id,score&shard.url=127.0.0.1:27077/solr/collection1/|127.0.0.1:28853/solr/collection1/&NOW=1347966808409&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 18825 T140 C7 P53205 REQ /select {fl=id,score&shard.url=127.0.0.1:53205/solr/collection1/|127.0.0.1:41457/solr/collection1/&NOW=1347966808409&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 18830 T122 C5 P27077 REQ /select {shard.url=127.0.0.1:27077/solr/collection1/|127.0.0.1:28853/solr/collection1/&NOW=1347966808409&q=*:*&ids=1&distrib=false&isShard=true&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 18831 T161 C6 P41457 REQ /select {wt=javabin&q=*:*&version=2} hits=1 status=0 QTime=11 
[junit4:junit4]   2> 18842 T108 C8 P38887 /update {wt=javabin&version=2} {add=[2 (1413445644112101376)]} 0 6
[junit4:junit4]   2> 18864 T160 C6 P41457 REQ /update {distrib.from=http://127.0.0.1:53205/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 18865 T138 C7 P53205 /update {wt=javabin&version=2} {add=[2 (1413445644121538560)]} 0 20
[junit4:junit4]   2> 18872 T108 C8 P38887 /update {wt=javabin&version=2} {add=[3 (1413445644145655808)]} 0 4
[junit4:junit4]   2> 18886 T160 C6 P41457 REQ /update {distrib.from=http://127.0.0.1:53205/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 18887 T138 C7 P53205 /update {wt=javabin&version=2} {add=[3 (1413445644152995840)]} 0 12
[junit4:junit4]   2> 18894 T108 C8 P38887 /update {wt=javabin&version=2} {add=[4 (1413445644168724480)]} 0 4
[junit4:junit4]   2> 18911 T146 C4 P28853 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 18912 T124 C5 P27077 /update {wt=javabin&version=2} {add=[4 (1413445644176064512)]} 0 15
[junit4:junit4]   2> 18920 T108 C8 P38887 /update {wt=javabin&version=2} {add=[5 (1413445644195987456)]} 0 4
[junit4:junit4]   2> 18945 T160 C6 P41457 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53205/solr/collection1/&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 18946 T135 C7 P53205 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=14 
[junit4:junit4]   2> 18947 T124 C5 P27077 /update {wt=javabin&version=2} {add=[5]} 0 21
[junit4:junit4]   2> 18954 T108 C8 P38887 /update {wt=javabin&version=2} {add=[6 (1413445644231639040)]} 0 4
[junit4:junit4]   2> 18971 T160 C6 P41457 REQ /update {distrib.from=http://127.0.0.1:53205/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 18972 T138 C7 P53205 /update {wt=javabin&version=2} {add=[6 (1413445644240027648)]} 0 14
[junit4:junit4]   2> 18979 T108 C8 P38887 /update {wt=javabin&version=2} {add=[7 (1413445644258902016)]} 0 3
[junit4:junit4]   2> 18995 T160 C6 P41457 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53205/solr/collection1/&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 18996 T135 C7 P53205 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=11 
[junit4:junit4]   2> 18997 T124 C5 P27077 /update {wt=javabin&version=2} {add=[7]} 0 15
[junit4:junit4]   2> 19003 T108 C8 P38887 /update {wt=javabin&version=2} {add=[8 (1413445644284067840)]} 0 3
[junit4:junit4]   2> 19022 T146 C4 P28853 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:27077/solr/collection1/&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 19023 T127 C5 P27077 REQ /update {distrib.from=http://127.0.0.1:53205/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=13 
[junit4:junit4]   2> 19023 T138 C7 P53205 /update {wt=javabin&version=2} {add=[8]} 0 16
[junit4:junit4]   2> 19030 T108 C8 P38887 /update {wt=javabin&version=2} {add=[9 (1413445644312379392)]} 0 3
[junit4:junit4]   2> 19046 T160 C6 P41457 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53205/solr/collection1/&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 19046 T135 C7 P53205 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=10 
[junit4:junit4]   2> 19047 T124 C5 P27077 /update {wt=javabin&version=2} {add=[9]} 0 14
[junit4:junit4]   2> 19053 T108 C8 P38887 /update {wt=javabin&version=2} {add=[10 (1413445644336496640)]} 0 3
[junit4:junit4]   2> 19065 T146 C4 P28853 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 19066 T124 C5 P27077 /update {wt=javabin&version=2} {add=[10 (1413445644342788096)]} 0 10
[junit4:junit4]   2> 19104 T108 C8 P38887 /update {wt=javabin&version=2} {add=[11 (1413445644356419584)]} 0 35
[junit4:junit4]   2> 19122 T146 C4 P28853 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:27077/solr/collection1/&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 19123 T127 C5 P27077 REQ /update {distrib.from=http://127.0.0.1:53205/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=11 
[junit4:junit4]   2> 19123 T138 C7 P53205 /update {wt=javabin&version=2} {add=[11]} 0 14
[junit4:junit4]   2> 19132 T108 C8 P38887 /update {wt=javabin&version=2} {add=[12 (1413445644417236992)]} 0 5
[junit4:junit4]   2> 19147 T146 C4 P28853 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 19148 T124 C5 P27077 /update {wt=javabin&version=2} {add=[12 (1413445644425625600)]} 0 13
[junit4:junit4]   2> 19155 T108 C8 P38887 /update {wt=javabin&version=2} {add=[13 (1413445644442402816)]} 0 4
[junit4:junit4]   2> 19175 T146 C4 P28853 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:27077/solr/collection1/&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 19177 T127 C5 P27077 REQ /update {distrib.from=http://127.0.0.1:53205/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=15 
[junit4:junit4]   2> 19177 T138 C7 P53205 /update {wt=javabin&version=2} {add=[13]} 0 18
[junit4:junit4]   2> 19185 T108 C8 P38887 /update {wt=javabin&version=2} {add=[14 (1413445644473860096)]} 0 4
[junit4:junit4]   2> 19201 T146 C4 P28853 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:27077/solr/collection1/&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 19201 T127 C5 P27077 REQ /update {distrib.from=http://127.0.0.1:53205/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=9 
[junit4:junit4]   2> 19202 T138 C7 P53205 /update {wt=javabin&version=2} {add=[14]} 0 13
[junit4:junit4]   2> 19209 T108 C8 P38887 /update {wt=javabin&version=2} {add=[15 (1413445644500074496)]} 0 3
[junit4:junit4]   2> 19225 T146 C4 P28853 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 19226 T124 C5 P27077 /update {wt=javabin&version=2} {add=[15 (1413445644507414528)]} 0 12
[junit4:junit4]   2> 19232 T108 C8 P38887 /update {wt=javabin&version=2} {add=[16 (1413445644524191744)]} 0 3
[junit4:junit4]   2> 19246 T146 C4 P28853 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 19247 T124 C5 P27077 /update {wt=javabin&version=2} {add=[16 (1413445644530483200)]} 0 11
[junit4:junit4]   2> 19263 T108 C8 P38887 /update {wt=javabin&version=2} {add=[17 (1413445644549357568)]} 0 12
[junit4:junit4]   2> 19302 T160 C6 P41457 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53205/solr/collection1/&wt=javabin&version=2} status=0 QTime=12 
[junit4:junit4]   2> 19303 T135 C7 P53205 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=28 
[junit4:junit4]   2> 19304 T124 C5 P27077 /update {wt=javabin&version=2} {add=[17]} 0 36
[junit4:junit4]   2> 19311 T108 C8 P38887 /update {wt=javabin&version=2} {add=[100 (1413445644605980672)]} 0 4
[junit4:junit4]   2> 19377 T146 C4 P28853 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=29 
[junit4:junit4]   2> 19378 T124 C5 P27077 /update {wt=javabin&version=2} {add=[100 (1413445644613320704)]} 0 64
[junit4:junit4]   2> 19385 T108 C8 P38887 /update {wt=javabin&version=2} {add=[101 (1413445644683575296)]} 0 3
[junit4:junit4]   2> 19406 T146 C4 P28853 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:27077/solr/collection1/&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 19407 T127 C5 P27077 REQ /update {distrib.from=http://127.0.0.1:53205/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=13 
[junit4:junit4]   2> 19408 T138 C7 P53205 /update {wt=javabin&version=2} {add=[101]} 0 18
[junit4:junit4]   2> 19414 T108 C8 P38887 /update {wt=javabin&version=2} {add=[102 (1413445644715032576)]} 0 3
[junit4:junit4]   2> 19426 T146 C4 P28853 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 19427 T124 C5 P27077 /update {wt=javabin&version=2} {add=[102 (1413445644721324032)]} 0 10
[junit4:junit4]   2> 19461 T108 C8 P38887 /update {wt=javabin&version=2} {add=[103 (1413445644734955520)]} 0 31
[junit4:junit4]   2> 19477 T160 C6 P41457 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53205/solr/collection1/&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 19477 T135 C7 P53205 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=9 
[junit4:junit4]   2> 19478 T124 C5 P27077 /update {wt=javabin&version=2} {add=[103]} 0 14
[junit4:junit4]   2> 19485 T108 C8 P38887 /update {wt=javabin&version=2} {add=[104 (1413445644788432896)]} 0 4
[junit4:junit4]   2> 19499 T160 C6 P41457 REQ /update {distrib.from=http://127.0.0.1:53205/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 19499 T138 C7 P53205 /update {wt=javabin&version=2} {add=[104 (1413445644795772928)]} 0 10
[junit4:junit4]   2> 19505 T108 C8 P38887 /update {wt=javabin&version=2} {add=[105 (1413445644810452992)]} 0 2
[junit4:junit4]   2> 19595 T160 C6 P41457 REQ /update {distrib.from=http://127.0.0.1:53205/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=28 
[junit4:junit4]   2> 19596 T138 C7 P53205 /update {wt=javabin&version=2} {add=[105 (1413445644816744448)]} 0 87
[junit4:junit4]   2> 19602 T108 C8 P38887 /update {wt=javabin&version=2} {add=[106 (1413445644912164864)]} 0 3
[junit4:junit4]   2> 19615 T160 C6 P41457 REQ /update {distrib.from=http://127.0.0.1:53205/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 19616 T138 C7 P53205 /update {wt=javabin&version=2} {add=[106 (1413445644918456320)]} 0 11
[junit4:junit4]   2> 19621 T108 C8 P38887 /update {wt=javabin&version=2} {add=[107 (1413445644933136384)]} 0 2
[junit4:junit4]   2> 19631 T146 C4 P28853 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 19631 T124 C5 P27077 /update {wt=javabin&version=2} {add=[107 (1413445644937330688)]} 0 7
[junit4:junit4]   2> 19636 T108 C8 P38887 /update {wt=javabin&version=2} {add=[108 (1413445644947816448)]} 0 2
[junit4:junit4]   2> 19648 T146 C4 P28853 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:27077/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 19649 T127 C5 P27077 REQ /update {distrib.from=http://127.0.0.1:53205/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 19649 T138 C7 P53205 /update {wt=javabin&version=2} {add=[108]} 0 10
[junit4:junit4]   2> 19654 T108 C8 P38887 /update {wt=javabin&version=2} {add=[109 (1413445644967739392)]} 0 2
[junit4:junit4]   2> 19663 T146 C4 P28853 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 19664 T124 C5 P27077 /update {wt=javabin&version=2} {add=[109 (1413445644971933696)]} 0 7
[junit4:junit4]   2> 19669 T108 C8 P38887 /update {wt=javabin&version=2} {add=[110 (1413445644983468032)]} 0 2
[junit4:junit4]   2> 19681 T146 C4 P28853 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:27077/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 19682 T127 C5 P27077 REQ /update {distrib.from=http://127.0.0.1:53205/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 19683 T138 C7 P53205 /update {wt=javabin&version=2} {add=[110]} 0 11
[junit4:junit4]   2> 19688 T108 C8 P38887 /update {wt=javabin&version=2} {add=[111 (1413445645003390976)]} 0 2
[junit4:junit4]   2> 19699 T146 C4 P28853 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 19699 T124 C5 P27077 /update {wt=javabin&version=2} {add=[111 (1413445645008633856)]} 0 8
[junit4:junit4]   2> 19705 T108 C8 P38887 /update {wt=javabin&version=2} {add=[112 (1413445645021216768)]} 0 2
[junit4:junit4]   2> 19718 T160 C6 P41457 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53205/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 19719 T135 C7 P53205 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=8 
[junit4:junit4]   2> 19720 T124 C5 P27077 /update {wt=javabin&version=2} {add=[112]} 0 12
[junit4:junit4]   2> 19745 T108 C8 P38887 /update {wt=javabin&version=2} {add=[113 (1413445645042188288)]} 0 22
[junit4:junit4]   2> 19760 T146 C4 P28853 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:27077/solr/collection1/&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 19761 T127 C5 P27077 REQ /update {distrib.from=http://127.0.0.1:53205/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=9 
[junit4:junit4]   2> 19761 T138 C7 P53205 /update {wt=javabin&version=2} {add=[113]} 0 12
[junit4:junit4]   2> 19768 T108 C8 P38887 /update {wt=javabin&version=2} {add=[114 (1413445645085179904)]} 0 4
[junit4:junit4]   2> 19781 T146 C4 P28853 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:27077/solr/collection1/&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 19781 T127 C5 P27077 REQ /update {distrib.from=http://127.0.0.1:53205/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 19782 T138 C7 P53205 /update {wt=javabin&version=2} {add=[114]} 0 11
[junit4:junit4]   2> 19787 T108 C8 P38887 /update {wt=javabin&version=2} {add=[115 (1413445645107200000)]} 0 2
[junit4:junit4]   2> 19797 T160 C6 P41457 REQ /update {distrib.from=http://127.0.0.1:53205/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 19798 T138 C7 P53205 /update {wt=javabin&version=2} {add=[115 (1413445645112442880)]} 0 8
[junit4:junit4]   2> 19804 T108 C8 P38887 /update {wt=javabin&version=2} {add=[116 (1413445645125025792)]} 0 2
[junit4:junit4]   2> 19813 T160 C6 P41457 REQ /update {distrib.from=http://127.0.0.1:53205/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 19814 T138 C7 P53205 /update {wt=javabin&version=2} {add=[116 (1413445645129220096)]} 0 7
[junit4:junit4]   2> 19819 T108 C8 P38887 /update {wt=javabin&version=2} {add=[117 (1413445645139705856)]} 0 2
[junit4:junit4]   2> 19831 T160 C6 P41457 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53205/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 19831 T135 C7 P53205 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 19832 T124 C5 P27077 /update {wt=javabin&version=2} {add=[117]} 0 10
[junit4:junit4]   2> 19837 T108 C8 P38887 /update {wt=javabin&version=2} {add=[118 (1413445645158580224)]} 0 2
[junit4:junit4]   2> 19888 T146 C4 P28853 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:27077/solr/collection1/&wt=javabin&version=2} status=0 QTime=21 
[junit4:junit4]   2> 19889 T127 C5 P27077 REQ /update {distrib.from=http://127.0.0.1:53205/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=47 
[junit4:junit4]   2> 19889 T138 C7 P53205 /update {wt=javabin&version=2} {add=[118]} 0 50
[junit4:junit4]   2> 19894 T108 C8 P38887 /update {wt=javabin&version=2} {add=[119 (1413445645218349056)]} 0 2
[junit4:junit4]   2> 19906 T160 C6 P41457 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53205/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 19907 T135 C7 P53205 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 19907 T124 C5 P27077 /update {wt=javabin&version=2} {add=[119]} 0 10
[junit4:junit4]   2> 19912 T108 C8 P38887 /update {wt=javabin&version=2} {add=[120 (1413445645237223424)]} 0 2
[junit4:junit4]   2> 19921 T160 C6 P41457 REQ /update {distrib.from=http://127.0.0.1:53205/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 19921 T138 C7 P53205 /update {wt=javabin&version=2} {add=[120 (1413445645242466304)]} 0 6
[junit4:junit4]   2> 19926 T108 C8 P38887 /update {wt=javabin&version=2} {add=[121 (1413445645251903488)]} 0 2
[junit4:junit4]   2> 19934 T160 C6 P41457 REQ /update {distrib.from=http://127.0.0.1:53205/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 19934 T138 C7 P53205 /update {wt=javabin&version=2} {add=[121 (1413445645256097792)]} 0 6
[junit4:junit4]   2> 19939 T108 C8 P38887 /update {wt=javabin&version=2} {add=[122 (1413445645265534976)]} 0 2
[junit4:junit4]   2> 19951 T146 C4 P28853 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 19952 T124 C5 P27077 /update {wt=javabin&version=2} {add=[122 (1413445645270777856)]} 0 11
[junit4:junit4]   2> 19977 T108 C8 P38887 /update {wt=javabin&version=2} {add=[123 (1413445645285457920)]} 0 22
[junit4:junit4]   2> 19989 T146 C4 P28853 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 19990 T124 C5 P27077 /update {wt=javabin&version=2} {add=[123 (1413445645312720896)]} 0 9
[junit4:junit4]   2> 20004 T108 C8 P38887 /update {wt=javabin&version=2} {add=[124 (1413445645324255232)]} 0 11
[junit4:junit4]   2> 20014 T146 C4 P28853 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 20015 T124 C5 P27077 /update {wt=javabin&version=2} {add=[124 (1413445645341032448)]} 0 7
[junit4:junit4]   2> 20020 T108 C8 P38887 /update {wt=javabin&version=2} {add=[125 (1413445645351518208)]} 0 2
[junit4:junit4]   2> 20036 T146 C4 P28853 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:27077/solr/collection1/&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 20037 T127 C5 P27077 REQ /update {distrib.from=http://127.0.0.1:53205/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=11 
[junit4:junit4]   2> 20037 T138 C7 P53205 /update {wt=javabin&version=2} {add=[125]} 0 14
[junit4:junit4]   2> 20042 T108 C8 P38887 /update {wt=javabin&version=2} {add=[126 (1413445645373538304)]} 0 2
[junit4:junit4]   2> 20053 T160 C6 P41457 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53205/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 20053 T135 C7 P53205 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 20054 T124 C5 P27077 /update {wt=javabin&version=2} {add=[126]} 0 10
[junit4:junit4]   2> 20059 T108 C8 P38887 /update {wt=javabin&version=2} {add=[127 (1413445645392412672)]} 0 2
[junit4:junit4]   2> 20101 T160 C6 P41457 REQ /update {distrib.from=http://127.0.0.1:53205/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=17 
[junit4:junit4]   2> 20101 T138 C7 P53205 /update {wt=javabin&version=2} {add=[127 (1413445645396606976)]} 0 39
[junit4:junit4]   2> 20106 T108 C8 P38887 /update {wt=javabin&version=2} {add=[128 (1413445645441695744)]} 0 2
[junit4:junit4]   2> 20124 T160 C6 P41457 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53205/solr/collection1/&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 20125 T135 C7 P53205 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=13 
[junit4:junit4]   2> 20126 T124 C5 P27077 /update {wt=javabin&version=2} {add=[128]} 0 17
[junit4:junit4]   2> 20130 T108 C8 P38887 /update {wt=javabin&version=2} {add=[129 (1413445645466861568)]} 0 2
[junit4:junit4]   2> 20139 T146 C4 P28853 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 20140 T124 C5 P27077 /update {wt=javabin&version=2} {add=[129 (1413445645472104448)]} 0 7
[junit4:junit4]   2> 20145 T108 C8 P38887 /update {wt=javabin&version=2} {add=[130 (1413445645481541632)]} 0 2
[junit4:junit4]   2> 20154 T160 C6 P41457 REQ /update {distrib.from=http://127.0.0.1:53205/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 20154 T138 C7 P53205 /update {wt=javabin&version=2} {add=[130 (1413445645485735936)]} 0 7
[junit4:junit4]   2> 20159 T108 C8 P38887 /update {wt=javabin&version=2} {add=[131 (1413445645497270272)]} 0 2
[junit4:junit4]   2> 20169 T160 C6 P41457 REQ /update {distrib.from=http://127.0.0.1:53205/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 20170 T138 C7 P53205 /update {wt=javabin&version=2} {add=[131 (1413445645501464576)]} 0 8
[junit4:junit4]   2> 20174 T108 C8 P38887 /update {wt=javabin&version=2} {add=[132 (1413445645512998912)]} 0 2
[junit4:junit4]   2> 20186 T146 C4 P28853 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:27077/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 20187 T127 C5 P27077 REQ /update {distrib.from=http://127.0.0.1:53205/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 20188 T138 C7 P53205 /update {wt=javabin&version=2} {add=[132]} 0 11
[junit4:junit4]   2> 20209 T108 C8 P38887 /update {wt=javabin&version=2} {add=[133 (1413445645531873280)]} 0 18
[junit4:junit4]   2> 20218 T146 C4 P28853 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 20219 T124 C5 P27077 /update {wt=javabin&version=2} {add=[133 (1413445645554941952)]} 0 7
[junit4:junit4]   2> 20225 T108 C8 P38887 /update {wt=javabin&version=2} {add=[134 (1413445645564379136)]} 0 3
[junit4:junit4]   2> 20235 T160 C6 P41457 REQ /update {distrib.from=http://127.0.0.1:53205/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 20236 T138 C7 P53205 /update {wt=javabin&version=2} {add=[134 (1413445645571719168)]} 0 8
[junit4:junit4]   2> 20241 T108 C8 P38887 /update {wt=javabin&version=2} {add=[135 (1413445645583253504)]} 0 2
[junit4:junit4]   2> 20254 T146 C4 P28853 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:27077/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 20254 T127 C5 P27077 REQ /update {distrib.from=http://127.0.0.1:53205/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 20255 T138 C7 P53205 /update {wt=javabin&version=2} {add=[135]} 0 11
[junit4:junit4]   2> 20260 T108 C8 P38887 /update {wt=javabin&version=2} {add=[136 (1413445645602127872)]} 0 2
[junit4:junit4]   2> 20271 T160 C6 P41457 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53205/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 20271 T135 C7 P53205 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 20273 T124 C5 P27077 /update {wt=javabin&version=2} {add=[136]} 0 11
[junit4:junit4]   2> 20278 T108 C8 P38887 /update {wt=javabin&version=2} {add=[137 (1413445645621002240)]} 0 2
[junit4:junit4]   2> 20286 T160 C6 P41457 REQ /update {distrib.from=http://127.0.0.1:53205/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 20286 T138 C7 P53205 /update {wt=javabin&version=2} {add=[137 (1413445645625196544)]} 0 6
[junit4:junit4]   2> 20291 T108 C8 P38887 /update {wt=javabin&version=2} {add=[138 (1413445645634633728)]} 0 2
[junit4:junit4]   2> 20300 T146 C4 P28853 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 20300 T124 C5 P27077 /update {wt=javabin&version=2} {add=[138 (1413445645639876608)]} 0 7
[junit4:junit4]   2> 20305 T108 C8 P38887 /update {wt=javabin&version=2} {add=[139 (1413445645649313792)]} 0 2
[junit4:junit4]   2> 20317 T160 C6 P41457 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53205/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 20318 T135 C7 P53205 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 20318 T124 C5 P27077 /update {wt=javabin&version=2} {add=[139]} 0 10
[junit4:junit4]   2> 20323 T108 C8 P38887 /update {wt=javabin&version=2} {add=[140 (1413445645668188160)]} 0 2
[junit4:junit4]   2> 20335 T160 C6 P41457 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53205/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 20335 T135 C7 P53205 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 20336 T124 C5 P27077 /update {wt=javabin&version=2} {add=[140]} 0 10
[junit4:junit4]   2> 20341 T108 C8 P38887 /update {wt=javabin&version=2} {add=[141 (1413445645688111104)]} 0 2
[junit4:junit4]   2> 20350 T160 C6 P41457 REQ /update {distrib.from=http://127.0.0.1:53205/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 20350 T138 C7 P53205 /update {wt=javabin&version=2} {add=[141 (1413445645692305408)]} 0 6
[junit4:junit4]   2> 20355 T108 C8 P38887 /update {wt=javabin&version=2} {add=[142 (1413445645702791168)]} 0 2
[junit4:junit4]   2> 20395 T160 C6 P41457 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53205/solr/collection1/&wt=javabin&version=2} status=0 QTime=16 
[junit4:junit4]   2> 20396 T135 C7 P53205 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=35 
[junit4:junit4]   2> 20397 T124 C5 P27077 /update {wt=javabin&version=2} {add=[142]} 0 39
[junit4:junit4]   2> 20416 T108 C8 P38887 /update {wt=javabin&version=2} {add=[143 (1413445645752074240)]} 0 16
[junit4:junit4]   2> 20427 T160 C6 P41457 REQ /update {distrib.from=http://127.0.0.1:53205/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 20428 T138 C7 P53205 /update {wt=javabin&version=2} {add=[143 (1413445645771997184)]} 0 9
[junit4:junit4]   2> 20434 T108 C8 P38887 /update {wt=javabin&version=2} {add=[144 (1413445645783531520)]} 0 3
[junit4:junit4]   2> 20444 T160 C6 P41457 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53205/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 20445 T135 C7 P53205 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 20446 T124 C5 P27077 /update {wt=javabin&version=2} {add=[144]} 0 10
[junit4:junit4]   2> 20450 T108 C8 P38887 /update {wt=javabin&version=2} {add=[145 (1413445645802405888)]} 0 1
[junit4:junit4]   2> 20462 T160 C6 P41457 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53205/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 20462 T135 C7 P53205 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 20463 T124 C5 P27077 /update {wt=javabin&version=2} {add=[145]} 0 10
[junit4:junit4]   2> 20468 T108 C8 P38887 /update {wt=javabin&version=2} {add=[146 (1413445645821280256)]} 0 1
[junit4:junit4]   2> 20505 T146 C4 P28853 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=16 
[junit4:junit4]   2> 20506 T124 C5 P27077 /update {wt=javabin&version=2} {add=[146 (1413445645825474560)]} 0 35
[junit4:junit4]   2> 20512 T108 C8 P38887 /update {wt=javabin&version=2} {add=[147 (1413445645866369024)]} 0 2
[junit4:junit4]   2> 20520 T160 C6 P41457 REQ /update {distrib.from=http://127.0.0.1:53205/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 20521 T138 C7 P53205 /update {wt=javabin&version=2} {add=[147 (1413445645871611904)]} 0 6
[junit4:junit4]   2> 20525 T108 C8 P38887 /update {wt=javabin&version=2} {add=[148 (1413445645881049088)]} 0 1
[junit4:junit4]   2> 20536 T146 C4 P28853 REQ /update {distrib.from=http://127.0.0.1:27077/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 20536 T124 C5 P27077 /update {wt=javabin&version=2} {add=[148 (1413445645885243392)]} 0 8
[junit4:junit4]   2> 20540 T108 C8 P38887 /update {wt=javabin&version=2} {add=[149 (1413445645896777728)]} 0 1
[junit4:junit4]   2> 20547 T160 C6 P41457 REQ /update {distrib.from=http://127.0.0.1:53205/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 20548 T138 C7 P53205 /update {wt=javabin&version=2} {add=[149 (1413445645900972032)]} 0 5
[junit4:junit4]   2> 20549 T95 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):1800
[junit4:junit4]   2> 20550 T95 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 20554 T108 C8 P38887 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 21214 T108 C8 P38887 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/control/data/index,segFN=segments_2,generation=2,filenames=[_0_Block_0.tip, _0_Block_0.pos, _0_Block_0.tim, _0_MockVariableIntBlock_0.doc, _0_MockVariableIntBlock_0.skp, _0_MockFixedIntBlock_0.tib, _0_Pulsing40_0.prx, _0_Pulsing40_0.frq, _0_MockVariableIntBlock_0.pyl, _0_MockFixedIntBlock_0.skp, _0_MockFixedIntBlock_0.pyl, _0_MockVariableIntBlock_0.tib, _0_MockFixedIntBlock_0.tii, _0_MockVariableIntBlock_0.pos, _0_Pulsing40_0.tip, _0.si, _0_MockVariableIntBlock_0.tii, _0.fnm, _0_Pulsing40_0.tim, _0_Block_0.doc, _0_MockFixedIntBlock_0.pos, _0_nrm.cfs, _0_MockFixedIntBlock_0.frq, _0_MockFixedIntBlock_0.doc, _0_MockVariableIntBlock_0.frq, _0_nrm.cfe, segments_2, _0.fdx, _0.fdt]
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/control/data/index,segFN=segments_3,generation=3,filenames=[_5_nrm.cfe, _6_MockFixedIntBlock_0.pyl, _3_MockVariableIntBlock_0.frq, _3.fdt, _4_MockVariableIntBlock_0.tii, _6_MockFixedIntBlock_0.skp, _7.fnm, _5_Pulsing40_0.tip, _7_MockFixedIntBlock_0.pos, _7_MockFixedIntBlock_0.skp, _5_Pulsing40_0.tim, _6_MockVariableIntBlock_0.tii, _1_Block_0.pos, _0_Pulsing40_0.tim, _6_MockVariableIntBlock_0.tib, _4_MockFixedIntBlock_0.pos, _1_MockVariableIntBlock_0.tii, _1_MockVariableIntBlock_0.tib, _1.fdx, _4_MockVariableIntBlock_0.tib, _1.fdt, _5_nrm.cfs, _0_MockVariableIntBlock_0.frq, _4_MockFixedIntBlock_0.frq, _1_MockFixedIntBlock_0.pos, _6.fdt, _3_Pulsing40_0.frq, _2.si, _1_MockVariableIntBlock_0.skp, _2_Pulsing40_0.tim, _7_MockVariableIntBlock_0.pos, _2_Block_0.tim, _3_MockFixedIntBlock_0.frq, _0_MockVariableIntBlock_0.doc, _2_Block_0.tip, _2_Pulsing40_0.tip, _6.fdx, _1_MockVariableIntBlock_0.pyl, _6_MockFixedIntBlock_0.tib, _6_MockFixedIntBlock_0.tii, _3_MockVariableIntBlock_0.tii, _2_nrm.cfe, _5_Pulsing40_0.frq, _0_Pulsing40_0.tip, _0_MockVariableIntBlock_0.pos, _2_nrm.cfs, _7_MockVariableIntBlock_0.skp, _6_MockFixedIntBlock_0.doc, _5_MockFixedIntBlock_0.frq, _5_MockFixedIntBlock_0.tib, _4_MockVariableIntBlock_0.frq, _7_MockFixedIntBlock_0.doc, _2.fnm, _5_MockVariableIntBlock_0.frq, _7_Pulsing40_0.tim, _3.fdx, _4_Pulsing40_0.tip, _4_Pulsing40_0.tim, _1.si, _5_MockFixedIntBlock_0.tii, _7_Pulsing40_0.tip, _3_MockVariableIntBlock_0.pos, _3_nrm.cfe, _0_Block_0.tip, _3_MockFixedIntBlock_0.skp, _4_MockFixedIntBlock_0.tib, _5_MockVariableIntBlock_0.pyl, _0_Block_0.tim, _1_MockFixedIntBlock_0.pyl, _4_nrm.cfe, _0_Pulsing40_0.prx, _4.fdx, _1_Pulsing40_0.prx, _2_MockFixedIntBlock_0.frq, _4_MockFixedIntBlock_0.tii, _7_MockVariableIntBlock_0.tii, _1_Block_0.doc, _6_MockVariableIntBlock_0.frq, _3_MockVariableIntBlock_0.doc, _5.si, _3_nrm.cfs, _6_MockFixedIntBlock_0.pos, _4_MockVariableIntBlock_0.pyl, _5_MockFixedIntBlock_0.skp, _1_MockFixedIntBlock_0.skp, _4_MockFixedIntBlock_0.doc, _6_Pulsing40_0.prx, _4_nrm.cfs, _3_MockVariableIntBlock_0.tib, _5_MockVariableIntBlock_0.doc, _1_MockFixedIntBlock_0.doc, _6_MockVariableIntBlock_0.pyl, _3_MockFixedIntBlock_0.doc, _2_MockVariableIntBlock_0.frq, _6_nrm.cfs, _7_MockFixedIntBlock_0.tib, _7_nrm.cfs, _7_MockFixedIntBlock_0.tii, _4_MockFixedIntBlock_0.pyl, _1_MockFixedIntBlock_0.tii, _1_nrm.cfs, _5.fnm, _0_Block_0.doc, _7_nrm.cfe, _5_MockFixedIntBlock_0.pos, _6_nrm.cfe, _5_MockFixedIntBlock_0.doc, _7_MockFixedIntBlock_0.pyl, _4.fdt, _4.si, _1_nrm.cfe, _4_Pulsing40_0.frq, _1_MockFixedIntBlock_0.tib, _2_Block_0.pos, _6_MockFixedIntBlock_0.frq, _7.si, _0_MockFixedIntBlock_0.tib, _0_Pulsing40_0.frq, _0_MockFixedIntBlock_0.tii, _5_MockVariableIntBlock_0.tii, _1_Block_0.tip, _1_Block_0.tim, _4_MockVariableIntBlock_0.doc, _2.fdt, _3_Pulsing40_0.tip, _7.fdx, _7_MockVariableIntBlock_0.frq, _2.fdx, _7.fdt, _3_Pulsing40_0.tim, _7_Pulsing40_0.frq, _2_MockFixedIntBlock_0.doc, _3.si, _2_MockVariableIntBlock_0.skp, _2_MockVariableIntBlock_0.pyl, _2_MockFixedIntBlock_0.skp, _3.fnm, _2_MockVariableIntBlock_0.doc, _0_MockVariableIntBlock_0.pyl, _4_Pulsing40_0.prx, _0_MockFixedIntBlock_0.pyl, _1_MockVariableIntBlock_0.doc, _7_MockVariableIntBlock_0.pyl, _2_MockVariableIntBlock_0.tii, _5_MockVariableIntBlock_0.tib, _2_MockVariableIntBlock_0.tib, _1_MockVariableIntBlock_0.pos, _3_MockFixedIntBlock_0.pos, _0_MockFixedIntBlock_0.doc, _5_Pulsing40_0.prx, _3_MockVariableIntBlock_0.pyl, _6.fnm, _6.si, _7_MockVariableIntBlock_0.tib, _5.fdt, _1_Pulsing40_0.tip, _6_Pulsing40_0.frq, _1_Pulsing40_0.tim, _4.fnm, _0_MockVariableIntBlock_0.skp, _2_MockFixedIntBlock_0.tii, _1.fnm, _7_MockVariableIntBlock_0.doc, _7_Pulsing40_0.prx, _1_Pulsing40_0.frq, _3_MockFixedIntBlock_0.pyl, _2_MockFixedIntBlock_0.tib, _2_MockFixedIntBlock_0.pyl, _6_Pulsing40_0.tim, _6_Pulsing40_0.tip, _2_Pulsing40_0.prx, _6_MockVariableIntBlock_0.doc, _2_MockVariableIntBlock_0.pos, _0.fnm, _5_MockVariableIntBlock_0.pos, _1_MockFixedIntBlock_0.frq, _5_MockFixedIntBlock_0.pyl, _4_MockFixedIntBlock_0.skp, _0_MockFixedIntBlock_0.pos, _2_Pulsing40_0.frq, _2_MockFixedIntBlock_0.pos, _0_Block_0.pos, _7_MockFixedIntBlock_0.frq, _0_MockFixedIntBlock_0.skp, _4_MockVariableIntBlock_0.skp, _0_MockVariableIntBlock_0.tib, _5_MockVariableIntBlock_0.skp, _4_MockVariableIntBlock_0.pos, _6_MockVariableIntBlock_0.pos, _0.si, _0_MockVariableIntBlock_0.tii, _3_MockFixedIntBlock_0.tib, _0_nrm.cfs, _6_MockVariableIntBlock_0.skp, _0_MockFixedIntBlock_0.frq, _1_MockVariableIntBlock_0.frq, _3_Pulsing40_0.prx, _0_nrm.cfe, _5.fdx, _0.fdx, _2_Block_0.doc, _3_MockVariableIntBlock_0.skp, segments_3, _0.fdt, _3_MockFixedIntBlock_0.tii]
[junit4:junit4]   2> 21216 T108 C8 P38887 oasc.SolrDeletionPolicy.updateCommits newest commit = 3
[junit4:junit4]   2> 21446 T108 C8 P38887 oass.SolrIndexSearcher.<init> Opening Searcher@15def7ff main
[junit4:junit4]   2> 21447 T108 C8 P38887 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 21450 T119 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@15def7ff main{StandardDirectoryReader(segments_3:17 _0(5.0):C1 _1(5.0):C10 _2(5.0):C10 _3(5.0):C10 _4(5.0):C10 _5(5.0):C10 _6(5.0):C10 _7(5.0):C6)}
[junit4:junit4]   2> 21451 T108 C8 P38887 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 897
[junit4:junit4]   2> 21455 T138 C7 P53205 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 21754 T138 C7 P53205 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty2/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty2/index,segFN=segments_2,generation=2,filenames=[_3_MockVariableIntBlock_0.frq, _3.fdt, _0_MockFixedIntBlock_0.tib, _0_Pulsing40_0.frq, _0_MockFixedIntBlock_0.tii, _0_Pulsing40_0.tim, _1_MockVariableIntBlock_0.tii, _2.fdt, _3_Pulsing40_0.tip, _2.fdx, _3_Pulsing40_0.tim, _1_MockVariableIntBlock_0.tib, _1.fdx, _1.fdt, _0_MockVariableIntBlock_0.frq, _3.si, _2_MockFixedIntBlock_0.doc, _1_MockFixedIntBlock_0.pos, _2_MockVariableIntBlock_0.skp, _1_MockVariableIntBlock_0.skp, _2.si, _3_Pulsing40_0.frq, _2_Pulsing40_0.tim, _2_MockVariableIntBlock_0.pyl, _3_MockFixedIntBlock_0.frq, _0_MockVariableIntBlock_0.doc, _2_Pulsing40_0.tip, _2_MockFixedIntBlock_0.skp, _1_MockVariableIntBlock_0.pyl, _3.fnm, _2_MockVariableIntBlock_0.doc, _3_MockVariableIntBlock_0.tii, _0_MockVariableIntBlock_0.pyl, _2_nrm.cfe, _0_MockFixedIntBlock_0.pyl, _1_MockVariableIntBlock_0.doc, _0_MockVariableIntBlock_0.pos, _0_Pulsing40_0.tip, _2_nrm.cfs, _2_MockVariableIntBlock_0.tii, _2_MockVariabl

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

lrCore org.apache.solr.core.SolrCore@7e480e56
[junit4:junit4]   2> 313770 T168 oasc.JmxMonitoredMap$SolrDynamicMBean.getMBeanInfo WARNING Could not getStatistics on info bean Lazy[solr.ReplicationHandler] java.lang.IllegalArgumentException: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty4/index does not exist
[junit4:junit4]   2> 	at org.apache.commons.io.FileUtils.sizeOfDirectory(FileUtils.java:2074)
[junit4:junit4]   2> 	at org.apache.solr.handler.ReplicationHandler.getIndexSize(ReplicationHandler.java:477)
[junit4:junit4]   2> 	at org.apache.solr.handler.ReplicationHandler.getStatistics(ReplicationHandler.java:525)
[junit4:junit4]   2> 	at org.apache.solr.core.RequestHandlers$LazyRequestHandlerWrapper.getStatistics(RequestHandlers.java:310)
[junit4:junit4]   2> 	at org.apache.solr.core.JmxMonitoredMap$SolrDynamicMBean.getMBeanInfo(JmxMonitoredMap.java:231)
[junit4:junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.getClassName(DefaultMBeanServerInterceptor.java:1824)
[junit4:junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.safeGetClassName(DefaultMBeanServerInterceptor.java:1661)
[junit4:junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.checkMBeanPermission(DefaultMBeanServerInterceptor.java:1833)
[junit4:junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.getAttribute(DefaultMBeanServerInterceptor.java:680)
[junit4:junit4]   2> 	at com.sun.jmx.mbeanserver.JmxMBeanServer.getAttribute(JmxMBeanServer.java:672)
[junit4:junit4]   2> 	at org.apache.solr.core.JmxMonitoredMap.unregister(JmxMonitoredMap.java:174)
[junit4:junit4]   2> 	at org.apache.solr.core.JmxMonitoredMap.clear(JmxMonitoredMap.java:116)
[junit4:junit4]   2> 	at org.apache.solr.core.SolrCore.close(SolrCore.java:864)
[junit4:junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:213)
[junit4:junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:158)
[junit4:junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:102)
[junit4:junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:56)
[junit4:junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:131)
[junit4:junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:526)
[junit4:junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:502)
[junit4:junit4]   2> 
[junit4:junit4]   2> 313771 T168 oasc.JmxMonitoredMap$SolrDynamicMBean.getMBeanInfo WARNING Could not getStatistics on info bean Lazy[solr.ReplicationHandler] java.lang.IllegalArgumentException: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1347966789597/jetty4/index does not exist
[junit4:junit4]   2> 	at org.apache.commons.io.FileUtils.sizeOfDirectory(FileUtils.java:2074)
[junit4:junit4]   2> 	at org.apache.solr.handler.ReplicationHandler.getIndexSize(ReplicationHandler.java:477)
[junit4:junit4]   2> 	at org.apache.solr.handler.ReplicationHandler.getStatistics(ReplicationHandler.java:525)
[junit4:junit4]   2> 	at org.apache.solr.core.RequestHandlers$LazyRequestHandlerWrapper.getStatistics(RequestHandlers.java:310)
[junit4:junit4]   2> 	at org.apache.solr.core.JmxMonitoredMap$SolrDynamicMBean.getMBeanInfo(JmxMonitoredMap.java:231)
[junit4:junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.getClassName(DefaultMBeanServerInterceptor.java:1824)
[junit4:junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.safeGetClassName(DefaultMBeanServerInterceptor.java:1661)
[junit4:junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.checkMBeanPermission(DefaultMBeanServerInterceptor.java:1833)
[junit4:junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.exclusiveUnregisterMBean(DefaultMBeanServerInterceptor.java:436)
[junit4:junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.unregisterMBean(DefaultMBeanServerInterceptor.java:421)
[junit4:junit4]   2> 	at com.sun.jmx.mbeanserver.JmxMBeanServer.unregisterMBean(JmxMBeanServer.java:540)
[junit4:junit4]   2> 	at org.apache.solr.core.JmxMonitoredMap.unregister(JmxMonitoredMap.java:175)
[junit4:junit4]   2> 	at org.apache.solr.core.JmxMonitoredMap.clear(JmxMonitoredMap.java:116)
[junit4:junit4]   2> 	at org.apache.solr.core.SolrCore.close(SolrCore.java:864)
[junit4:junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:213)
[junit4:junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:158)
[junit4:junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:102)
[junit4:junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:56)
[junit4:junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:131)
[junit4:junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:526)
[junit4:junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:502)
[junit4:junit4]   2> 
[junit4:junit4]   2> 313783 T168 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 313787 T168 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> 313788 T168 oasu.DefaultSolrCoreState.decref SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 313790 T168 oasu.DefaultSolrCoreState.decref Closing SolrCoreState - canceling any ongoing recovery
[junit4:junit4]   2> 313790 T168 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 313790 T168 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 313790 T168 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 313791 T168 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 313791 T168 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4136dc05 name:ZooKeeperConnection Watcher:127.0.0.1:31500/solr got event WatchedEvent state:Disconnected type:None path:null path:null type:None
[junit4:junit4]   2> 313791 T168 oascc.ConnectionManager.process Client->ZooKeeper status change trigger but we are already closed
[junit4:junit4]   2> 313791 T168 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> NOTE: test params are: codec=Lucene40: {n_f1=Pulsing40(freqCutoff=7 minBlockSize=83 maxBlockSize=225), foo_b=Block(blocksize=128), foo_d=MockFixedIntBlock(blockSize=1023), foo_f=Block(blocksize=128), n_tl1=Pulsing40(freqCutoff=7 minBlockSize=83 maxBlockSize=225), n_d1=MockVariableIntBlock(baseBlockSize=105), rnd_b=MockFixedIntBlock(blockSize=1023), intDefault=Pulsing40(freqCutoff=7 minBlockSize=83 maxBlockSize=225), n_td1=Pulsing40(freqCutoff=7 minBlockSize=83 maxBlockSize=225), id=MockFixedIntBlock(blockSize=1023), timestamp=MockVariableIntBlock(baseBlockSize=105), range_facet_sl=MockFixedIntBlock(blockSize=1023), range_facet_si=MockVariableIntBlock(baseBlockSize=105), oddField_s=MockFixedIntBlock(blockSize=1023), multiDefault=MockVariableIntBlock(baseBlockSize=105), n_tf1=MockVariableIntBlock(baseBlockSize=105), n_dt1=Pulsing40(freqCutoff=7 minBlockSize=83 maxBlockSize=225), n_ti1=MockFixedIntBlock(blockSize=1023), range_facet_l=MockVariableIntBlock(baseBlockSize=105), text=Block(blocksize=128), _version_=Pulsing40(freqCutoff=7 minBlockSize=83 maxBlockSize=225), SubjectTerms_mfacet=Pulsing40(freqCutoff=7 minBlockSize=83 maxBlockSize=225), a_t=MockVariableIntBlock(baseBlockSize=105), n_tdt1=Pulsing40(freqCutoff=7 minBlockSize=83 maxBlockSize=225), other_tl1=Pulsing40(freqCutoff=7 minBlockSize=83 maxBlockSize=225), n_l1=MockVariableIntBlock(baseBlockSize=105), a_si=Pulsing40(freqCutoff=7 minBlockSize=83 maxBlockSize=225)}, sim=DefaultSimilarity, locale=en_PH, timezone=Australia/Hobart
[junit4:junit4]   2> NOTE: FreeBSD 9.0-RELEASE amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=2,free=82973880,total=121962496
[junit4:junit4]   2> NOTE: All tests run in this JVM: [BasicZkTest, ZkSolrClientTest, TestMergePolicyConfig, UUIDFieldTest, TestWriterPerf, TestRTGBase, TestUpdate, SolrInfoMBeanTest, TestPluginEnable, DirectSolrSpellCheckerTest, BasicDistributedZk2Test]
[junit4:junit4] Completed on J1 in 314.41s, 1 test, 1 failure <<< FAILURES!

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

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