lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache Jenkins Server <jenk...@builds.apache.org>
Subject [JENKINS] Lucene-Solr-Tests-4.x-java7 - Build # 471 - Failure
Date Wed, 19 Sep 2012 10:47:26 GMT
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-java7/471/

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([AB52D2962C147607:2AB45C8E5B4B163B]: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:601)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:722)




Build Log:
[...truncated 7725 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4:junit4]   2> 4 T965 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1348050513622
[junit4:junit4]   2> 5 T965 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 7 T966 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4]   2> 8 T966 oazs.NIOServerCnxn$Factory.<init> binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 8 T966 oazsp.FileTxnSnapLog.save Snapshotting: 0
[junit4:junit4]   2> 106 T965 oasc.ZkTestServer.run start zk server on port:39140
[junit4:junit4]   2> 106 T965 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:39140 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@711da449
[junit4:junit4]   2> 107 T971 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:39140
[junit4:junit4]   2> 107 T965 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 107 T971 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:39140, initiating session
[junit4:junit4]   2> 108 T967 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:39141
[junit4:junit4]   2> 108 T967 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:39141
[junit4:junit4]   2> 108 T969 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 110 T969 oazs.NIOServerCnxn.finishSessionInit Established session 0x139de126edb0000 with negotiated timeout 10000 for client /140.211.11.196:39141
[junit4:junit4]   2> 110 T971 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:39140, sessionid = 0x139de126edb0000, negotiated timeout = 10000
[junit4:junit4]   2> 111 T972 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@711da449 name:ZooKeeperConnection Watcher:127.0.0.1:39140 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 111 T965 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 111 T965 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 113 T970 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x139de126edb0000
[junit4:junit4]   2> 130 T972 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 130 T965 oaz.ZooKeeper.close Session: 0x139de126edb0000 closed
[junit4:junit4]   2> 130 T967 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:39141 which had sessionid 0x139de126edb0000
[junit4:junit4]   2> 130 T965 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:39140/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@22e41d90
[junit4:junit4]   2> 131 T973 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:39140
[junit4:junit4]   2> 131 T965 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 131 T973 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:39140, initiating session
[junit4:junit4]   2> 132 T967 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:39142
[junit4:junit4]   2> 132 T967 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:39142
[junit4:junit4]   2> 133 T969 oazs.NIOServerCnxn.finishSessionInit Established session 0x139de126edb0001 with negotiated timeout 10000 for client /140.211.11.196:39142
[junit4:junit4]   2> 133 T973 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:39140, sessionid = 0x139de126edb0001, negotiated timeout = 10000
[junit4:junit4]   2> 133 T974 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@22e41d90 name:ZooKeeperConnection Watcher:127.0.0.1:39140/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 133 T965 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 134 T965 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 143 T965 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 145 T965 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 146 T965 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 156 T965 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 156 T965 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 168 T965 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4]   2> 169 T965 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 271 T965 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 272 T965 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 274 T965 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4]   2> 275 T965 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 285 T965 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4]   2> 286 T965 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 287 T965 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4]   2> 288 T965 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 290 T965 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 290 T965 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 292 T965 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 292 T965 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 302 T965 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 302 T965 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 304 T965 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4]   2> 304 T965 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 311 T970 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x139de126edb0001
[junit4:junit4]   2> 312 T974 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 312 T965 oaz.ZooKeeper.close Session: 0x139de126edb0001 closed
[junit4:junit4]   2> 312 T967 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:39142 which had sessionid 0x139de126edb0001
[junit4:junit4]   2> 313 T965 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 316 T965 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:39143
[junit4:junit4]   2> 317 T965 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 317 T965 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 317 T965 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 344 T965 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 345 T965 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 345 T965 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr
[junit4:junit4]   2> 345 T965 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/solr.xml
[junit4:junit4]   2> 346 T965 oasc.CoreContainer.<init> New CoreContainer 1686674443
[junit4:junit4]   2> 346 T965 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 346 T965 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 368 T965 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 379 T965 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:39140/solr
[junit4:junit4]   2> 379 T965 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:39140/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@784b47c8
[junit4:junit4]   2> 380 T984 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:39140
[junit4:junit4]   2> 380 T965 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 381 T984 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:39140, initiating session
[junit4:junit4]   2> 381 T967 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:39144
[junit4:junit4]   2> 381 T967 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:39144
[junit4:junit4]   2> 382 T969 oazs.NIOServerCnxn.finishSessionInit Established session 0x139de126edb0002 with negotiated timeout 5000 for client /140.211.11.196:39144
[junit4:junit4]   2> 383 T984 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:39140, sessionid = 0x139de126edb0002, negotiated timeout = 5000
[junit4:junit4]   2> 383 T985 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@784b47c8 name:ZooKeeperConnection Watcher:127.0.0.1:39140/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 383 T965 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 384 T970 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139de126edb0002 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 394 T965 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 395 T965 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39143_solr
[junit4:junit4]   2> 395 T970 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139de126edb0002 type:delete cxid:0x7 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:39143_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:39143_solr
[junit4:junit4]   2> 396 T965 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:39143_solr
[junit4:junit4]   2> 406 T965 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 406 T965 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 406 T965 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 407 T965 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 407 T965 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 407 T965 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 408 T965 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 408 T965 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 408 T965 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 408 T965 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 420 T965 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 424 T970 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139de126edb0002 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> 434 T965 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 436 T965 oasc.Overseer.start Overseer (id=88345838461059074-127.0.0.1:39143_solr-n_0000000000) starting
[junit4:junit4]   2> 436 T970 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139de126edb0002 type:create cxid:0x1a zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 437 T970 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139de126edb0002 type:create cxid:0x1b zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 438 T970 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139de126edb0002 type:create cxid:0x1c zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 451 T970 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139de126edb0002 type:create cxid:0x1d zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 452 T987 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 452 T965 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 454 T965 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 455 T986 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 458 T965 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1
[junit4:junit4]   2> 458 T965 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 459 T965 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 459 T965 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 460 T965 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4]   2> 461 T965 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 461 T965 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4]   2> 495 T965 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_40
[junit4:junit4]   2> 542 T965 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 643 T965 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 647 T965 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 1162 T965 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 1174 T965 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 1178 T965 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 1190 T965 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1196 T965 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1200 T965 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1201 T965 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1202 T965 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/control/data/
[junit4:junit4]   2> 1204 T965 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@ac8df7b
[junit4:junit4]   2> 1238 T965 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/control/data/index/
[junit4:junit4]   2> 1240 T965 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/control/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 1241 T965 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/control/data/index forceNew:false
[junit4:junit4]   2> 1283 T965 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/control/data/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 1284 T965 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 1285 T965 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 1287 T965 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 1287 T965 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 1288 T965 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 1289 T965 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 1289 T965 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 1290 T965 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 1290 T965 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 1291 T965 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 1292 T965 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 1292 T965 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 1293 T965 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 1294 T965 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 1294 T965 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 1295 T965 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 1295 T965 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 1296 T965 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 1297 T965 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1297 T965 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1298 T965 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1299 T965 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1299 T965 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1300 T965 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1300 T965 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 1301 T965 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 1302 T965 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 1306 T965 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 1310 T965 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 1311 T965 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> 1316 T965 oass.SolrIndexSearcher.<init> Opening Searcher@5b34f2a2 main
[junit4:junit4]   2> 1317 T965 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 1317 T965 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 1318 T965 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 1326 T965 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 1372 T988 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5b34f2a2 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 1378 T970 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139de126edb0002 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> 1391 T965 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 1391 T965 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:39143/solr shardId:control_shard
[junit4:junit4]   2> 1392 T965 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/control_shard/election
[junit4:junit4]   2> 1408 T970 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139de126edb0002 type:delete cxid:0x62 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/collections/control_collection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/control_collection/leaders
[junit4:junit4]   2> 1409 T965 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 1409 T970 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139de126edb0002 type:create cxid:0x63 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 1457 T986 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 1458 T970 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139de126edb0002 type:create cxid:0x6a zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer/queue-work Error:KeeperErrorCode = NoNode for /solr/overseer/queue-work
[junit4:junit4]   2> 1473 T985 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 1918 T965 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 1919 T965 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 1919 T965 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:39143/solr/collection1/
[junit4:junit4]   2> 1920 T965 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 1920 T965 oasc.SyncStrategy.syncToMe http://127.0.0.1:39143/solr/collection1/ has no replicas
[junit4:junit4]   2> 1920 T965 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:39143/solr/collection1/
[junit4:junit4]   2> 1921 T965 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/control_shard
[junit4:junit4]   2> 1937 T970 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139de126edb0002 type:create cxid:0x88 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 1976 T986 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 1999 T985 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 2056 T965 oasc.ZkController.register We are http://127.0.0.1:39143/solr/collection1/ and leader is http://127.0.0.1:39143/solr/collection1/
[junit4:junit4]   2> 2056 T965 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:39143/solr
[junit4:junit4]   2> 2056 T965 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 2059 T965 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2060 T965 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1
[junit4:junit4]   2> 2060 T965 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 2061 T965 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 2178 T965 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 2181 T965 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:39145
[junit4:junit4]   2> 2181 T965 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 2181 T965 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty1-1348050515690
[junit4:junit4]   2> 2182 T965 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty1-1348050515690/'
[junit4:junit4]   2> 2209 T965 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 2209 T965 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 2210 T965 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty1-1348050515690
[junit4:junit4]   2> 2210 T965 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty1-1348050515690/solr.xml
[junit4:junit4]   2> 2210 T965 oasc.CoreContainer.<init> New CoreContainer 465297097
[junit4:junit4]   2> 2211 T965 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty1-1348050515690/'
[junit4:junit4]   2> 2211 T965 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty1-1348050515690/'
[junit4:junit4]   2> 2233 T965 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 2244 T965 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:39140/solr
[junit4:junit4]   2> 2244 T965 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:39140/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@1e9dc639
[junit4:junit4]   2> 2245 T998 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:39140
[junit4:junit4]   2> 2245 T965 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 2246 T998 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:39140, initiating session
[junit4:junit4]   2> 2246 T967 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:39146
[junit4:junit4]   2> 2246 T967 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:39146
[junit4:junit4]   2> 2248 T969 oazs.NIOServerCnxn.finishSessionInit Established session 0x139de126edb0003 with negotiated timeout 5000 for client /140.211.11.196:39146
[junit4:junit4]   2> 2248 T998 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:39140, sessionid = 0x139de126edb0003, negotiated timeout = 5000
[junit4:junit4]   2> 2248 T999 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e9dc639 name:ZooKeeperConnection Watcher:127.0.0.1:39140/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 2248 T965 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 2249 T970 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139de126edb0003 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2266 T970 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139de126edb0003 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2267 T965 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39145_solr
[junit4:junit4]   2> 2267 T970 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139de126edb0003 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:39145_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:39145_solr
[junit4:junit4]   2> 2268 T965 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:39145_solr
[junit4:junit4]   2> 2276 T985 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 2276 T965 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 2276 T965 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 2277 T965 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 2277 T965 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 2277 T965 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 2278 T965 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 2278 T965 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 2278 T965 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 2278 T965 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 2279 T965 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 2291 T965 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 2305 T965 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty1-1348050515690/collection1
[junit4:junit4]   2> 2306 T965 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 2306 T965 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 2307 T965 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 2307 T965 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty1-1348050515690/collection1/'
[junit4:junit4]   2> 2308 T965 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/solrtest-jetty1-1348050515690/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 2309 T965 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/solrtest-jetty1-1348050515690/collection1/lib/README' to classloader
[junit4:junit4]   2> 2343 T965 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_40
[junit4:junit4]   2> 2391 T965 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 2492 T965 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 2496 T965 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 2524 T986 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2542 T985 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 2542 T999 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 2925 T965 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 2934 T965 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 2936 T965 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 2945 T965 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 2949 T965 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 2952 T965 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 2953 T965 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 2954 T965 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty1-1348050515690/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty1/
[junit4:junit4]   2> 2954 T965 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@ac8df7b
[junit4:junit4]   2> 2955 T965 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty1/index/
[junit4:junit4]   2> 2956 T965 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 2956 T965 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty1/index forceNew:false
[junit4:junit4]   2> 2961 T965 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty1/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 2961 T965 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 2962 T965 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 2964 T965 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 2964 T965 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 2964 T965 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 2965 T965 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 2965 T965 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 2966 T965 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 2966 T965 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 2967 T965 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 2967 T965 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 2968 T965 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 2968 T965 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 2969 T965 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 2969 T965 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 2969 T965 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 2970 T965 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 2970 T965 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 2971 T965 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2971 T965 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2972 T965 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2972 T965 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2973 T965 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2973 T965 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2974 T965 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2974 T965 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 2975 T965 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 2977 T965 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 2981 T965 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 2981 T965 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> 2984 T965 oass.SolrIndexSearcher.<init> Opening Searcher@53c3f452 main
[junit4:junit4]   2> 2985 T965 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 2986 T965 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 2986 T965 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 2992 T965 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 3044 T1000 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@53c3f452 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 3546 T986 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3560 T985 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 3560 T999 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4054 T965 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 4054 T965 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:39145/solr shardId:shard1
[junit4:junit4]   2> 4055 T965 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 4070 T970 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139de126edb0003 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> 4071 T965 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 4071 T970 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139de126edb0003 type:create cxid:0x44 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4073 T965 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 4073 T965 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 4073 T965 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:39145/solr/collection1/
[junit4:junit4]   2> 4074 T965 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 4074 T965 oasc.SyncStrategy.syncToMe http://127.0.0.1:39145/solr/collection1/ has no replicas
[junit4:junit4]   2> 4075 T965 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:39145/solr/collection1/
[junit4:junit4]   2> 4075 T965 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 4078 T970 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139de126edb0003 type:create cxid:0x4e zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4571 T986 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4585 T985 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4585 T999 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 4589 T965 oasc.ZkController.register We are http://127.0.0.1:39145/solr/collection1/ and leader is http://127.0.0.1:39145/solr/collection1/
[junit4:junit4]   2> 4589 T965 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:39145/solr
[junit4:junit4]   2> 4589 T965 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 4591 T965 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4592 T965 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1
[junit4:junit4]   2> 4592 T965 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 4593 T965 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 4706 T965 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 4709 T965 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:39148
[junit4:junit4]   2> 4709 T965 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 4710 T965 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty2-1348050518222
[junit4:junit4]   2> 4710 T965 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty2-1348050518222/'
[junit4:junit4]   2> 4737 T965 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 4738 T965 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 4738 T965 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty2-1348050518222
[junit4:junit4]   2> 4738 T965 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty2-1348050518222/solr.xml
[junit4:junit4]   2> 4738 T965 oasc.CoreContainer.<init> New CoreContainer 1749562012
[junit4:junit4]   2> 4739 T965 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty2-1348050518222/'
[junit4:junit4]   2> 4739 T965 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty2-1348050518222/'
[junit4:junit4]   2> 4761 T965 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 4772 T965 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:39140/solr
[junit4:junit4]   2> 4772 T965 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:39140/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@10e886c
[junit4:junit4]   2> 4773 T1010 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:39140
[junit4:junit4]   2> 4773 T965 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 4774 T1010 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:39140, initiating session
[junit4:junit4]   2> 4774 T967 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:39149
[junit4:junit4]   2> 4775 T967 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:39149
[junit4:junit4]   2> 4776 T969 oazs.NIOServerCnxn.finishSessionInit Established session 0x139de126edb0004 with negotiated timeout 5000 for client /140.211.11.196:39149
[junit4:junit4]   2> 4776 T1010 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:39140, sessionid = 0x139de126edb0004, negotiated timeout = 5000
[junit4:junit4]   2> 4777 T1011 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10e886c name:ZooKeeperConnection Watcher:127.0.0.1:39140/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 4777 T965 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 4777 T970 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139de126edb0004 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4786 T970 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139de126edb0004 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4787 T965 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39148_solr
[junit4:junit4]   2> 4787 T970 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139de126edb0004 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:39148_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:39148_solr
[junit4:junit4]   2> 4793 T965 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:39148_solr
[junit4:junit4]   2> 4795 T985 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 4795 T999 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 4795 T965 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 4796 T965 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 4796 T965 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 4796 T965 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 4797 T965 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 4797 T965 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 4797 T965 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 4797 T965 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 4798 T965 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 4798 T965 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 4810 T965 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 4815 T965 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty2-1348050518222/collection1
[junit4:junit4]   2> 4815 T965 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 4815 T965 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 4816 T965 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 4816 T965 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty2-1348050518222/collection1/'
[junit4:junit4]   2> 4817 T965 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/solrtest-jetty2-1348050518222/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 4818 T965 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/solrtest-jetty2-1348050518222/collection1/lib/README' to classloader
[junit4:junit4]   2> 4852 T965 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_40
[junit4:junit4]   2> 4911 T965 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 5011 T965 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 5016 T965 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 5089 T986 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 5103 T1011 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5103 T999 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5103 T985 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5436 T965 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 5444 T965 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 5447 T965 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 5456 T965 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 5460 T965 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 5463 T965 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 5464 T965 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 5464 T965 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty2-1348050518222/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty2/
[junit4:junit4]   2> 5465 T965 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@ac8df7b
[junit4:junit4]   2> 5466 T965 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty2/index/
[junit4:junit4]   2> 5466 T965 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 5467 T965 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty2/index forceNew:false
[junit4:junit4]   2> 5472 T965 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty2/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 5472 T965 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 5472 T965 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 5474 T965 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 5475 T965 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 5475 T965 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 5475 T965 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 5476 T965 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 5476 T965 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 5477 T965 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 5477 T965 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 5478 T965 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 5478 T965 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 5479 T965 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 5479 T965 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 5480 T965 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 5480 T965 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 5480 T965 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 5481 T965 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 5482 T965 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5482 T965 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5482 T965 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5483 T965 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5483 T965 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5484 T965 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5484 T965 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 5485 T965 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 5486 T965 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 5488 T965 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 5491 T965 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 5492 T965 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> 5495 T965 oass.SolrIndexSearcher.<init> Opening Searcher@35ad54dd main
[junit4:junit4]   2> 5496 T965 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 5496 T965 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 5497 T965 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 5502 T965 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 5552 T1012 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@35ad54dd main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 5605 T986 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 5618 T985 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5618 T999 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 5618 T1011 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6058 T965 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 6058 T965 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:39148/solr shardId:shard2
[junit4:junit4]   2> 6059 T965 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4]   2> 6075 T970 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139de126edb0004 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> 6075 T965 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 6076 T970 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139de126edb0004 type:create cxid:0x43 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 6078 T965 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 6078 T965 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 6078 T965 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:39148/solr/collection1/
[junit4:junit4]   2> 6079 T965 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 6079 T965 oasc.SyncStrategy.syncToMe http://127.0.0.1:39148/solr/collection1/ has no replicas
[junit4:junit4]   2> 6080 T965 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:39148/solr/collection1/
[junit4:junit4]   2> 6080 T965 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4]   2> 6082 T970 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139de126edb0004 type:create cxid:0x4c zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 6120 T986 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6126 T985 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6126 T999 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6126 T1011 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6135 T965 oasc.ZkController.register We are http://127.0.0.1:39148/solr/collection1/ and leader is http://127.0.0.1:39148/solr/collection1/
[junit4:junit4]   2> 6135 T965 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:39148/solr
[junit4:junit4]   2> 6135 T965 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 6136 T965 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6137 T965 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1
[junit4:junit4]   2> 6137 T965 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 6138 T965 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 6250 T965 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 6252 T965 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:39152
[junit4:junit4]   2> 6253 T965 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 6253 T965 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty3-1348050519766
[junit4:junit4]   2> 6254 T965 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty3-1348050519766/'
[junit4:junit4]   2> 6281 T965 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 6281 T965 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 6282 T965 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty3-1348050519766
[junit4:junit4]   2> 6282 T965 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty3-1348050519766/solr.xml
[junit4:junit4]   2> 6282 T965 oasc.CoreContainer.<init> New CoreContainer 693571038
[junit4:junit4]   2> 6283 T965 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty3-1348050519766/'
[junit4:junit4]   2> 6283 T965 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty3-1348050519766/'
[junit4:junit4]   2> 6305 T965 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 6315 T965 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:39140/solr
[junit4:junit4]   2> 6316 T965 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:39140/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@75cb631a
[junit4:junit4]   2> 6317 T1022 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:39140
[junit4:junit4]   2> 6317 T965 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 6317 T1022 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:39140, initiating session
[junit4:junit4]   2> 6318 T967 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:39153
[junit4:junit4]   2> 6318 T967 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:39153
[junit4:junit4]   2> 6321 T969 oazs.NIOServerCnxn.finishSessionInit Established session 0x139de126edb0005 with negotiated timeout 5000 for client /140.211.11.196:39153
[junit4:junit4]   2> 6321 T1022 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:39140, sessionid = 0x139de126edb0005, negotiated timeout = 5000
[junit4:junit4]   2> 6321 T1023 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@75cb631a name:ZooKeeperConnection Watcher:127.0.0.1:39140/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 6322 T965 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 6323 T970 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139de126edb0005 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 6336 T970 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139de126edb0005 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 6337 T965 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39152_solr
[junit4:junit4]   2> 6338 T970 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139de126edb0005 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:39152_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:39152_solr
[junit4:junit4]   2> 6339 T965 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:39152_solr
[junit4:junit4]   2> 6348 T999 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 6348 T985 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 6348 T1011 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 6348 T965 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 6349 T965 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 6349 T965 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 6349 T965 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 6350 T965 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 6350 T965 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 6350 T965 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 6351 T965 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 6351 T965 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 6351 T965 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 6363 T965 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 6368 T965 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty3-1348050519766/collection1
[junit4:junit4]   2> 6368 T965 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 6369 T965 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 6369 T965 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 6370 T965 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty3-1348050519766/collection1/'
[junit4:junit4]   2> 6371 T965 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/solrtest-jetty3-1348050519766/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 6371 T965 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/solrtest-jetty3-1348050519766/collection1/lib/README' to classloader
[junit4:junit4]   2> 6406 T965 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_40
[junit4:junit4]   2> 6454 T965 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 6554 T965 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 6561 T965 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 6629 T986 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6642 T985 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6642 T1011 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6642 T999 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 6642 T1023 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7239 T965 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 7252 T965 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 7256 T965 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 7269 T965 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 7274 T965 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 7279 T965 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 7281 T965 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 7282 T965 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty3-1348050519766/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty3/
[junit4:junit4]   2> 7282 T965 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@ac8df7b
[junit4:junit4]   2> 7284 T965 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty3/index/
[junit4:junit4]   2> 7285 T965 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 7286 T965 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty3/index forceNew:false
[junit4:junit4]   2> 7291 T965 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty3/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 7292 T965 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 7293 T965 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 7296 T965 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 7296 T965 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 7297 T965 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 7297 T965 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 7298 T965 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 7299 T965 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 7299 T965 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 7300 T965 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 7301 T965 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 7302 T965 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 7303 T965 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 7303 T965 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 7304 T965 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 7304 T965 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 7305 T965 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 7306 T965 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 7307 T965 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7307 T965 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7308 T965 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7309 T965 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7310 T965 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7310 T965 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7311 T965 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 7312 T965 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 7313 T965 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 7316 T965 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 7321 T965 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 7322 T965 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> 7326 T965 oass.SolrIndexSearcher.<init> Opening Searcher@7b95aa1d main
[junit4:junit4]   2> 7328 T965 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 7328 T965 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 7329 T965 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 7337 T965 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 7395 T1024 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7b95aa1d main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 7647 T986 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7662 T1023 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7662 T1011 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7662 T999 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7662 T985 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 7904 T965 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 7904 T965 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:39152/solr shardId:shard1
[junit4:junit4]   2> 7906 T965 oasc.ZkController.register We are http://127.0.0.1:39152/solr/collection1/ and leader is http://127.0.0.1:39145/solr/collection1/
[junit4:junit4]   2> 7907 T965 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:39152/solr
[junit4:junit4]   2> 7907 T965 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 7908 T965 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C65 name=collection1 org.apache.solr.core.SolrCore@7bf5f1cc url=http://127.0.0.1:39152/solr/collection1 node=127.0.0.1:39152_solr
[junit4:junit4]   2> 7915 T1025 C65 P39152 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 7915 T965 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7916 T1025 C65 P39152 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 7917 T965 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1
[junit4:junit4]   2> 7917 T965 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 7917 T1025 C65 P39152 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:39145/solr/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 7918 T965 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 7924 T1025 C65 P39152 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&connTimeout=30000&socketTimeout=30000&retry=false
[junit4:junit4]   2> 7945 T1025 C65 P39152 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:39152/solr START replicas=[http://127.0.0.1:39145/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 7945 T1025 C65 P39152 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 7945 T1025 C65 P39152 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 7946 T1025 C65 P39152 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 7946 T1025 C65 P39152 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C66 name=collection1 org.apache.solr.core.SolrCore@7a1d1456 url=http://127.0.0.1:39145/solr/collection1 node=127.0.0.1:39145_solr
[junit4:junit4]   2> 7958 T991 C66 P39145 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=0 
[junit4:junit4]   2> 8103 T965 oejs.Server.doStart jetty-8.1.2.v20120308
[junit4:junit4]   2> 8106 T965 oejs.AbstractConnector.doStart Started SocketConnector@0.0.0.0:39157
[junit4:junit4]   2> 8107 T965 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 8108 T965 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty4-1348050521556
[junit4:junit4]   2> 8108 T965 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty4-1348050521556/'
[junit4:junit4]   2> 8149 T965 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 8150 T965 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 8150 T965 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty4-1348050521556
[junit4:junit4]   2> 8151 T965 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty4-1348050521556/solr.xml
[junit4:junit4]   2> 8151 T965 oasc.CoreContainer.<init> New CoreContainer 657091016
[junit4:junit4]   2> 8152 T965 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty4-1348050521556/'
[junit4:junit4]   2> 8153 T965 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty4-1348050521556/'
[junit4:junit4]   2> 8165 T986 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8182 T985 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8182 T1011 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8182 T999 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8182 T1023 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 8185 T965 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 8200 T965 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:39140/solr
[junit4:junit4]   2> 8201 T965 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:39140/solr sessionTimeout=5000 watcher=org.apache.solr.common.cloud.ConnectionManager@1b644cae
[junit4:junit4]   2> 8202 T1036 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:39140
[junit4:junit4]   2> 8202 T965 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 8203 T1036 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:39140, initiating session
[junit4:junit4]   2> 8203 T967 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:39158
[junit4:junit4]   2> 8203 T967 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:39158
[junit4:junit4]   2> 8205 T969 oazs.NIOServerCnxn.finishSessionInit Established session 0x139de126edb0006 with negotiated timeout 5000 for client /140.211.11.196:39158
[junit4:junit4]   2> 8205 T1036 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:39140, sessionid = 0x139de126edb0006, negotiated timeout = 5000
[junit4:junit4]   2> 8205 T1037 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b644cae name:ZooKeeperConnection Watcher:127.0.0.1:39140/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 8205 T965 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 8206 T970 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139de126edb0006 type:create cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8207 T970 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139de126edb0006 type:create cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8216 T965 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39157_solr
[junit4:junit4]   2> 8217 T970 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x139de126edb0006 type:delete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:39157_solr Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:39157_solr
[junit4:junit4]   2> 8217 T965 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:39157_solr
[junit4:junit4]   2> 8224 T1023 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 8224 T985 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 8224 T999 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 8224 T1011 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 8224 T965 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 8225 T965 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 8225 T965 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 8226 T965 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 8226 T965 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 8227 T965 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 8227 T965 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 8227 T965 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 8228 T965 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 8228 T965 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 8247 T965 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 8253 T965 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty4-1348050521556/collection1
[junit4:junit4]   2> 8253 T965 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 8254 T965 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 8254 T965 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 8255 T965 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty4-1348050521556/collection1/'
[junit4:junit4]   2> 8257 T965 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/solrtest-jetty4-1348050521556/collection1/lib/README' to classloader
[junit4:junit4]   2> 8258 T965 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/solrtest-jetty4-1348050521556/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 8308 T965 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_40
[junit4:junit4]   2> 8378 T965 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 8479 T965 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 8485 T965 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 9114 T965 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 9126 T965 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 9130 T965 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 9151 T965 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 9156 T965 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 9161 T965 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 9162 T965 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 9163 T965 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-jetty4-1348050521556/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty4/
[junit4:junit4]   2> 9164 T965 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@ac8df7b
[junit4:junit4]   2> 9165 T965 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty4/index/
[junit4:junit4]   2> 9166 T965 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 9167 T965 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty4/index forceNew:false
[junit4:junit4]   2> 9199 T965 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty4/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 9200 T965 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 9201 T965 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 9204 T965 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 9204 T965 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 9205 T965 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 9205 T965 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 9206 T965 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 9207 T965 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 9207 T965 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 9208 T965 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 9209 T965 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 9210 T965 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 9210 T965 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 9211 T965 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 9212 T965 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 9212 T965 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 9213 T965 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 9214 T965 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 9215 T965 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 9215 T965 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 9216 T965 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 9217 T965 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 9218 T965 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 9218 T965 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 9219 T965 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 9220 T965 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 9221 T965 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 9225 T965 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 9230 T965 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 9231 T965 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> 9235 T965 oass.SolrIndexSearcher.<init> Opening Searcher@2c51baa main
[junit4:junit4]   2> 9237 T965 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 9238 T965 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 9239 T965 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 9247 T965 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 9295 T1038 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2c51baa main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 9693 T986 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9707 T985 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9707 T1037 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9707 T999 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9707 T1011 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9707 T1023 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 9804 T965 oasc.CoreContainer.register registering core: collection1
[junit4:junit4]   2> 9804 T965 oasc.ZkController.register Register shard - core:collection1 address:http://127.0.0.1:39157/solr shardId:shard2
[junit4:junit4]   2> 9807 T965 oasc.ZkController.register We are http://127.0.0.1:39157/solr/collection1/ and leader is http://127.0.0.1:39148/solr/collection1/
[junit4:junit4]   2> 9807 T965 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:39157/solr
[junit4:junit4]   2> 9807 T965 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 9808 T965 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C67 name=collection1 org.apache.solr.core.SolrCore@59a9d2d url=http://127.0.0.1:39157/solr/collection1 node=127.0.0.1:39157_solr
[junit4:junit4]   2> 9809 T1039 C67 P39157 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 9809 T965 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9809 T1039 C67 P39157 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 9810 T965 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1
[junit4:junit4]   2> 9810 T965 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 9810 T1039 C67 P39157 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:39148/solr/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 9810 T965 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 9811 T1039 C67 P39157 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:39157/solr START replicas=[http://127.0.0.1:39148/solr/collection1/] nUpdates=100
[junit4:junit4]   2> 9811 T1039 C67 P39157 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 9811 T1039 C67 P39157 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 9812 T1039 C67 P39157 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 9812 T1039 C67 P39157 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C68 name=collection1 org.apache.solr.core.SolrCore@3e91cae url=http://127.0.0.1:39148/solr/collection1 node=127.0.0.1:39148_solr
[junit4:junit4]   2> 9820 T1003 C68 P39148 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=1 
[junit4:junit4]   2> 9828 T965 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:39140/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@d2ff8af
[junit4:junit4]   2> 9829 T1041 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:39140
[junit4:junit4]   2> 9829 T965 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 9829 T1041 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:39140, initiating session
[junit4:junit4]   2> 9830 T967 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:39162
[junit4:junit4]   2> 9830 T967 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:39162
[junit4:junit4]   2> 9831 T969 oazs.NIOServerCnxn.finishSessionInit Established session 0x139de126edb0007 with negotiated timeout 10000 for client /140.211.11.196:39162
[junit4:junit4]   2> 9831 T1041 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:39140, sessionid = 0x139de126edb0007, negotiated timeout = 10000
[junit4:junit4]   2> 9832 T1042 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d2ff8af name:ZooKeeperConnection Watcher:127.0.0.1:39140/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 9832 T965 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 9832 T965 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 9835 T965 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   2> 9836 T965 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 9843 T965 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> ASYNC  NEW_CORE C69 name=collection1 org.apache.solr.core.SolrCore@2aa97c9c url=http://127.0.0.1:39143/solr/collection1 node=127.0.0.1:39143_solr
[junit4:junit4]   2> 9865 T977 C69 P39143 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16
[junit4:junit4]   2> 9884 T977 C69 P39143 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/control/data/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 9885 T977 C69 P39143 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 9891 T977 C69 P39143 /update {wt=javabin&version=2} {add=[1 (1413533425727438848)]} 0 39
[junit4:junit4]   2> 9892 T965 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:39140/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@4623ddda
[junit4:junit4]   2> 9893 T1043 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:39140
[junit4:junit4]   2> 9893 T965 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 9894 T1043 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:39140, initiating session
[junit4:junit4]   2> 9894 T967 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:39164
[junit4:junit4]   2> 9895 T967 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:39164
[junit4:junit4]   2> 9896 T969 oazs.NIOServerCnxn.finishSessionInit Established session 0x139de126edb0008 with negotiated timeout 10000 for client /140.211.11.196:39164
[junit4:junit4]   2> 9896 T1043 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:39140, sessionid = 0x139de126edb0008, negotiated timeout = 10000
[junit4:junit4]   2> 9896 T1044 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4623ddda name:ZooKeeperConnection Watcher:127.0.0.1:39140/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 9896 T965 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 9897 T965 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 9913 T993 C66 P39145 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty1/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 9913 T993 C66 P39145 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2>  C65_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:39152_solr, base_url=http://127.0.0.1:39152/solr}
[junit4:junit4]   2> 9958 T1015 C65 P39152 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty3/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 9959 T1015 C65 P39152 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 9965 T1015 C65 P39152 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=11 
[junit4:junit4]   2> 9966 T993 C66 P39145 /update {wt=javabin&version=2} {add=[1 (1413533425757847552)]} 0 66
[junit4:junit4]   2> 9967 T965 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):1800
[junit4:junit4]   2> 9967 T965 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 10210 T986 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 10223 T985 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10223 T999 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10223 T1023 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10223 T1044 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10223 T1037 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10223 T1011 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10223 T1042 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 10969 T965 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 10974 T1025 C65 P39152 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 10974 T1025 C65 P39152 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=tlog{file=./org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty3/tlog/tlog.0000000000000000000 refcount=1}}
[junit4:junit4]   2> 10974 T1025 C65 P39152 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:39145/solr/collection1/. core=collection1
[junit4:junit4]   2> 10974 T1025 C65 P39152 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 10988 T994 C66 P39145 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 11068 T994 C66 P39145 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty1/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty1/index,segFN=segments_2,generation=2,filenames=[_0.fnm, _0.frq, _0.tim, _0_nrm.cfe, segments_2, _0.fdx, _0_nrm.cfs, _0.si, _0.prx, _0.tip, _0.fdt]
[junit4:junit4]   2> 11069 T994 C66 P39145 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 11076 T994 C66 P39145 oass.SolrIndexSearcher.<init> Opening Searcher@373fd main
[junit4:junit4]   2> 11076 T994 C66 P39145 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 11078 T1000 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@373fd main{StandardDirectoryReader(segments_2:3 _0(4.0.0.2):C1)}
[junit4:junit4]   2> 11079 T994 C66 P39145 /update {waitSearcher=true&commit=true&commit_end_point=true&wt=javabin&softCommit=false&version=2} {commit=} 0 92
[junit4:junit4]   2> 11133 T1025 C65 P39152 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 11133 T1025 C65 P39152 oascsi.HttpClientUtil.createClient Creating new http client, config:connTimeout=5000&socketTimeout=20000&allowCompression=false&maxConnections=10000&maxConnectionsPerHost=10000
[junit4:junit4]   2> 11159 T1025 C65 P39152 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 11162 T995 C66 P39145 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 11163 T995 C66 P39145 REQ /replication {command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=2 
[junit4:junit4]   2> 11164 T1025 C65 P39152 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4]   2> 11164 T1025 C65 P39152 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 11164 T1025 C65 P39152 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 11169 T995 C66 P39145 REQ /replication {command=filelist&generation=2&wt=javabin&qt=/replication&version=2} status=0 QTime=2 
[junit4:junit4]   2> 11170 T1025 C65 P39152 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 11
[junit4:junit4]   2> 11172 T1025 C65 P39152 oash.SnapPuller.fetchLatestIndex Starting download to ./org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty3/index.20120919052844789 fullCopy=true
[junit4:junit4]   2> 11184 T995 C66 P39145 REQ /replication {file=_0.fnm&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=5 
[junit4:junit4]   2> 11202 T995 C66 P39145 REQ /replication {file=_0_nrm.cfe&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11207 T995 C66 P39145 REQ /replication {file=_0.tim&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11212 T995 C66 P39145 REQ /replication {file=_0.frq&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11216 T995 C66 P39145 REQ /replication {file=segments_2&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11221 T995 C66 P39145 REQ /replication {file=_0.fdx&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11226 T995 C66 P39145 REQ /replication {file=_0_nrm.cfs&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11231 T995 C66 P39145 REQ /replication {file=_0.si&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11236 T995 C66 P39145 REQ /replication {file=_0.tip&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11241 T995 C66 P39145 REQ /replication {file=_0.prx&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11246 T995 C66 P39145 REQ /replication {file=_0.fdt&command=filecontent&checksum=true&generation=2&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 11248 T1025 C65 P39152 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 11249 T1025 C65 P39152 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20120919052844789
[junit4:junit4]   2> 11258 T1025 C65 P39152 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 11258 T1025 C65 P39152 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 11258 T1025 C65 P39152 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4]   2> 11262 T1025 C65 P39152 oasc.SolrCore.getNewIndexDir WARNING New index directory detected: old=./org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty3/index/ new=./org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty3/index.20120919052844789
[junit4:junit4]   2> 11263 T1025 C65 P39152 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty3/index.20120919052844789 forceNew:true
[junit4:junit4]   2> 11267 T1025 C65 P39152 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty3/index.20120919052844789,segFN=segments_2,generation=2,filenames=[_0.fnm, _0_nrm.cfe, _0.tim, _0.frq, segments_2, _0.fdx, _0_nrm.cfs, _0.si, _0.tip, _0.prx, _0.fdt]
[junit4:junit4]   2> 11268 T1025 C65 P39152 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 11268 T1025 C65 P39152 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 11270 T1025 C65 P39152 oass.SolrIndexSearcher.<init> Opening Searcher@6feceb55 main
[junit4:junit4]   2> 11273 T1024 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6feceb55 main{StandardDirectoryReader(segments_2:3:nrt _0(4.0.0.2):C1)}
[junit4:junit4]   2> 11273 T1024 oasc.CachingDirectoryFactory.close Closing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty3/index
[junit4:junit4]   2> 11273 T1024 oash.SnapPuller$2.onClose removing old index directory ./org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty3/index
[junit4:junit4]   2> 11275 T1025 C65 P39152 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=false,waitSearcher=false,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 11276 T1025 C65 P39152 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 11276 T1025 C65 P39152 oasc.RecoveryStrategy.replay Replaying buffered documents. core=collection1
[junit4:junit4]   2> 11277 T1047 C65 P39152 oasu.UpdateLog$LogReplayer.doReplay WARNING Starting log replay tlog{file=./org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty3/tlog/tlog.0000000000000000000 refcount=2} active=true starting pos=428
[junit4:junit4]   2> 11277 T1047 C65 P39152 oasu.DirectUpdateHandler2.commit start commit{flags=2,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 11279 T1047 C65 P39152 oass.SolrIndexSearcher.<init> Opening Searcher@5ed0577 main
[junit4:junit4]   2> 11280 T1047 C65 P39152 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 11281 T1024 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5ed0577 main{StandardDirectoryReader(segments_2:3:nrt _0(4.0.0.2):C1)}
[junit4:junit4]   2> 11281 T1047 C65 P39152 oasu.UpdateLog$LogReplayer.run WARNING Log replay finished. recoveryInfo=RecoveryInfo{adds=0 deletes=0 deleteByQuery=0 errors=0 positionOfStart=428}
[junit4:junit4]   2> 11281 T1025 C65 P39152 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 11283 T1025 C65 P39152 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 11729 T986 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 11743 T1042 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11743 T1011 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11743 T1023 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11743 T999 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11743 T985 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11743 T1044 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11744 T1037 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 11971 T965 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2>  C67_STATE=coll:collection1 core:collection1 props:{shard=shard2, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:39157_solr, base_url=http://127.0.0.1:39157/solr}
[junit4:junit4]   2> 12830 T1039 C67 P39157 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 12830 T1039 C67 P39157 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 12830 T1039 C67 P39157 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:39148/solr/collection1/. core=collection1
[junit4:junit4]   2> 12830 T1039 C67 P39157 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 12843 T1005 C68 P39148 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 12848 T1005 C68 P39148 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty2/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 12849 T1005 C68 P39148 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 12850 T1005 C68 P39148 oass.SolrIndexSearcher.<init> Opening Searcher@5bb2abbc main
[junit4:junit4]   2> 12850 T1005 C68 P39148 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 12852 T1012 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5bb2abbc main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 12852 T1005 C68 P39148 /update {waitSearcher=true&commit=true&commit_end_point=true&wt=javabin&softCommit=false&version=2} {commit=} 0 9
[junit4:junit4]   2> 12853 T1039 C67 P39157 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 12854 T1039 C67 P39157 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 12856 T1006 C68 P39148 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 12856 T1006 C68 P39148 REQ /replication {command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
[junit4:junit4]   2> 12860 T1039 C67 P39157 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty4/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 12860 T1039 C67 P39157 oasc.SolrDeletionPolicy.updateCommits newest commit = 1
[junit4:junit4]   2> 12861 T1039 C67 P39157 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 12890 T1039 C67 P39157 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty4/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty4/index,segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 12890 T1039 C67 P39157 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 12892 T1039 C67 P39157 oass.SolrIndexSearcher.<init> Opening Searcher@51354cac main
[junit4:junit4]   2> 12893 T1039 C67 P39157 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 12894 T1038 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@51354cac main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 12894 T1039 C67 P39157 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 12894 T1039 C67 P39157 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 12904 T1039 C67 P39157 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 12973 T965 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 13249 T986 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 13264 T1042 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 13264 T1044 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 13264 T1023 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 13264 T1011 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 13264 T985 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 13264 T1037 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 13264 T999 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 13975 T965 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 13979 T977 C69 P39143 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 14010 T977 C69 P39143 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/control/data/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/control/data/index,segFN=segments_2,generation=2,filenames=[_0.fnm, _0.frq, _0.tim, _0_nrm.cfe, segments_2, _0.fdx, _0_nrm.cfs, _0.si, _0.prx, _0.tip, _0.fdt]
[junit4:junit4]   2> 14010 T977 C69 P39143 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 14021 T977 C69 P39143 oass.SolrIndexSearcher.<init> Opening Searcher@6a16f17c main
[junit4:junit4]   2> 14022 T977 C69 P39143 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 14023 T988 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6a16f17c main{StandardDirectoryReader(segments_2:3 _0(4.0.0.2):C1)}
[junit4:junit4]   2> 14024 T977 C69 P39143 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 45
[junit4:junit4]   2> 14027 T1007 C68 P39148 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 14031 T1007 C68 P39148 oass.SolrIndexSearcher.<init> Opening Searcher@41620aeb main
[junit4:junit4]   2> 14031 T1007 C68 P39148 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 14032 T1012 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@41620aeb main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 14033 T1007 C68 P39148 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:39145/solr/collection1/, StdNode: http://127.0.0.1:39152/solr/collection1/, StdNode: http://127.0.0.1:39157/solr/collection1/]
[junit4:junit4]   2>  C65_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:39152_solr, base_url=http://127.0.0.1:39152/solr}
[junit4:junit4]   2> 14037 T1015 C65 P39152 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 14037 T996 C66 P39145 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 14040 T1015 C65 P39152 oass.SolrIndexSearcher.<init> Opening Searcher@4c60bdda main
[junit4:junit4]   2> 14041 T1015 C65 P39152 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 14042 T1024 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4c60bdda main{StandardDirectoryReader(segments_2:3:nrt _0(4.0.0.2):C1)}
[junit4:junit4]   2> 14042 T1015 C65 P39152 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&expungeDeletes=false&softCommit=false&version=2} {commit=} 0 5
[junit4:junit4]   2> 14048 T996 C66 P39145 oass.SolrIndexSearcher.<init> Opening Searcher@305e0ade main
[junit4:junit4]   2> 14049 T996 C66 P39145 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2>  C67_STATE=coll:collection1 core:collection1 props:{shard=shard2, roles=null, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:39157_solr, base_url=http://127.0.0.1:39157/solr}
[junit4:junit4]   2> 14049 T1029 C67 P39157 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 14052 T1000 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@305e0ade main{StandardDirectoryReader(segments_2:3 _0(4.0.0.2):C1)}
[junit4:junit4]   2> 14052 T996 C66 P39145 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&expungeDeletes=false&softCommit=false&version=2} {commit=} 0 15
[junit4:junit4]   2> 14054 T1029 C67 P39157 oass.SolrIndexSearcher.<init> Opening Searcher@5cf7ac3 main
[junit4:junit4]   2> 14054 T1029 C67 P39157 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 14056 T1038 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5cf7ac3 main{StandardDirectoryReader(segments_2:2)}
[junit4:junit4]   2> 14056 T1029 C67 P39157 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&expungeDeletes=false&softCommit=false&version=2} {commit=} 0 7
[junit4:junit4]   2> 14057 T1007 C68 P39148 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 30
[junit4:junit4]   2> 14064 T978 C69 P39143 REQ /select {fl=id,score&shard.url=127.0.0.1:39143/solr/collection1/&NOW=1348050527678&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 14073 T978 C69 P39143 REQ /select {shard.url=127.0.0.1:39143/solr/collection1/&NOW=1348050527678&q=*:*&ids=1&distrib=false&isShard=true&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14074 T977 C69 P39143 REQ /select {wt=javabin&q=*:*&version=2} hits=1 status=0 QTime=14 
[junit4:junit4]   2> 14075 T965 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:39140/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@1fc3e3e4
[junit4:junit4]   2> 14076 T1052 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:39140
[junit4:junit4]   2> 14076 T965 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 14076 T1052 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:39140, initiating session
[junit4:junit4]   2> 14077 T967 oazs.NIOServerCnxn$Factory.run Accepted socket connection from /140.211.11.196:39177
[junit4:junit4]   2> 14077 T967 oazs.NIOServerCnxn.readConnectRequest Client attempting to establish new session at /140.211.11.196:39177
[junit4:junit4]   2> 14078 T969 oazs.NIOServerCnxn.finishSessionInit Established session 0x139de126edb0009 with negotiated timeout 10000 for client /140.211.11.196:39177
[junit4:junit4]   2> 14078 T1052 oaz.ClientCnxn$SendThread.readConnectResult Session establishment complete on server localhost/127.0.0.1:39140, sessionid = 0x139de126edb0009, negotiated timeout = 10000
[junit4:junit4]   2> 14079 T1053 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1fc3e3e4 name:ZooKeeperConnection Watcher:127.0.0.1:39140/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 14079 T965 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 14079 T965 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 14081 T970 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x139de126edb0009
[junit4:junit4]   2> 14082 T1053 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 14082 T965 oaz.ZooKeeper.close Session: 0x139de126edb0009 closed
[junit4:junit4]   2> 14082 T967 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:39177 which had sessionid 0x139de126edb0009
[junit4:junit4]   2> 14084 T997 C66 P39145 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 14087 T1008 C68 P39148 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 14094 T992 C66 P39145 REQ /select {fl=id,score&shard.url=127.0.0.1:39145/solr/collection1/|127.0.0.1:39152/solr/collection1/&NOW=1348050527708&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 14094 T1030 C67 P39157 REQ /select {fl=id,score&shard.url=127.0.0.1:39148/solr/collection1/|127.0.0.1:39157/solr/collection1/&NOW=1348050527708&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 14098 T992 C66 P39145 REQ /select {shard.url=127.0.0.1:39145/solr/collection1/|127.0.0.1:39152/solr/collection1/&NOW=1348050527708&q=*:*&ids=1&distrib=false&isShard=true&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 14099 T1007 C68 P39148 REQ /select {wt=javabin&q=*:*&version=2} hits=1 status=0 QTime=9 
[junit4:junit4]   2> 14108 T977 C69 P39143 /update {wt=javabin&version=2} {add=[2 (1413533430155575296)]} 0 6
[junit4:junit4]   2> 14133 T1029 C67 P39157 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39148/solr/collection1/&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 14134 T1009 C68 P39148 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=16 
[junit4:junit4]   2> 14135 T993 C66 P39145 /update {wt=javabin&version=2} {add=[2]} 0 24
[junit4:junit4]   2> 14141 T977 C69 P39143 /update {wt=javabin&version=2} {add=[3 (1413533430193324032)]} 0 3
[junit4:junit4]   2> 14153 T1029 C67 P39157 REQ /update {distrib.from=http://127.0.0.1:39148/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 14154 T1007 C68 P39148 /update {wt=javabin&version=2} {add=[3 (1413533430199615488)]} 0 10
[junit4:junit4]   2> 14160 T977 C69 P39143 /update {wt=javabin&version=2} {add=[4 (1413533430213246976)]} 0 3
[junit4:junit4]   2> 14177 T1015 C65 P39152 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 14178 T993 C66 P39145 /update {wt=javabin&version=2} {add=[4 (1413533430219538432)]} 0 15
[junit4:junit4]   2> 14185 T977 C69 P39143 /update {wt=javabin&version=2} {add=[5 (1413533430238412800)]} 0 4
[junit4:junit4]   2> 14201 T1029 C67 P39157 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39148/solr/collection1/&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 14201 T1009 C68 P39148 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=10 
[junit4:junit4]   2> 14202 T993 C66 P39145 /update {wt=javabin&version=2} {add=[5]} 0 14
[junit4:junit4]   2> 14208 T977 C69 P39143 /update {wt=javabin&version=2} {add=[6 (1413533430263578624)]} 0 3
[junit4:junit4]   2> 14223 T1029 C67 P39157 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39148/solr/collection1/&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 14224 T1009 C68 P39148 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=10 
[junit4:junit4]   2> 14225 T993 C66 P39145 /update {wt=javabin&version=2} {add=[6]} 0 14
[junit4:junit4]   2> 14231 T977 C69 P39143 /update {wt=javabin&version=2} {add=[7 (1413533430287695872)]} 0 3
[junit4:junit4]   2> 14245 T1029 C67 P39157 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39148/solr/collection1/&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 14246 T1009 C68 P39148 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=9 
[junit4:junit4]   2> 14247 T993 C66 P39145 /update {wt=javabin&version=2} {add=[7]} 0 13
[junit4:junit4]   2> 14253 T977 C69 P39143 /update {wt=javabin&version=2} {add=[8 (1413533430310764544)]} 0 3
[junit4:junit4]   2> 14265 T1015 C65 P39152 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 14266 T993 C66 P39145 /update {wt=javabin&version=2} {add=[8 (1413533430317056000)]} 0 10
[junit4:junit4]   2> 14272 T977 C69 P39143 /update {wt=javabin&version=2} {add=[9 (1413533430330687488)]} 0 3
[junit4:junit4]   2> 14287 T1029 C67 P39157 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39148/solr/collection1/&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 14288 T1009 C68 P39148 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=10 
[junit4:junit4]   2> 14288 T993 C66 P39145 /update {wt=javabin&version=2} {add=[9]} 0 13
[junit4:junit4]   2> 14294 T977 C69 P39143 /update {wt=javabin&version=2} {add=[10 (1413533430353756160)]} 0 3
[junit4:junit4]   2> 14310 T1015 C65 P39152 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39145/solr/collection1/&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 14311 T996 C66 P39145 REQ /update {distrib.from=http://127.0.0.1:39148/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=10 
[junit4:junit4]   2> 14312 T1007 C68 P39148 /update {wt=javabin&version=2} {add=[10]} 0 15
[junit4:junit4]   2> 14338 T977 C69 P39143 /update {wt=javabin&version=2} {add=[11 (1413533430378921984)]} 0 23
[junit4:junit4]   2> 14355 T1015 C65 P39152 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39145/solr/collection1/&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 14356 T996 C66 P39145 REQ /update {distrib.from=http://127.0.0.1:39148/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=11 
[junit4:junit4]   2> 14357 T1007 C68 P39148 /update {wt=javabin&version=2} {add=[11]} 0 15
[junit4:junit4]   2> 14366 T977 C69 P39143 /update {wt=javabin&version=2} {add=[12 (1413533430426107904)]} 0 6
[junit4:junit4]   2> 14382 T1015 C65 P39152 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39145/solr/collection1/&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 14382 T996 C66 P39145 REQ /update {distrib.from=http://127.0.0.1:39148/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=10 
[junit4:junit4]   2> 14383 T1007 C68 P39148 /update {wt=javabin&version=2} {add=[12]} 0 14
[junit4:junit4]   2> 14389 T977 C69 P39143 /update {wt=javabin&version=2} {add=[13 (1413533430453370880)]} 0 3
[junit4:junit4]   2> 14403 T1015 C65 P39152 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 14403 T993 C66 P39145 /update {wt=javabin&version=2} {add=[13 (1413533430460710912)]} 0 10
[junit4:junit4]   2> 14409 T977 C69 P39143 /update {wt=javabin&version=2} {add=[14 (1413533430474342400)]} 0 3
[junit4:junit4]   2> 14419 T1015 C65 P39152 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 14420 T993 C66 P39145 /update {wt=javabin&version=2} {add=[14 (1413533430480633856)]} 0 8
[junit4:junit4]   2> 14425 T977 C69 P39143 /update {wt=javabin&version=2} {add=[15 (1413533430491119616)]} 0 2
[junit4:junit4]   2> 14437 T1015 C65 P39152 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 14438 T993 C66 P39145 /update {wt=javabin&version=2} {add=[15 (1413533430497411072)]} 0 10
[junit4:junit4]   2> 14445 T977 C69 P39143 /update {wt=javabin&version=2} {add=[16 (1413533430512091136)]} 0 3
[junit4:junit4]   2> 14459 T1015 C65 P39152 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39145/solr/collection1/&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 14460 T996 C66 P39145 REQ /update {distrib.from=http://127.0.0.1:39148/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=9 
[junit4:junit4]   2> 14461 T1007 C68 P39148 /update {wt=javabin&version=2} {add=[16]} 0 13
[junit4:junit4]   2> 14475 T977 C69 P39143 /update {wt=javabin&version=2} {add=[17 (1413533430538305536)]} 0 10
[junit4:junit4]   2> 14502 T1029 C67 P39157 REQ /update {distrib.from=http://127.0.0.1:39148/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=10 
[junit4:junit4]   2> 14503 T1007 C68 P39148 /update {wt=javabin&version=2} {add=[17 (1413533430551937024)]} 0 25
[junit4:junit4]   2> 14509 T977 C69 P39143 /update {wt=javabin&version=2} {add=[100 (1413533430579200000)]} 0 3
[junit4:junit4]   2> 14565 T1015 C65 P39152 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39145/solr/collection1/&wt=javabin&version=2} status=0 QTime=24 
[junit4:junit4]   2> 14566 T996 C66 P39145 REQ /update {distrib.from=http://127.0.0.1:39148/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=51 
[junit4:junit4]   2> 14566 T1007 C68 P39148 /update {wt=javabin&version=2} {add=[100]} 0 54
[junit4:junit4]   2> 14573 T977 C69 P39143 /update {wt=javabin&version=2} {add=[101 (1413533430646308864)]} 0 3
[junit4:junit4]   2> 14592 T1015 C65 P39152 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39145/solr/collection1/&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 14593 T996 C66 P39145 REQ /update {distrib.from=http://127.0.0.1:39148/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=14 
[junit4:junit4]   2> 14594 T1007 C68 P39148 /update {wt=javabin&version=2} {add=[101]} 0 18
[junit4:junit4]   2> 14600 T977 C69 P39143 /update {wt=javabin&version=2} {add=[102 (1413533430674620416)]} 0 3
[junit4:junit4]   2> 14611 T1015 C65 P39152 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 14612 T993 C66 P39145 /update {wt=javabin&version=2} {add=[102 (1413533430680911872)]} 0 9
[junit4:junit4]   2> 14638 T977 C69 P39143 /update {wt=javabin&version=2} {add=[103 (1413533430693494784)]} 0 23
[junit4:junit4]   2> 14650 T1029 C67 P39157 REQ /update {distrib.from=http://127.0.0.1:39148/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 14650 T1007 C68 P39148 /update {wt=javabin&version=2} {add=[103 (1413533430721806336)]} 0 8
[junit4:junit4]   2> 14658 T977 C69 P39143 /update {wt=javabin&version=2} {add=[104 (1413533430733340672)]} 0 5
[junit4:junit4]   2> 14672 T1029 C67 P39157 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39148/solr/collection1/&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 14672 T1009 C68 P39148 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=8 
[junit4:junit4]   2> 14673 T993 C66 P39145 /update {wt=javabin&version=2} {add=[104]} 0 12
[junit4:junit4]   2> 14679 T977 C69 P39143 /update {wt=javabin&version=2} {add=[105 (1413533430757457920)]} 0 3
[junit4:junit4]   2> 14733 T1029 C67 P39157 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39148/solr/collection1/&wt=javabin&version=2} status=0 QTime=22 
[junit4:junit4]   2> 14734 T1009 C68 P39148 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=48 
[junit4:junit4]   2> 14734 T993 C66 P39145 /update {wt=javabin&version=2} {add=[105]} 0 52
[junit4:junit4]   2> 14741 T977 C69 P39143 /update {wt=javabin&version=2} {add=[106 (1413533430822469632)]} 0 3
[junit4:junit4]   2> 14755 T1029 C67 P39157 REQ /update {distrib.from=http://127.0.0.1:39148/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 14756 T1007 C68 P39148 /update {wt=javabin&version=2} {add=[106 (1413533430828761088)]} 0 12
[junit4:junit4]   2> 14761 T977 C69 P39143 /update {wt=javabin&version=2} {add=[107 (1413533430844489728)]} 0 2
[junit4:junit4]   2> 14775 T1015 C65 P39152 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39145/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 14776 T996 C66 P39145 REQ /update {distrib.from=http://127.0.0.1:39148/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=9 
[junit4:junit4]   2> 14777 T1007 C68 P39148 /update {wt=javabin&version=2} {add=[107]} 0 13
[junit4:junit4]   2> 14782 T977 C69 P39143 /update {wt=javabin&version=2} {add=[108 (1413533430865461248)]} 0 2
[junit4:junit4]   2> 14818 T1015 C65 P39152 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39145/solr/collection1/&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 14819 T996 C66 P39145 REQ /update {distrib.from=http://127.0.0.1:39148/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=32 
[junit4:junit4]   2> 14821 T1007 C68 P39148 /update {wt=javabin&version=2} {add=[108]} 0 36
[junit4:junit4]   2> 14827 T977 C69 P39143 /update {wt=javabin&version=2} {add=[109 (1413533430912647168)]} 0 3
[junit4:junit4]   2> 14837 T1015 C65 P39152 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 14838 T993 C66 P39145 /update {wt=javabin&version=2} {add=[109 (1413533430918938624)]} 0 8
[junit4:junit4]   2> 14843 T977 C69 P39143 /update {wt=javabin&version=2} {add=[110 (1413533430930472960)]} 0 2
[junit4:junit4]   2> 14856 T1015 C65 P39152 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39145/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 14856 T996 C66 P39145 REQ /update {distrib.from=http://127.0.0.1:39148/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 14857 T1007 C68 P39148 /update {wt=javabin&version=2} {add=[110]} 0 11
[junit4:junit4]   2> 14862 T977 C69 P39143 /update {wt=javabin&version=2} {add=[111 (1413533430950395904)]} 0 2
[junit4:junit4]   2> 14875 T1015 C65 P39152 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39145/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 14875 T996 C66 P39145 REQ /update {distrib.from=http://127.0.0.1:39148/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 14876 T1007 C68 P39148 /update {wt=javabin&version=2} {add=[111]} 0 11
[junit4:junit4]   2> 14881 T977 C69 P39143 /update {wt=javabin&version=2} {add=[112 (1413533430970318848)]} 0 2
[junit4:junit4]   2> 14892 T1029 C67 P39157 REQ /update {distrib.from=http://127.0.0.1:39148/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 14892 T1007 C68 P39148 /update {wt=javabin&version=2} {add=[112 (1413533430975561728)]} 0 8
[junit4:junit4]   2> 14907 T977 C69 P39143 /update {wt=javabin&version=2} {add=[113 (1413533430987096064)]} 0 12
[junit4:junit4]   2> 14918 T1015 C65 P39152 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 14918 T993 C66 P39145 /update {wt=javabin&version=2} {add=[113 (1413533431002824704)]} 0 8
[junit4:junit4]   2> 14924 T977 C69 P39143 /update {wt=javabin&version=2} {add=[114 (1413533431014359040)]} 0 3
[junit4:junit4]   2> 14938 T1015 C65 P39152 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39145/solr/collection1/&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 14938 T996 C66 P39145 REQ /update {distrib.from=http://127.0.0.1:39148/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=8 
[junit4:junit4]   2> 14939 T1007 C68 P39148 /update {wt=javabin&version=2} {add=[114]} 0 12
[junit4:junit4]   2> 14945 T977 C69 P39143 /update {wt=javabin&version=2} {add=[115 (1413533431036379136)]} 0 2
[junit4:junit4]   2> 14958 T1029 C67 P39157 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39148/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 14958 T1009 C68 P39148 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=8 
[junit4:junit4]   2> 14959 T993 C66 P39145 /update {wt=javabin&version=2} {add=[115]} 0 12
[junit4:junit4]   2> 14965 T977 C69 P39143 /update {wt=javabin&version=2} {add=[116 (1413533431057350656)]} 0 2
[junit4:junit4]   2> 14975 T1029 C67 P39157 REQ /update {distrib.from=http://127.0.0.1:39148/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 14975 T1007 C68 P39148 /update {wt=javabin&version=2} {add=[116 (1413533431062593536)]} 0 7
[junit4:junit4]   2> 14981 T977 C69 P39143 /update {wt=javabin&version=2} {add=[117 (1413533431074127872)]} 0 2
[junit4:junit4]   2> 14994 T1029 C67 P39157 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39148/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 14994 T1009 C68 P39148 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=8 
[junit4:junit4]   2> 14995 T993 C66 P39145 /update {wt=javabin&version=2} {add=[117]} 0 12
[junit4:junit4]   2> 15001 T977 C69 P39143 /update {wt=javabin&version=2} {add=[118 (1413533431096147968)]} 0 2
[junit4:junit4]   2> 15044 T1015 C65 P39152 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39145/solr/collection1/&wt=javabin&version=2} status=0 QTime=18 
[junit4:junit4]   2> 15045 T996 C66 P39145 REQ /update {distrib.from=http://127.0.0.1:39148/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=38 
[junit4:junit4]   2> 15046 T1007 C68 P39148 /update {wt=javabin&version=2} {add=[118]} 0 41
[junit4:junit4]   2> 15051 T977 C69 P39143 /update {wt=javabin&version=2} {add=[119 (1413533431148576768)]} 0 2
[junit4:junit4]   2> 15066 T1029 C67 P39157 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39148/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15066 T1009 C68 P39148 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=8 
[junit4:junit4]   2> 15068 T993 C66 P39145 /update {wt=javabin&version=2} {add=[119]} 0 14
[junit4:junit4]   2> 15072 T977 C69 P39143 /update {wt=javabin&version=2} {add=[120 (1413533431170596864)]} 0 1
[junit4:junit4]   2> 15083 T1029 C67 P39157 REQ /update {distrib.from=http://127.0.0.1:39148/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15084 T1007 C68 P39148 /update {wt=javabin&version=2} {add=[120 (1413533431175839744)]} 0 9
[junit4:junit4]   2> 15088 T977 C69 P39143 /update {wt=javabin&version=2} {add=[121 (1413533431187374080)]} 0 1
[junit4:junit4]   2> 15099 T1029 C67 P39157 REQ /update {distrib.from=http://127.0.0.1:39148/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15099 T1007 C68 P39148 /update {wt=javabin&version=2} {add=[121 (1413533431192616960)]} 0 8
[junit4:junit4]   2> 15105 T977 C69 P39143 /update {wt=javabin&version=2} {add=[122 (1413533431204151296)]} 0 2
[junit4:junit4]   2> 15122 T1015 C65 P39152 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39145/solr/collection1/&wt=javabin&version=2} status=0 QTime=5 
[junit4:junit4]   2> 15123 T996 C66 P39145 REQ /update {distrib.from=http://127.0.0.1:39148/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=13 
[junit4:junit4]   2> 15123 T1007 C68 P39148 /update {wt=javabin&version=2} {add=[122]} 0 16
[junit4:junit4]   2> 15137 T977 C69 P39143 /update {wt=javabin&version=2} {add=[123 (1413533431228268544)]} 0 11
[junit4:junit4]   2> 15149 T1015 C65 P39152 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 15150 T993 C66 P39145 /update {wt=javabin&version=2} {add=[123 (1413533431243997184)]} 0 10
[junit4:junit4]   2> 15156 T977 C69 P39143 /update {wt=javabin&version=2} {add=[124 (1413533431256580096)]} 0 3
[junit4:junit4]   2> 15170 T1015 C65 P39152 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39145/solr/collection1/&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 15171 T996 C66 P39145 REQ /update {distrib.from=http://127.0.0.1:39148/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=8 
[junit4:junit4]   2> 15171 T1007 C68 P39148 /update {wt=javabin&version=2} {add=[124]} 0 11
[junit4:junit4]   2> 15177 T977 C69 P39143 /update {wt=javabin&version=2} {add=[125 (1413533431279648768)]} 0 2
[junit4:junit4]   2> 15188 T1015 C65 P39152 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39145/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15189 T996 C66 P39145 REQ /update {distrib.from=http://127.0.0.1:39148/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 15189 T1007 C68 P39148 /update {wt=javabin&version=2} {add=[125]} 0 10
[junit4:junit4]   2> 15194 T977 C69 P39143 /update {wt=javabin&version=2} {add=[126 (1413533431298523136)]} 0 1
[junit4:junit4]   2> 15208 T1029 C67 P39157 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39148/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15208 T1009 C68 P39148 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=8 
[junit4:junit4]   2> 15209 T993 C66 P39145 /update {wt=javabin&version=2} {add=[126]} 0 12
[junit4:junit4]   2> 15215 T977 C69 P39143 /update {wt=javabin&version=2} {add=[127 (1413533431320543232)]} 0 2
[junit4:junit4]   2> 15259 T1029 C67 P39157 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39148/solr/collection1/&wt=javabin&version=2} status=0 QTime=11 
[junit4:junit4]   2> 15259 T1009 C68 P39148 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=38 
[junit4:junit4]   2> 15261 T993 C66 P39145 /update {wt=javabin&version=2} {add=[127]} 0 43
[junit4:junit4]   2> 15266 T977 C69 P39143 /update {wt=javabin&version=2} {add=[128 (1413533431374020608)]} 0 2
[junit4:junit4]   2> 15283 T1029 C67 P39157 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39148/solr/collection1/&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 15284 T1009 C68 P39148 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=12 
[junit4:junit4]   2> 15285 T993 C66 P39145 /update {wt=javabin&version=2} {add=[128]} 0 16
[junit4:junit4]   2> 15289 T977 C69 P39143 /update {wt=javabin&version=2} {add=[129 (1413533431398137856)]} 0 1
[junit4:junit4]   2> 15302 T1015 C65 P39152 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39145/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15302 T996 C66 P39145 REQ /update {distrib.from=http://127.0.0.1:39148/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 15303 T1007 C68 P39148 /update {wt=javabin&version=2} {add=[129]} 0 10
[junit4:junit4]   2> 15308 T977 C69 P39143 /update {wt=javabin&version=2} {add=[130 (1413533431418060800)]} 0 1
[junit4:junit4]   2> 15319 T1029 C67 P39157 REQ /update {distrib.from=http://127.0.0.1:39148/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15319 T1007 C68 P39148 /update {wt=javabin&version=2} {add=[130 (1413533431423303680)]} 0 8
[junit4:junit4]   2> 15324 T977 C69 P39143 /update {wt=javabin&version=2} {add=[131 (1413533431433789440)]} 0 2
[junit4:junit4]   2> 15338 T1029 C67 P39157 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39148/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15338 T1009 C68 P39148 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=8 
[junit4:junit4]   2> 15339 T993 C66 P39145 /update {wt=javabin&version=2} {add=[131]} 0 12
[junit4:junit4]   2> 15344 T977 C69 P39143 /update {wt=javabin&version=2} {add=[132 (1413533431455809536)]} 0 1
[junit4:junit4]   2> 15355 T1015 C65 P39152 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15355 T993 C66 P39145 /update {wt=javabin&version=2} {add=[132 (1413533431461052416)]} 0 7
[junit4:junit4]   2> 15370 T977 C69 P39143 /update {wt=javabin&version=2} {add=[133 (1413533431472586752)]} 0 11
[junit4:junit4]   2> 15382 T1015 C65 P39152 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39145/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15383 T996 C66 P39145 REQ /update {distrib.from=http://127.0.0.1:39148/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 15384 T1007 C68 P39148 /update {wt=javabin&version=2} {add=[133]} 0 10
[junit4:junit4]   2> 15391 T977 C69 P39143 /update {wt=javabin&version=2} {add=[134 (1413533431502995456)]} 0 3
[junit4:junit4]   2> 15405 T1029 C67 P39157 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39148/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15405 T1009 C68 P39148 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=8 
[junit4:junit4]   2> 15407 T993 C66 P39145 /update {wt=javabin&version=2} {add=[134]} 0 14
[junit4:junit4]   2> 15411 T977 C69 P39143 /update {wt=javabin&version=2} {add=[135 (1413533431526064128)]} 0 1
[junit4:junit4]   2> 15421 T1015 C65 P39152 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15422 T993 C66 P39145 /update {wt=javabin&version=2} {add=[135 (1413533431531307008)]} 0 8
[junit4:junit4]   2> 15427 T977 C69 P39143 /update {wt=javabin&version=2} {add=[136 (1413533431541792768)]} 0 2
[junit4:junit4]   2> 15437 T1029 C67 P39157 REQ /update {distrib.from=http://127.0.0.1:39148/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15438 T1007 C68 P39148 /update {wt=javabin&version=2} {add=[136 (1413533431548084224)]} 0 8
[junit4:junit4]   2> 15443 T977 C69 P39143 /update {wt=javabin&version=2} {add=[137 (1413533431558569984)]} 0 2
[junit4:junit4]   2> 15455 T1029 C67 P39157 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39148/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15456 T1009 C68 P39148 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 15457 T993 C66 P39145 /update {wt=javabin&version=2} {add=[137]} 0 11
[junit4:junit4]   2> 15462 T977 C69 P39143 /update {wt=javabin&version=2} {add=[138 (1413533431578492928)]} 0 2
[junit4:junit4]   2> 15472 T1015 C65 P39152 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39145/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15473 T996 C66 P39145 REQ /update {distrib.from=http://127.0.0.1:39148/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 15473 T1007 C68 P39148 /update {wt=javabin&version=2} {add=[138]} 0 9
[junit4:junit4]   2> 15478 T977 C69 P39143 /update {wt=javabin&version=2} {add=[139 (1413533431596318720)]} 0 1
[junit4:junit4]   2> 15486 T1029 C67 P39157 REQ /update {distrib.from=http://127.0.0.1:39148/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15487 T1007 C68 P39148 /update {wt=javabin&version=2} {add=[139 (1413533431601561600)]} 0 6
[junit4:junit4]   2> 15491 T977 C69 P39143 /update {wt=javabin&version=2} {add=[140 (1413533431609950208)]} 0 1
[junit4:junit4]   2> 15503 T1029 C67 P39157 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39148/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15504 T1009 C68 P39148 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=7 
[junit4:junit4]   2> 15505 T993 C66 P39145 /update {wt=javabin&version=2} {add=[140]} 0 11
[junit4:junit4]   2> 15509 T977 C69 P39143 /update {wt=javabin&version=2} {add=[141 (1413533431628824576)]} 0 1
[junit4:junit4]   2> 15520 T1029 C67 P39157 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39148/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15521 T1009 C68 P39148 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 15521 T993 C66 P39145 /update {wt=javabin&version=2} {add=[141]} 0 9
[junit4:junit4]   2> 15526 T977 C69 P39143 /update {wt=javabin&version=2} {add=[142 (1413533431646650368)]} 0 1
[junit4:junit4]   2> 15559 T1029 C67 P39157 REQ /update {distrib.from=http://127.0.0.1:39148/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=11 
[junit4:junit4]   2> 15559 T1007 C68 P39148 /update {wt=javabin&version=2} {add=[142 (1413533431651893248)]} 0 30
[junit4:junit4]   2> 15573 T977 C69 P39143 /update {wt=javabin&version=2} {add=[143 (1413533431686496256)]} 0 10
[junit4:junit4]   2> 15588 T1029 C67 P39157 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39148/solr/collection1/&wt=javabin&version=2} status=0 QTime=3 
[junit4:junit4]   2> 15588 T1009 C68 P39148 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=9 
[junit4:junit4]   2> 15589 T993 C66 P39145 /update {wt=javabin&version=2} {add=[143]} 0 13
[junit4:junit4]   2> 15594 T977 C69 P39143 /update {wt=javabin&version=2} {add=[144 (1413533431716904960)]} 0 2
[junit4:junit4]   2> 15605 T1029 C67 P39157 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39148/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15606 T1009 C68 P39148 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 15607 T993 C66 P39145 /update {wt=javabin&version=2} {add=[144]} 0 10
[junit4:junit4]   2> 15610 T977 C69 P39143 /update {wt=javabin&version=2} {add=[145 (1413533431734730752)]} 0 1
[junit4:junit4]   2> 15621 T1029 C67 P39157 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39148/solr/collection1/&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15622 T1009 C68 P39148 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 15623 T993 C66 P39145 /update {wt=javabin&version=2} {add=[145]} 0 10
[junit4:junit4]   2> 15627 T977 C69 P39143 /update {wt=javabin&version=2} {add=[146 (1413533431752556544)]} 0 1
[junit4:junit4]   2> 15658 T1015 C65 P39152 REQ /update {distrib.from=http://127.0.0.1:39145/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=10 
[junit4:junit4]   2> 15659 T993 C66 P39145 /update {wt=javabin&version=2} {add=[146 (1413533431756750848)]} 0 29
[junit4:junit4]   2> 15663 T977 C69 P39143 /update {wt=javabin&version=2} {add=[147 (1413533431790305280)]} 0 1
[junit4:junit4]   2> 15671 T1029 C67 P39157 REQ /update {distrib.from=http://127.0.0.1:39148/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15672 T1007 C68 P39148 /update {wt=javabin&version=2} {add=[147 (1413533431795548160)]} 0 6
[junit4:junit4]   2> 15676 T977 C69 P39143 /update {wt=javabin&version=2} {add=[148 (1413533431803936768)]} 0 1
[junit4:junit4]   2> 15689 T1015 C65 P39152 REQ /update {update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:39145/solr/collection1/&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   2> 15690 T996 C66 P39145 REQ /update {distrib.from=http://127.0.0.1:39148/solr/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} status=0 QTime=8 
[junit4:junit4]   2> 15691 T1007 C68 P39148 /update {wt=javabin&version=2} {add=[148]} 0 12
[junit4:junit4]   2> 15695 T977 C69 P39143 /update {wt=javabin&version=2} {add=[149 (1413533431823859712)]} 0 1
[junit4:junit4]   2> 15703 T1029 C67 P39157 REQ /update {distrib.from=http://127.0.0.1:39148/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   2> 15704 T1007 C68 P39148 /update {wt=javabin&version=2} {add=[149 (1413533431829102592)]} 0 6
[junit4:junit4]   2> 15705 T965 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):1800
[junit4:junit4]   2> 15706 T965 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 15708 T977 C69 P39143 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 16018 T977 C69 P39143 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/control/data/index,segFN=segments_2,generation=2,filenames=[_0.fnm, _0.frq, _0.tim, _0_nrm.cfe, segments_2, _0.fdx, _0_nrm.cfs, _0.si, _0.prx, _0.tip, _0.fdt]
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/control/data/index,segFN=segments_3,generation=3,filenames=[_5_nrm.cfe, _3_nrm.cfe, _5.fdt, _5.prx, _1.frq, _4.prx, _7.si, _4.fnm, _4_nrm.cfe, _3.fdt, _1.fnm, _2.tim, _4.fdx, _7.fnm, _5.tip, _5.tim, _4.frq, _7.frq, _7.tim, _0.prx, _7.tip, _0.fnm, _2.prx, _2.frq, _2.fdt, _7.fdx, _3.prx, _2.fdx, _7.fdt, _5.si, _2.tip, _1.fdx, _1.prx, _3_nrm.cfs, _5_nrm.cfs, _1.fdt, _0.tim, _0.frq, _4_nrm.cfs, _3.si, _6.fdt, _0.tip, _2.si, _3.frq, _6.frq, _3.tim, _6.fdx, _3.fnm, _2_nrm.cfe, _6.tip, _6_nrm.cfs, _7_nrm.cfs, _6.tim, _4.tip, _0.si, _2_nrm.cfs, _1.tip, _1.tim, _1_nrm.cfs, _5.fnm, _7_nrm.cfe, _4.tim, _6_nrm.cfe, _5.frq, _4.si, _4.fdt, _0_nrm.cfs, _1_nrm.cfe, _2.fnm, _7.prx, _3.fdx, _6.prx, _1.si, _0_nrm.cfe, _5.fdx, _6.si, _6.fnm, _0.fdx, _3.tip, segments_3, _0.fdt]
[junit4:junit4]   2> 16018 T977 C69 P39143 oasc.SolrDeletionPolicy.updateCommits newest commit = 3
[junit4:junit4]   2> 16056 T977 C69 P39143 oass.SolrIndexSearcher.<init> Opening Searcher@69c509e6 main
[junit4:junit4]   2> 16057 T977 C69 P39143 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 16059 T988 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@69c509e6 main{StandardDirectoryReader(segments_3:17 _0(4.0.0.2):C1 _1(4.0.0.2):C10 _2(4.0.0.2):C10 _3(4.0.0.2):C10 _4(4.0.0.2):C10 _5(4.0.0.2):C10 _6(4.0.0.2):C10 _7(4.0.0.2):C6)}
[junit4:junit4]   2> 16059 T977 C69 P39143 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 351
[junit4:junit4]   2> 16063 T993 C66 P39145 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 16237 T993 C66 P39145 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty1/index,segFN=segments_2,generation=2,filenames=[_0.fnm, _0.frq, _0.tim, _0_nrm.cfe, segments_2, _0.fdx, _0_nrm.cfs, _0.si, _0.prx, _0.tip, _0.fdt]
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty1/index,segFN=segments_3,generation=3,filenames=[_3_nrm.cfe, _1.frq, _4.prx, _4.fnm, _4_nrm.cfe, _3.fdt, _1.fnm, _2.tim, _4.fdx, _4.frq, _0.prx, _0.fnm, _2.prx, _2.frq, _2.fdt, _3.prx, _2.fdx, _2.tip, _1.fdx, _1.prx, _3_nrm.cfs, _1.fdt, _0.tim, _0.frq, _4_nrm.cfs, _3.si, _0.tip, _2.si, _3.frq, _3.tim, _3.fnm, _2_nrm.cfe, _4.tip, _0.si, _2_nrm.cfs, _1.tip, _1.tim, _1_nrm.cfs, _4.tim, _4.si, _4.fdt, _0_nrm.cfs, _1_nrm.cfe, _2.fnm, _3.fdx, _1.si, _0_nrm.cfe, _0.fdx, _3.tip, segments_3, _0.fdt]
[junit4:junit4]   2> 16238 T993 C66 P39145 oasc.SolrDeletionPolicy.updateCommits newest commit = 3
[junit4:junit4]   2> 16270 T993 C66 P39145 oass.SolrIndexSearcher.<init> Opening Searcher@47328a84 main
[junit4:junit4]   2> 16271 T993 C66 P39145 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 16273 T1000 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@47328a84 main{StandardDirectoryReader(segments_3:11 _0(4.0.0.2):C1 _1(4.0.0.2):C10 _2(4.0.0.2):C10 _3(4.0.0.2):C10 _4(4.0.0.2):C1)}
[junit4:junit4]   2> 16274 T993 C66 P39145 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:39152/solr/collection1/, StdNode: http://127.0.0.1:39148/solr/collection1/, StdNode: http://127.0.0.1:39157/solr/collection1/]
[junit4:junit4]   2> 16276 T1015 C65 P39152 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 16278 T1029 C67 P39157 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 16278 T1009 C68 P39148 oasu.DirectUpdateHandler2.commit start commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4]   2> 16574 T1015 C65 P39152 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty3/index.20120919052844789,segFN=segments_2,generation=2,filenames=[_0.fnm, _0_nrm.cfe, _0.tim, _0.frq, segments_2, _0.fdx, _0_nrm.cfs, _0.si, _0.tip, _0.prx, _0.fdt]
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty3/index.20120919052844789,segFN=segments_3,generation=3,filenames=[_3_nrm.cfe, _1.frq, _4.prx, _4.fnm, _4_nrm.cfe, _3.fdt, _1.fnm, _2.tim, _4.fdx, _4.frq, _0.prx, _0.fnm, _2.prx, _2.frq, _2.fdt, _3.prx, _2.fdx, _2.tip, _1.fdx, _1.prx, _3_nrm.cfs, _1.fdt, _0.frq, _0.tim, _4_nrm.cfs, _3.si, _0.tip, _2.si, _3.frq, _3.tim, _3.fnm, _2_nrm.cfe, _4.tip, _0.si, _2_nrm.cfs, _1.tip, _1.tim, _1_nrm.cfs, _4.tim, _4.si, _4.fdt, _0_nrm.cfs, _1_nrm.cfe, _2.fnm, _3.fdx, _1.si, _0_nrm.cfe, _0.fdx, _3.tip, segments_3, _0.fdt]
[junit4:junit4]   2> 16574 T1015 C65 P39152 oasc.SolrDeletionPolicy.updateCommits newest commit = 3
[junit4:junit4]   2> 16579 T1015 C65 P39152 oass.SolrIndexSearcher.<init> Opening Searcher@7430413b main
[junit4:junit4]   2> 16580 T1015 C65 P39152 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 16581 T1024 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7430413b main{StandardDirectoryReader(segments_3:11:nrt _0(4.0.0.2):C1 _1(4.0.0.2):C10 _2(4.0.0.2):C10 _3(4.0.0.2):C10 _4(4.0.0.2):C1)}
[junit4:junit4]   2> 16582 T1015 C65 P39152 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&expungeDeletes=false&softCommit=false&version=2} {commit=} 0 306
[junit4:junit4]   2> 16584 T1009 C68 P39148 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty2/index,segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty2/index,segFN=segments_2,generation=2,filenames=[_3_nrm.cfe, _2.si, _3.frq, _1.frq, _3.tim, _3.fdt, _3.fnm, _1.fnm, _2.tim, _2_nrm.cfe, _2_nrm.cfs, _0.si, _0.prx, _1.tip, _1.tim, _1_nrm.cfs, _0.fnm, _2.prx, _2.fdt, _2.frq, _3.prx, _0_nrm.cfs, _2.fdx, _2.fnm, _1_nrm.cfe, _3.fdx, _3_nrm.cfs, _1.prx, _1.fdx, _2.tip, _1.fdt, _1.si, _0.frq, _0.tim, _0_nrm.cfe, segments_2, _3.si, _3.tip, _0.fdx, _0.tip, _0.fdt]
[junit4:junit4]   2> 16584 T1009 C68 P39148 oasc.SolrDeletionPolicy.updateCommits newest commit = 2
[junit4:junit4]   2> 16592 T1029 C67 P39157 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty4/index,segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/jetty4/index,segFN=segments_3,generation=3,filenames=[_3_nrm.cfe, _2.si, _3.frq, _1.frq, _3.tim, _3.fdt, _3.fnm, _1.fnm, _2.tim, _2_nrm.cfe, _2_nrm.cfs, _0.si, _0.prx, _1.tip, _1.tim, _1_nrm.cfs, _0.fnm, _2.prx, _2.fdt, _2.frq, _3.prx, _0_nrm.cfs, _2.fdx, _2.fnm, _1_nrm.cfe, _3.fdx, _3_nrm.cfs, _1.prx, _1.fdx, _2.tip, _1.fdt, _1.si, _0.frq, _0.tim, _0_nrm.cfe, _3.si, _3.tip, _0.fdx, _0.tip, _0.fdt, segments_3]
[junit4:junit4]   2> 16593 T1029 C67 P39157 oasc.SolrDeletionPolicy.updateCommits newest commit = 3
[junit4:junit4]   2> 16617 T1009 C68 P39148 oass.SolrIndexSearcher.<init> Opening Searcher@1b2d9d3 main
[junit4:junit4]   2> 16617 T1009 C68 P39148 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 16619 T1012 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1b2d9d3 main{StandardDirectoryReader(segments_2:9 _0(4.0.0.2):C10 _1(4.0.0.2):C10 _2(4.0.0.2):C10 _3(4.0.0.2):C5)}
[junit4:junit4]   2> 16620 T1009 C68 P39148 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&expungeDeletes=false&softCommit=false&version=2} {commit=} 0 342
[junit4:junit4]   2> 16628 T1029 C67 P39157 oass.SolrIndexSearcher.<init> Opening Searcher@7211fb37 main
[junit4:junit4]   2> 16629 T1029 C67 P39157 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 16630 T1038 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7211fb37 main{StandardDirectoryReader(segments_3:10 _0(4.0.0.2):C10 _1(4.0.0.2):C10 _2(4.0.0.2):C10 _3(4.0.0.2):C5)}
[junit4:junit4]   2> 16631 T1029 C67 P39157 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&expungeDeletes=false&softCommit=false&version=2} {commit=} 0 353
[junit4:junit4]   2> 16631 T993 C66 P39145 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 568
[junit4:junit4]   2> 16638 T978 C69 P39143 REQ /select {fl=id,score&shard.url=127.0.0.1:39143/solr/collection1/&NOW=1348050530252&start=0&q=*:*&distrib=false&isShard=true&wt=javabin&fsv=true&rows=10&version=2} hits=67 status=0 QTime=0 
[junit4:junit4]   2> 16648 T978 C69 P39143 REQ /select {shard.url=127.0.0.1:39143/solr/collection1/&NOW=1348050530252&q=*:*&ids=3,2,1,10,7,6,5,4,9,8&distrib=false&isShard=true&wt=javabin&version=2} status=0 QTime=6 
[junit4:junit4]   2> 16652 T977 C69 P39143 REQ /select {wt=javabin&q=*:*&version=2} hits=67 status=0 QTime=18 
[junit4:junit4]   2> 16654 T965 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:39140/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@508911c7
[junit4:junit4]   2> 16655 T1059 oaz.ClientCnxn$SendThread.startConnect Opening socket connection to server /127.0.0.1:39140
[junit4:junit4]   2> 1665

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

ient.AbstractHttpClient.execute(AbstractHttpClient.java:820)
[junit4:junit4]   2> 	at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:754)
[junit4:junit4]   2> 	at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:732)
[junit4:junit4]   2> 	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:353)
[junit4:junit4]   2> 	... 11 more
[junit4:junit4]   2> 
[junit4:junit4]   2> 303663 T1037 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:39157/solr DONE. sync failed
[junit4:junit4]   2> 303663 T1037 oasc.SolrException.log SEVERE Sync Failed
[junit4:junit4]   2> 303663 T1037 oasc.ShardLeaderElectionContext.rejoinLeaderElection Not rejoining election because CoreContainer is shutdown
[junit4:junit4]   2> 303663 T1037 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@59a9d2d
[junit4:junit4]   2> 303670 T1037 oasc.JmxMonitoredMap$SolrDynamicMBean.getMBeanInfo WARNING Could not getStatistics on info bean Lazy[solr.ReplicationHandler] java.lang.IllegalArgumentException: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/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:1804)
[junit4:junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.safeGetClassName(DefaultMBeanServerInterceptor.java:1595)
[junit4:junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.checkMBeanPermission(DefaultMBeanServerInterceptor.java:1813)
[junit4:junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.getAttribute(DefaultMBeanServerInterceptor.java:644)
[junit4:junit4]   2> 	at com.sun.jmx.mbeanserver.JmxMBeanServer.getAttribute(JmxMBeanServer.java:668)
[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> 303671 T1037 oasc.JmxMonitoredMap$SolrDynamicMBean.getMBeanInfo WARNING Could not getStatistics on info bean Lazy[solr.ReplicationHandler] java.lang.IllegalArgumentException: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-1348050513622/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:1804)
[junit4:junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.safeGetClassName(DefaultMBeanServerInterceptor.java:1595)
[junit4:junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.checkMBeanPermission(DefaultMBeanServerInterceptor.java:1813)
[junit4:junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.exclusiveUnregisterMBean(DefaultMBeanServerInterceptor.java:430)
[junit4:junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.unregisterMBean(DefaultMBeanServerInterceptor.java:415)
[junit4:junit4]   2> 	at com.sun.jmx.mbeanserver.JmxMBeanServer.unregisterMBean(JmxMBeanServer.java:536)
[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> 303683 T1037 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 303685 T1037 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> 303686 T1037 oasu.DefaultSolrCoreState.decref SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 303687 T1037 oasu.DefaultSolrCoreState.decref Closing SolrCoreState - canceling any ongoing recovery
[junit4:junit4]   2> 303688 T1037 oascc.ZkStateReader$3.process Updating live nodes
[junit4:junit4]   2> 303688 T1037 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 303688 T1037 oascc.ZkStateReader$2.process A cluster state change has occurred - updating...
[junit4:junit4]   2> 303688 T1037 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 303688 T1037 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b644cae name:ZooKeeperConnection Watcher:127.0.0.1:39140/solr got event WatchedEvent state:Disconnected type:None path:null path:null type:None
[junit4:junit4]   2> 303689 T1037 oascc.ConnectionManager.process Client->ZooKeeper status change trigger but we are already closed
[junit4:junit4]   2> 303689 T1037 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> NOTE: test params are: codec=Asserting, sim=DefaultSimilarity, locale=hr, timezone=America/Indiana/Tell_City
[junit4:junit4]   2> NOTE: FreeBSD 9.0-RELEASE amd64/Oracle Corporation 1.7.0_06 (64-bit)/cpus=16,threads=2,free=77820048,total=209715200
[junit4:junit4]   2> NOTE: All tests run in this JVM: [TestUpdate, TestLRUCache, TestRemoteStreaming, TestStressRecovery, PrimUtilsTest, SuggesterTSTTest, PolyFieldTest, UpdateParamsTest, TestSolrXMLSerializer, TestReload, XmlUpdateRequestHandlerTest, TestSolrDeletionPolicy1, PrimitiveFieldTypeTest, HighlighterTest, TestDocumentBuilder, ClusterStateUpdateTest, TermVectorComponentTest, DisMaxRequestHandlerTest, TestSort, IndexSchemaTest, TestWriterPerf, StatsComponentTest, DistributedQueryElevationComponentTest, MultiTermTest, SolrCoreTest, ZkNodePropsTest, TestPluginEnable, EchoParamsTest, LeaderElectionTest, TestDocSet, RequiredFieldsTest, TestRTGBase, LukeRequestHandlerTest, OverseerTest, SignatureUpdateProcessorFactoryTest, TestFoldingMultitermQuery, BasicDistributedZk2Test]
[junit4:junit4] Completed on J1 in 304.07s, 1 test, 1 failure <<< FAILURES!

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

Total time: 38 minutes 59 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