lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-trunk-Linux (64bit/jdk1.8.0-ea-b82) - Build # 4832 - Still Failing!
Date Sat, 23 Mar 2013 06:46:11 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/4832/
Java: 64bit/jdk1.8.0-ea-b82 -XX:+UseSerialGC

2 tests failed.
FAILED:  org.apache.solr.cloud.BasicDistributedZk2Test.testDistribSearch

Error Message:
Server at http://127.0.0.1:39811/onenodecollectioncore returned non ok status:404, message:Can not find: /onenodecollectioncore/update

Stack Trace:
org.apache.solr.common.SolrException: Server at http://127.0.0.1:39811/onenodecollectioncore returned non ok status:404, message:Can not find: /onenodecollectioncore/update
	at __randomizedtesting.SeedInfo.seed([B6D7B904D28757ED:3731371CA5D837D1]:0)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:375)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
	at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
	at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:116)
	at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:102)
	at org.apache.solr.cloud.BasicDistributedZk2Test.testNodeWithoutCollectionForwarding(BasicDistributedZk2Test.java:197)
	at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:89)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:806)
	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:487)
	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:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	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:46)
	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)


FAILED:  org.apache.solr.cloud.UnloadDistributedZkTest.testDistribSearch

Error Message:
Still found shard2 in collection test_unload_shard_and_collection

Stack Trace:
java.lang.AssertionError: Still found shard2 in collection test_unload_shard_and_collection
	at __randomizedtesting.SeedInfo.seed([B6D7B904D28757ED:3731371CA5D837D1]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.cloud.UnloadDistributedZkTest.testUnloadShardAndCollection(UnloadDistributedZkTest.java:127)
	at org.apache.solr.cloud.UnloadDistributedZkTest.doTest(UnloadDistributedZkTest.java:77)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:806)
	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:487)
	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:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	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:46)
	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 9192 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4:junit4]   2> 0 T944 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4]   2> 4 T944 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1364020434854
[junit4:junit4]   2> 4 T944 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 5 T945 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4]   2> 6 T945 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4]   2> 6 T945 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4]   2> 6 T945 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4]   2> 6 T945 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 6 T945 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/zookeeper/server1/data/version-2/snapshot.0
[junit4:junit4]   2> 105 T944 oasc.ZkTestServer.run start zk server on port:58621
[junit4:junit4]   2> 105 T944 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:58621 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@cc59891
[junit4:junit4]   2> 106 T944 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 106 T950 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:58621. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 107 T950 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:58621, initiating session
[junit4:junit4]   2> 107 T946 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:46272
[junit4:junit4]   2> 107 T946 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:46272
[junit4:junit4]   2> 108 T948 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 136 T948 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d95f417a90000 with negotiated timeout 10000 for client /127.0.0.1:46272
[junit4:junit4]   2> 136 T950 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:58621, sessionid = 0x13d95f417a90000, negotiated timeout = 10000
[junit4:junit4]   2> 137 T951 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@cc59891 name:ZooKeeperConnection Watcher:127.0.0.1:58621 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 137 T944 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 137 T944 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 141 T949 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d95f417a90000
[junit4:junit4]   2> 142 T951 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 142 T946 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:46272 which had sessionid 0x13d95f417a90000
[junit4:junit4]   2> 142 T944 oaz.ZooKeeper.close Session: 0x13d95f417a90000 closed
[junit4:junit4]   2> 143 T944 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:58621/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@2027779
[junit4:junit4]   2> 143 T944 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 144 T952 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:58621. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 144 T952 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:58621, initiating session
[junit4:junit4]   2> 144 T946 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:46273
[junit4:junit4]   2> 144 T946 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:46273
[junit4:junit4]   2> 145 T948 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d95f417a90001 with negotiated timeout 10000 for client /127.0.0.1:46273
[junit4:junit4]   2> 145 T952 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:58621, sessionid = 0x13d95f417a90001, negotiated timeout = 10000
[junit4:junit4]   2> 145 T953 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2027779 name:ZooKeeperConnection Watcher:127.0.0.1:58621/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 145 T944 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 146 T944 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 149 T944 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 152 T944 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 154 T944 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 156 T944 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 157 T944 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 161 T944 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4]   2> 162 T944 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 166 T944 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4]   2> 166 T944 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 168 T944 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4]   2> 169 T944 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 172 T944 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4]   2> 172 T944 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 177 T944 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 177 T944 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 180 T944 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 181 T944 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 184 T944 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 184 T944 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 186 T944 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4]   2> 187 T944 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 189 T949 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d95f417a90001
[junit4:junit4]   2> 190 T953 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 190 T946 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:46273 which had sessionid 0x13d95f417a90001
[junit4:junit4]   2> 190 T944 oaz.ZooKeeper.close Session: 0x13d95f417a90001 closed
[junit4:junit4]   2> 246 T944 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 261 T944 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49239
[junit4:junit4]   2> 262 T944 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 262 T944 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 263 T944 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1364020435041
[junit4:junit4]   2> 263 T944 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1364020435041/solr.xml
[junit4:junit4]   2> 263 T944 oasc.CoreContainer.<init> New CoreContainer 7976772
[junit4:junit4]   2> 263 T944 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1364020435041/'
[junit4:junit4]   2> 264 T944 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1364020435041/'
[junit4:junit4]   2> 279 T944 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 280 T944 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 280 T944 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 280 T944 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 281 T944 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 281 T944 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 281 T944 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 281 T944 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 282 T944 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 282 T944 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 287 T944 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 296 T944 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:58621/solr
[junit4:junit4]   2> 296 T944 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 297 T944 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:58621 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@3e531f2
[junit4:junit4]   2> 297 T944 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 298 T963 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:58621. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 298 T963 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:58621, initiating session
[junit4:junit4]   2> 298 T946 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:46274
[junit4:junit4]   2> 299 T946 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:46274
[junit4:junit4]   2> 299 T948 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d95f417a90002 with negotiated timeout 20000 for client /127.0.0.1:46274
[junit4:junit4]   2> 299 T963 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:58621, sessionid = 0x13d95f417a90002, negotiated timeout = 20000
[junit4:junit4]   2> 300 T964 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3e531f2 name:ZooKeeperConnection Watcher:127.0.0.1:58621 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 300 T944 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 301 T949 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d95f417a90002
[junit4:junit4]   2> 302 T964 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 302 T946 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:46274 which had sessionid 0x13d95f417a90002
[junit4:junit4]   2> 302 T944 oaz.ZooKeeper.close Session: 0x13d95f417a90002 closed
[junit4:junit4]   2> 303 T944 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 305 T944 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:58621/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@43c70b64
[junit4:junit4]   2> 305 T944 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 306 T965 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:58621. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 306 T965 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:58621, initiating session
[junit4:junit4]   2> 306 T946 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:46275
[junit4:junit4]   2> 306 T946 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:46275
[junit4:junit4]   2> 307 T948 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d95f417a90003 with negotiated timeout 20000 for client /127.0.0.1:46275
[junit4:junit4]   2> 307 T965 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:58621, sessionid = 0x13d95f417a90003, negotiated timeout = 20000
[junit4:junit4]   2> 307 T966 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@43c70b64 name:ZooKeeperConnection Watcher:127.0.0.1:58621/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 308 T944 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 310 T944 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4]   2> 312 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a90003 type:create cxid:0x7 zxid:0x1b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 313 T944 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4]   2> 316 T944 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 318 T944 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49239_
[junit4:junit4]   2> 318 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a90003 type:delete cxid:0x12 zxid:0x1e txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:49239_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:49239_
[junit4:junit4]   2> 319 T944 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49239_
[junit4:junit4]   2> 321 T944 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 327 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a90003 type:delete cxid:0x20 zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for /solr/overseer_elect/leader
[junit4:junit4]   2> 327 T944 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 329 T944 oasc.Overseer.start Overseer (id=89392443218788355-127.0.0.1:49239_-n_0000000000) starting
[junit4:junit4]   2> 329 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a90003 type:create cxid:0x25 zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 330 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a90003 type:create cxid:0x26 zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 331 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a90003 type:create cxid:0x28 zxid:0x27 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 332 T944 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4]   2> 334 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a90003 type:create cxid:0x2e zxid:0x29 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 335 T968 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 336 T944 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 338 T944 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4]   2> 339 T944 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 341 T967 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 343 T969 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1364020435041/collection1
[junit4:junit4]   2> 343 T969 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 343 T969 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 343 T969 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 344 T969 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1364020435041/collection1/'
[junit4:junit4]   2> 345 T969 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1364020435041/collection1/lib/README' to classloader
[junit4:junit4]   2> 345 T969 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1364020435041/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 373 T969 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 398 T969 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 400 T969 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 403 T969 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 690 T969 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 703 T969 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 704 T969 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 717 T969 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 720 T969 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 723 T969 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 724 T969 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 726 T969 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 726 T969 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 727 T969 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 727 T969 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 727 T969 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 727 T969 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1364020435041/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/control/data/
[junit4:junit4]   2> 727 T969 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3447d61
[junit4:junit4]   2> 728 T969 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 728 T969 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/control/data
[junit4:junit4]   2> 728 T969 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/control/data/index/
[junit4:junit4]   2> 728 T969 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/control/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 729 T969 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/control/data/index
[junit4:junit4]   2> 730 T969 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@396092f7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@463b7008),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 730 T969 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 731 T969 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 732 T969 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 732 T969 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 732 T969 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 733 T969 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 733 T969 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 733 T969 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 733 T969 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 733 T969 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 736 T969 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 739 T969 oass.SolrIndexSearcher.<init> Opening Searcher@6c10209d main
[junit4:junit4]   2> 739 T969 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/control/data/tlog
[junit4:junit4]   2> 740 T969 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 740 T969 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 744 T970 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6c10209d main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 745 T969 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 745 T969 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 1844 T967 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 1845 T967 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "collection":"control_collection",
[junit4:junit4]   2> 	  "core_node_name":"1",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:49239_",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:49239"}
[junit4:junit4]   2> 1845 T967 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4]   2> 1845 T967 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 1849 T966 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   2> 2747 T969 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 2747 T969 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49239 collection:control_collection shard:shard1
[junit4:junit4]   2> 2748 T969 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4]   2> 2756 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a90003 type:delete cxid:0x82 zxid:0x35 txntype:-1 reqpath:n/a Error Path:/solr/collections/control_collection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/control_collection/leaders
[junit4:junit4]   2> 2757 T969 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 2758 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a90003 type:create cxid:0x83 zxid:0x36 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2760 T969 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 2760 T969 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 2760 T969 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49239/collection1/
[junit4:junit4]   2> 2760 T969 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 2761 T969 oasc.SyncStrategy.syncToMe http://127.0.0.1:49239/collection1/ has no replicas
[junit4:junit4]   2> 2761 T969 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49239/collection1/
[junit4:junit4]   2> 2761 T969 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4]   2> 2765 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a90003 type:create cxid:0x8e zxid:0x3a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3354 T967 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3362 T966 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   2> 3369 T969 oasc.ZkController.register We are http://127.0.0.1:49239/collection1/ and leader is http://127.0.0.1:49239/collection1/
[junit4:junit4]   2> 3370 T969 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49239
[junit4:junit4]   2> 3370 T969 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 3370 T969 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 3370 T969 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 3371 T969 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3372 T944 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 3373 T944 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 3373 T944 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 3376 T944 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 3377 T944 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:58621/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@707bd7f8
[junit4:junit4]   2> 3377 T944 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 3378 T972 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:58621. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 3378 T972 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:58621, initiating session
[junit4:junit4]   2> 3378 T946 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:46281
[junit4:junit4]   2> 3378 T946 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:46281
[junit4:junit4]   2> 3379 T948 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d95f417a90004 with negotiated timeout 10000 for client /127.0.0.1:46281
[junit4:junit4]   2> 3379 T972 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:58621, sessionid = 0x13d95f417a90004, negotiated timeout = 10000
[junit4:junit4]   2> 3385 T973 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@707bd7f8 name:ZooKeeperConnection Watcher:127.0.0.1:58621/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3386 T944 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 3387 T944 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 3389 T944 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   2> 3446 T944 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 3448 T944 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58137
[junit4:junit4]   2> 3449 T944 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 3449 T944 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 3450 T944 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1364020438239
[junit4:junit4]   2> 3450 T944 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1364020438239/solr.xml
[junit4:junit4]   2> 3450 T944 oasc.CoreContainer.<init> New CoreContainer 1697825671
[junit4:junit4]   2> 3451 T944 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1364020438239/'
[junit4:junit4]   2> 3451 T944 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1364020438239/'
[junit4:junit4]   2> 3468 T944 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 3468 T944 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 3469 T944 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 3469 T944 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 3469 T944 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 3469 T944 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 3470 T944 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 3470 T944 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 3470 T944 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 3471 T944 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 3476 T944 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 3485 T944 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:58621/solr
[junit4:junit4]   2> 3485 T944 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 3485 T944 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:58621 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@10f957bd
[junit4:junit4]   2> 3486 T944 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 3486 T983 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:58621. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 3492 T983 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:58621, initiating session
[junit4:junit4]   2> 3492 T946 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:46282
[junit4:junit4]   2> 3493 T946 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:46282
[junit4:junit4]   2> 3493 T948 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d95f417a90005 with negotiated timeout 20000 for client /127.0.0.1:46282
[junit4:junit4]   2> 3493 T983 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:58621, sessionid = 0x13d95f417a90005, negotiated timeout = 20000
[junit4:junit4]   2> 3494 T984 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10f957bd name:ZooKeeperConnection Watcher:127.0.0.1:58621 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3494 T944 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 3495 T949 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d95f417a90005
[junit4:junit4]   2> 3496 T984 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 3496 T946 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:46282 which had sessionid 0x13d95f417a90005
[junit4:junit4]   2> 3496 T944 oaz.ZooKeeper.close Session: 0x13d95f417a90005 closed
[junit4:junit4]   2> 3496 T944 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 3499 T944 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:58621/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@117166df
[junit4:junit4]   2> 3499 T944 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 3500 T985 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:58621. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 3500 T985 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:58621, initiating session
[junit4:junit4]   2> 3500 T946 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:46283
[junit4:junit4]   2> 3501 T946 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:46283
[junit4:junit4]   2> 3501 T948 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d95f417a90006 with negotiated timeout 20000 for client /127.0.0.1:46283
[junit4:junit4]   2> 3501 T985 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:58621, sessionid = 0x13d95f417a90006, negotiated timeout = 20000
[junit4:junit4]   2> 3502 T986 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@117166df name:ZooKeeperConnection Watcher:127.0.0.1:58621/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3502 T944 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 3503 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a90006 type:create cxid:0x1 zxid:0x48 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3504 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a90006 type:create cxid:0x3 zxid:0x49 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3506 T944 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 4508 T944 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58137_
[junit4:junit4]   2> 4509 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a90006 type:delete cxid:0xd zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:58137_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:58137_
[junit4:junit4]   2> 4510 T944 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58137_
[junit4:junit4]   2> 4513 T966 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 4513 T986 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 4513 T966 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 4513 T973 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 4518 T987 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1364020438239/collection1
[junit4:junit4]   2> 4518 T987 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 4519 T987 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 4519 T987 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 4520 T987 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1364020438239/collection1/'
[junit4:junit4]   2> 4521 T987 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1364020438239/collection1/lib/README' to classloader
[junit4:junit4]   2> 4521 T987 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1364020438239/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 4550 T987 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 4575 T987 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 4576 T987 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 4579 T987 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 4868 T967 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4868 T967 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "collection":"control_collection",
[junit4:junit4]   2> 	  "core_node_name":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:49239_",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:49239"}
[junit4:junit4]   2> 4872 T966 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 4872 T986 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 4872 T973 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 4887 T987 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 4892 T987 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 4894 T987 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 4907 T987 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 4910 T987 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 4913 T987 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 4914 T987 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 4914 T987 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 4915 T987 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 4916 T987 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 4916 T987 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 4916 T987 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 4916 T987 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1364020438239/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/jetty1/
[junit4:junit4]   2> 4916 T987 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3447d61
[junit4:junit4]   2> 4917 T987 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 4917 T987 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/jetty1
[junit4:junit4]   2> 4917 T987 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/jetty1/index/
[junit4:junit4]   2> 4917 T987 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 4918 T987 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/jetty1/index
[junit4:junit4]   2> 4919 T987 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@58aa816d lockFactory=org.apache.lucene.store.NativeFSLockFactory@3a6629ca),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 4919 T987 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 4921 T987 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 4921 T987 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 4921 T987 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 4922 T987 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 4922 T987 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 4922 T987 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 4922 T987 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 4923 T987 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 4923 T987 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 4925 T987 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 4927 T987 oass.SolrIndexSearcher.<init> Opening Searcher@22995c08 main
[junit4:junit4]   2> 4928 T987 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/jetty1/tlog
[junit4:junit4]   2> 4928 T987 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 4928 T987 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 4932 T988 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@22995c08 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 4933 T987 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 4933 T987 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 6376 T967 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6377 T967 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core_node_name":"2",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:58137_",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:58137"}
[junit4:junit4]   2> 6377 T967 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4]   2> 6377 T967 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4]   2> 6382 T986 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 6382 T966 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 6382 T973 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 6936 T987 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 6936 T987 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:58137 collection:collection1 shard:shard2
[junit4:junit4]   2> 6937 T987 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4]   2> 6943 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a90006 type:delete cxid:0x4a zxid:0x5a txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders
[junit4:junit4]   2> 6943 T987 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 6944 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a90006 type:create cxid:0x4b zxid:0x5b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 6945 T987 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 6946 T987 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 6946 T987 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:58137/collection1/
[junit4:junit4]   2> 6946 T987 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 6946 T987 oasc.SyncStrategy.syncToMe http://127.0.0.1:58137/collection1/ has no replicas
[junit4:junit4]   2> 6946 T987 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:58137/collection1/
[junit4:junit4]   2> 6946 T987 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4]   2> 6950 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a90006 type:create cxid:0x56 zxid:0x5f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7887 T967 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7895 T986 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 7895 T973 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 7895 T966 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 7905 T987 oasc.ZkController.register We are http://127.0.0.1:58137/collection1/ and leader is http://127.0.0.1:58137/collection1/
[junit4:junit4]   2> 7905 T987 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58137
[junit4:junit4]   2> 7905 T987 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 7906 T987 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 7906 T987 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 7907 T987 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7908 T944 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 7909 T944 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 7909 T944 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 7967 T944 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 7969 T944 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:39811
[junit4:junit4]   2> 7970 T944 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 7970 T944 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 7971 T944 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1364020442763
[junit4:junit4]   2> 7971 T944 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1364020442763/solr.xml
[junit4:junit4]   2> 7971 T944 oasc.CoreContainer.<init> New CoreContainer 911279854
[junit4:junit4]   2> 7972 T944 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1364020442763/'
[junit4:junit4]   2> 7972 T944 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1364020442763/'
[junit4:junit4]   2> 7988 T944 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 7988 T944 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 7988 T944 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 7989 T944 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 7989 T944 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 7989 T944 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 7989 T944 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 7990 T944 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 7990 T944 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 7990 T944 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 7995 T944 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 8003 T944 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:58621/solr
[junit4:junit4]   2> 8004 T944 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 8004 T944 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:58621 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@5fc98c73
[junit4:junit4]   2> 8005 T944 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 8005 T999 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:58621. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 8006 T999 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:58621, initiating session
[junit4:junit4]   2> 8006 T946 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:46299
[junit4:junit4]   2> 8006 T946 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:46299
[junit4:junit4]   2> 8007 T948 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d95f417a90007 with negotiated timeout 20000 for client /127.0.0.1:46299
[junit4:junit4]   2> 8007 T999 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:58621, sessionid = 0x13d95f417a90007, negotiated timeout = 20000
[junit4:junit4]   2> 8007 T1000 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5fc98c73 name:ZooKeeperConnection Watcher:127.0.0.1:58621 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 8007 T944 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 8008 T949 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d95f417a90007
[junit4:junit4]   2> 8009 T1000 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 8009 T944 oaz.ZooKeeper.close Session: 0x13d95f417a90007 closed
[junit4:junit4]   2> 8009 T946 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:46299 which had sessionid 0x13d95f417a90007
[junit4:junit4]   2> 8010 T944 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 8012 T944 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:58621/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@329139b1
[junit4:junit4]   2> 8012 T944 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 8012 T1001 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:58621. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 8013 T1001 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:58621, initiating session
[junit4:junit4]   2> 8013 T946 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:46300
[junit4:junit4]   2> 8013 T946 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:46300
[junit4:junit4]   2> 8014 T948 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d95f417a90008 with negotiated timeout 20000 for client /127.0.0.1:46300
[junit4:junit4]   2> 8014 T1001 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:58621, sessionid = 0x13d95f417a90008, negotiated timeout = 20000
[junit4:junit4]   2> 8014 T1002 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@329139b1 name:ZooKeeperConnection Watcher:127.0.0.1:58621/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 8015 T944 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 8016 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a90008 type:create cxid:0x1 zxid:0x6c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8017 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a90008 type:create cxid:0x3 zxid:0x6d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8019 T944 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 9022 T944 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39811_
[junit4:junit4]   2> 9023 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a90008 type:delete cxid:0xd zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:39811_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:39811_
[junit4:junit4]   2> 9023 T944 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:39811_
[junit4:junit4]   2> 9025 T966 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 9025 T986 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 9026 T1002 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9026 T973 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9026 T973 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 9027 T986 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9027 T966 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9030 T1003 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1364020442763/collection1
[junit4:junit4]   2> 9030 T1003 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 9031 T1003 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 9031 T1003 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 9032 T1003 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1364020442763/collection1/'
[junit4:junit4]   2> 9032 T1003 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1364020442763/collection1/lib/README' to classloader
[junit4:junit4]   2> 9033 T1003 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1364020442763/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 9064 T1003 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 9089 T1003 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 9090 T1003 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 9093 T1003 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 9385 T1003 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 9390 T1003 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 9392 T1003 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 9401 T967 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9402 T967 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core_node_name":"2",
[junit4:junit4]   2> 	  "shard":"shard2",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:58137_",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:58137"}
[junit4:junit4]   2> 9405 T1003 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 9405 T966 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 9405 T1002 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 9405 T986 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 9405 T973 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 9408 T1003 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 9411 T1003 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 9412 T1003 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 9412 T1003 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 9412 T1003 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 9413 T1003 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 9413 T1003 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 9413 T1003 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 9414 T1003 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1364020442763/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/jetty2/
[junit4:junit4]   2> 9414 T1003 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3447d61
[junit4:junit4]   2> 9414 T1003 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 9415 T1003 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/jetty2
[junit4:junit4]   2> 9415 T1003 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/jetty2/index/
[junit4:junit4]   2> 9415 T1003 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 9415 T1003 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/jetty2/index
[junit4:junit4]   2> 9416 T1003 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@753b9796 lockFactory=org.apache.lucene.store.NativeFSLockFactory@24fef8d2),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 9417 T1003 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 9418 T1003 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 9418 T1003 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 9419 T1003 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 9419 T1003 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 9420 T1003 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 9420 T1003 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 9420 T1003 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 9420 T1003 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 9421 T1003 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 9423 T1003 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 9425 T1003 oass.SolrIndexSearcher.<init> Opening Searcher@e1f9270 main
[junit4:junit4]   2> 9425 T1003 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/jetty2/tlog
[junit4:junit4]   2> 9426 T1003 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 9426 T1003 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 9429 T1004 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@e1f9270 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 9431 T1003 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 9431 T1003 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 10911 T967 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 10913 T967 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core_node_name":"3",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:39811_",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:39811"}
[junit4:junit4]   2> 10913 T967 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4]   2> 10913 T967 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 10921 T966 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 10921 T1002 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 10921 T973 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 10921 T986 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 11432 T1003 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 11433 T1003 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:39811 collection:collection1 shard:shard1
[junit4:junit4]   2> 11434 T1003 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 11444 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a90008 type:delete cxid:0x49 zxid:0x7d txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders/shard1 Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders/shard1
[junit4:junit4]   2> 11444 T1003 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 11445 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a90008 type:create cxid:0x4a zxid:0x7e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 11449 T1003 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 11449 T1003 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 11449 T1003 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:39811/collection1/
[junit4:junit4]   2> 11450 T1003 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 11450 T1003 oasc.SyncStrategy.syncToMe http://127.0.0.1:39811/collection1/ has no replicas
[junit4:junit4]   2> 11450 T1003 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:39811/collection1/
[junit4:junit4]   2> 11451 T1003 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 11456 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a90008 type:create cxid:0x54 zxid:0x81 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 12429 T967 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12443 T1002 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 12443 T973 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 12443 T986 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 12443 T966 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 12463 T1003 oasc.ZkController.register We are http://127.0.0.1:39811/collection1/ and leader is http://127.0.0.1:39811/collection1/
[junit4:junit4]   2> 12463 T1003 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:39811
[junit4:junit4]   2> 12463 T1003 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 12464 T1003 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 12464 T1003 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 12466 T1003 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12468 T944 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 12469 T944 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 12470 T944 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 12528 T944 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 12531 T944 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:54300
[junit4:junit4]   2> 12532 T944 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 12533 T944 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 12533 T944 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1364020447325
[junit4:junit4]   2> 12534 T944 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1364020447325/solr.xml
[junit4:junit4]   2> 12535 T944 oasc.CoreContainer.<init> New CoreContainer 246008904
[junit4:junit4]   2> 12535 T944 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1364020447325/'
[junit4:junit4]   2> 12536 T944 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1364020447325/'
[junit4:junit4]   2> 12554 T944 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 12554 T944 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 12554 T944 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 12555 T944 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 12555 T944 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 12555 T944 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 12555 T944 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 12556 T944 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 12556 T944 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 12556 T944 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 12561 T944 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 12568 T944 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:58621/solr
[junit4:junit4]   2> 12569 T944 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 12569 T944 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:58621 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@25984de0
[junit4:junit4]   2> 12570 T944 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 12570 T1015 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:58621. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 12571 T1015 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:58621, initiating session
[junit4:junit4]   2> 12571 T946 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:46312
[junit4:junit4]   2> 12572 T946 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:46312
[junit4:junit4]   2> 12573 T948 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d95f417a90009 with negotiated timeout 20000 for client /127.0.0.1:46312
[junit4:junit4]   2> 12573 T1015 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:58621, sessionid = 0x13d95f417a90009, negotiated timeout = 20000
[junit4:junit4]   2> 12573 T1016 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@25984de0 name:ZooKeeperConnection Watcher:127.0.0.1:58621 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 12574 T944 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 12575 T949 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d95f417a90009
[junit4:junit4]   2> 12576 T1016 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 12576 T944 oaz.ZooKeeper.close Session: 0x13d95f417a90009 closed
[junit4:junit4]   2> 12576 T946 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:46312 which had sessionid 0x13d95f417a90009
[junit4:junit4]   2> 12576 T944 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 12579 T944 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:58621/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@31a1b0a1
[junit4:junit4]   2> 12579 T944 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 12579 T1017 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:58621. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 12580 T1017 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:58621, initiating session
[junit4:junit4]   2> 12580 T946 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:46313
[junit4:junit4]   2> 12580 T946 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:46313
[junit4:junit4]   2> 12581 T948 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d95f417a9000a with negotiated timeout 20000 for client /127.0.0.1:46313
[junit4:junit4]   2> 12581 T1017 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:58621, sessionid = 0x13d95f417a9000a, negotiated timeout = 20000
[junit4:junit4]   2> 12581 T1018 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@31a1b0a1 name:ZooKeeperConnection Watcher:127.0.0.1:58621/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 12582 T944 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 12583 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a9000a type:create cxid:0x1 zxid:0x8e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 12585 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a9000a type:create cxid:0x3 zxid:0x8f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 12588 T944 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 13591 T944 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54300_
[junit4:junit4]   2> 13592 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a9000a type:delete cxid:0xd zxid:0x90 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:54300_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:54300_
[junit4:junit4]   2> 13594 T944 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54300_
[junit4:junit4]   2> 13599 T973 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 13599 T1002 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 13600 T966 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 13600 T986 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 13600 T986 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 13600 T1018 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 13600 T966 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 13602 T973 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 13602 T1002 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 13610 T1019 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1364020447325/collection1
[junit4:junit4]   2> 13610 T1019 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 13611 T1019 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 13611 T1019 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 13614 T1019 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1364020447325/collection1/'
[junit4:junit4]   2> 13614 T1019 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1364020447325/collection1/lib/README' to classloader
[junit4:junit4]   2> 13615 T1019 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1364020447325/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 13670 T1019 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 13699 T1019 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 13700 T1019 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 13706 T1019 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 13957 T967 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 13958 T967 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core_node_name":"3",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:39811_",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:39811"}
[junit4:junit4]   2> 13964 T973 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 13965 T1018 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 13965 T986 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 13965 T966 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 13965 T1002 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 14049 T1019 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 14057 T1019 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 14060 T1019 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 14080 T1019 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 14084 T1019 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 14087 T1019 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 14088 T1019 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 14089 T1019 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 14089 T1019 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 14091 T1019 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 14091 T1019 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 14092 T1019 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 14092 T1019 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1364020447325/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/jetty3/
[junit4:junit4]   2> 14092 T1019 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3447d61
[junit4:junit4]   2> 14093 T1019 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 14094 T1019 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/jetty3
[junit4:junit4]   2> 14094 T1019 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/jetty3/index/
[junit4:junit4]   2> 14094 T1019 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 14095 T1019 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/jetty3/index
[junit4:junit4]   2> 14097 T1019 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5594612a lockFactory=org.apache.lucene.store.NativeFSLockFactory@22cf3f4f),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 14098 T1019 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 14101 T1019 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 14101 T1019 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 14102 T1019 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 14103 T1019 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 14103 T1019 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 14104 T1019 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 14104 T1019 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 14105 T1019 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 14105 T1019 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 14110 T1019 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 14114 T1019 oass.SolrIndexSearcher.<init> Opening Searcher@510c3920 main
[junit4:junit4]   2> 14114 T1019 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/jetty3/tlog
[junit4:junit4]   2> 14115 T1019 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 14115 T1019 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 14122 T1020 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@510c3920 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 14125 T1019 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 14125 T1019 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 15474 T967 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 15475 T967 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core_node_name":"4",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:54300_",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:54300"}
[junit4:junit4]   2> 15475 T967 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4]   2> 15476 T967 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4]   2> 15484 T973 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 15484 T1018 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 15484 T986 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 15484 T1002 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 15484 T966 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 16127 T1019 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 16128 T1019 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:54300 collection:collection1 shard:shard2
[junit4:junit4]   2> 16134 T1019 oasc.ZkController.register We are http://127.0.0.1:54300/collection1/ and leader is http://127.0.0.1:58137/collection1/
[junit4:junit4]   2> 16134 T1019 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:54300
[junit4:junit4]   2> 16134 T1019 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 16134 T1019 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C89 name=collection1 org.apache.solr.core.SolrCore@5b826431 url=http://127.0.0.1:54300/collection1 node=127.0.0.1:54300_ C89_STATE=coll:collection1 core:collection1 props:{core=collection1, collection=collection1, node_name=127.0.0.1:54300_, state=down, base_url=http://127.0.0.1:54300}
[junit4:junit4]   2> 16135 T1021 C89 P54300 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 16136 T1019 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 16137 T1021 C89 P54300 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 16138 T1021 C89 P54300 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 16138 T1021 C89 P54300 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 16139 T944 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 16140 T944 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 16140 T1021 C89 P54300 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 16140 T944 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 16208 T944 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 16210 T944 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:56280
[junit4:junit4]   2> 16211 T944 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 16212 T944 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 16213 T944 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1364020450996
[junit4:junit4]   2> 16213 T944 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1364020450996/solr.xml
[junit4:junit4]   2> 16214 T944 oasc.CoreContainer.<init> New CoreContainer 1681822901
[junit4:junit4]   2> 16214 T944 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1364020450996/'
[junit4:junit4]   2> 16215 T944 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1364020450996/'
[junit4:junit4]   2> 16242 T944 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 16242 T944 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 16242 T944 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 16243 T944 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 16243 T944 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 16243 T944 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 16243 T944 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 16244 T944 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 16244 T944 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 16244 T944 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 16249 T944 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 16256 T944 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:58621/solr
[junit4:junit4]   2> 16256 T944 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 16257 T944 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:58621 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@53993614
[junit4:junit4]   2> 16258 T944 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 16258 T1032 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:58621. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 16259 T1032 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:58621, initiating session
[junit4:junit4]   2> 16259 T946 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:46319
[junit4:junit4]   2> 16260 T946 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:46319
[junit4:junit4]   2> 16262 T948 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d95f417a9000b with negotiated timeout 20000 for client /127.0.0.1:46319
[junit4:junit4]   2> 16262 T1032 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:58621, sessionid = 0x13d95f417a9000b, negotiated timeout = 20000
[junit4:junit4]   2> 16262 T1033 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@53993614 name:ZooKeeperConnection Watcher:127.0.0.1:58621 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 16262 T944 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 16264 T949 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d95f417a9000b
[junit4:junit4]   2> 16265 T1033 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 16265 T946 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:46319 which had sessionid 0x13d95f417a9000b
[junit4:junit4]   2> 16265 T944 oaz.ZooKeeper.close Session: 0x13d95f417a9000b closed
[junit4:junit4]   2> 16266 T944 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 16268 T944 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:58621/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@473a7f04
[junit4:junit4]   2> 16269 T1034 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:58621. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 16269 T944 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 16269 T1034 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:58621, initiating session
[junit4:junit4]   2> 16270 T946 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:46320
[junit4:junit4]   2> 16270 T946 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:46320
[junit4:junit4]   2> 16271 T948 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d95f417a9000c with negotiated timeout 20000 for client /127.0.0.1:46320
[junit4:junit4]   2> 16271 T1034 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:58621, sessionid = 0x13d95f417a9000c, negotiated timeout = 20000
[junit4:junit4]   2> 16272 T1035 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@473a7f04 name:ZooKeeperConnection Watcher:127.0.0.1:58621/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 16272 T944 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 16273 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a9000c type:create cxid:0x1 zxid:0xa1 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 16275 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a9000c type:create cxid:0x3 zxid:0xa2 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 16279 T944 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 16992 T967 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 16994 T967 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core_node_name":"4",
[junit4:junit4]   2> 	  "shard":"shard2",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:54300_",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"recovering",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:54300"}
[junit4:junit4]   2> 17001 T973 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 17001 T966 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 17001 T1002 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 17001 T986 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 17002 T1018 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 17003 T1035 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 17147 T982 oass.SolrDispatchFilter.handleAdminRequest /admin/cores {wt=javabin&coreNodeName=4&core=collection1&nodeName=127.0.0.1:54300_&action=PREPRECOVERY&version=2&checkLive=true&state=recovering&onlyIfLeader=true} status=0 QTime=1000 
[junit4:junit4]   2> 17285 T944 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:56280_
[junit4:junit4]   2> 17287 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a9000c type:delete cxid:0xf zxid:0xa7 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:56280_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:56280_
[junit4:junit4]   2> 17290 T944 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:56280_
[junit4:junit4]   2> 17294 T986 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 17294 T973 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 17294 T1002 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 17294 T1035 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 17294 T1018 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 17295 T966 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 17295 T966 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 17298 T986 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 17298 T973 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 17298 T1002 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 17298 T1018 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 17299 T1035 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 17307 T1036 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1364020450996/collection1
[junit4:junit4]   2> 17307 T1036 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 17309 T1036 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 17309 T1036 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 17311 T1036 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1364020450996/collection1/'
[junit4:junit4]   2> 17312 T1036 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1364020450996/collection1/lib/README' to classloader
[junit4:junit4]   2> 17312 T1036 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1364020450996/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 17368 T1036 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 17397 T1036 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 17399 T1036 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 17402 T1036 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 17751 T1036 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 17759 T1036 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 17761 T1036 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 17781 T1036 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 17787 T1036 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 17792 T1036 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 17794 T1036 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 17795 T1036 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 17795 T1036 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 17797 T1036 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 17798 T1036 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 17798 T1036 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 17798 T1036 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1364020450996/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/jetty4/
[junit4:junit4]   2> 17799 T1036 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3447d61
[junit4:junit4]   2> 17799 T1036 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 17800 T1036 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/jetty4
[junit4:junit4]   2> 17800 T1036 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/jetty4/index/
[junit4:junit4]   2> 17801 T1036 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 17801 T1036 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/jetty4/index
[junit4:junit4]   2> 17804 T1036 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@686b51d lockFactory=org.apache.lucene.store.NativeFSLockFactory@2b744374),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 17804 T1036 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 17807 T1036 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 17807 T1036 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 17808 T1036 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 17809 T1036 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 17810 T1036 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 17810 T1036 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 17810 T1036 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 17811 T1036 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 17812 T1036 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 17816 T1036 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 17819 T1036 oass.SolrIndexSearcher.<init> Opening Searcher@4ebc482 main
[junit4:junit4]   2> 17819 T1036 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/jetty4/tlog
[junit4:junit4]   2> 17820 T1036 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 17820 T1036 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 17825 T1037 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4ebc482 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 17828 T1036 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 17828 T1036 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 18511 T967 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 18512 T967 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core_node_name":"5",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:56280_",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:56280"}
[junit4:junit4]   2> 18512 T967 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4]   2> 18513 T967 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 18519 T1002 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 18519 T986 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 18519 T1035 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 18519 T966 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 18519 T1018 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 18519 T973 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 18830 T1036 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 18831 T1036 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:56280 collection:collection1 shard:shard1
[junit4:junit4]   2> 18837 T1036 oasc.ZkController.register We are http://127.0.0.1:56280/collection1/ and leader is http://127.0.0.1:39811/collection1/
[junit4:junit4]   2> 18837 T1036 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:56280
[junit4:junit4]   2> 18837 T1036 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 18837 T1036 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C90 name=collection1 org.apache.solr.core.SolrCore@16bc88d8 url=http://127.0.0.1:56280/collection1 node=127.0.0.1:56280_ C90_STATE=coll:collection1 core:collection1 props:{core=collection1, collection=collection1, node_name=127.0.0.1:56280_, state=down, base_url=http://127.0.0.1:56280}
[junit4:junit4]   2> 18838 T1038 C90 P56280 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 18839 T1038 C90 P56280 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 18839 T1038 C90 P56280 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 18839 T1036 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 18839 T1038 C90 P56280 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 18842 T1038 C90 P56280 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 18841 T944 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 18842 T944 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 18843 T944 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 18848 T944 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 18850 T944 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 18859 T979 oasc.CoreContainer.create Creating SolrCore 'onenodecollectioncore' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1364020438239/onenodecollectioncore
[junit4:junit4]   2> 18860 T979 oasc.ZkController.createCollectionZkNode Check for collection zkNode:onenodecollection
[junit4:junit4]   2> 18861 T979 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:onenodecollection
[junit4:junit4]   2> 18861 T979 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4]   2> 18863 T979 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4]   2> 18863 T979 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection
[junit4:junit4]   2> 18865 T979 oasc.ZkController.readConfigName Load collection config from:/collections/onenodecollection
[junit4:junit4]   2> 18867 T979 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1364020438239/onenodecollectioncore/'
[junit4:junit4]   2> 18890 T979 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 18934 T979 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 18936 T979 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 18942 T979 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2>  C89_STATE=coll:collection1 core:collection1 props:{core=collection1, collection=collection1, shard=shard2, node_name=127.0.0.1:54300_, state=recovering, base_url=http://127.0.0.1:54300}
[junit4:junit4]   2> 19149 T1021 C89 P54300 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:58137/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 19149 T1021 C89 P54300 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:54300 START replicas=[http://127.0.0.1:58137/collection1/] nUpdates=100
[junit4:junit4]   2> 19150 T1021 C89 P54300 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 19151 T1021 C89 P54300 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 19151 T1021 C89 P54300 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 19151 T1021 C89 P54300 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 19151 T1021 C89 P54300 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 19151 T1021 C89 P54300 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:58137/collection1/. core=collection1
[junit4:junit4]   2> 19152 T1021 C89 P54300 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C91 name=collection1 org.apache.solr.core.SolrCore@2b3fd0d0 url=http://127.0.0.1:58137/collection1 node=127.0.0.1:58137_ C91_STATE=coll:collection1 core:collection1 props:{core=collection1, collection=collection1, shard=shard2, node_name=127.0.0.1:58137_, state=active, base_url=http://127.0.0.1:58137, leader=true}
[junit4:junit4]   2> 19154 T980 C91 P58137 REQ /get {wt=javabin&getVersions=100&qt=/get&distrib=false&version=2} status=0 QTime=0 
[junit4:junit4]   2> 19155 T981 C91 P58137 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 19157 T981 C91 P58137 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@58aa816d lockFactory=org.apache.lucene.store.NativeFSLockFactory@3a6629ca),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 19158 T981 C91 P58137 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 19159 T981 C91 P58137 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@58aa816d lockFactory=org.apache.lucene.store.NativeFSLockFactory@3a6629ca),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@58aa816d lockFactory=org.apache.lucene.store.NativeFSLockFactory@3a6629ca),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 19159 T981 C91 P58137 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 19159 T981 C91 P58137 oass.SolrIndexSearcher.<init> Opening Searcher@3e3cacdd realtime
[junit4:junit4]   2> 19160 T981 C91 P58137 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 19160 T981 C91 P58137 /update {wt=javabin&softCommit=false&waitSearcher=true&commit_end_point=true&version=2&openSearcher=false&commit=true} {commit=} 0 5
[junit4:junit4]   2> 19161 T1021 C89 P54300 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 19161 T1021 C89 P54300 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 19168 T980 C91 P58137 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 19168 T980 C91 P58137 REQ /replication {wt=javabin&command=indexversion&qt=/replication&version=2} status=0 QTime=6 
[junit4:junit4]   2> 19169 T1021 C89 P54300 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4]   2> 19169 T1021 C89 P54300 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 19169 T1021 C89 P54300 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 19171 T982 C91 P58137 REQ /replication {wt=javabin&command=filelist&qt=/replication&generation=2&version=2} status=0 QTime=0 
[junit4:junit4]   2> 19171 T1021 C89 P54300 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4]   2> 19173 T1021 C89 P54300 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/jetty3/index.20130323193414022
[junit4:junit4]   2> 19173 T1021 C89 P54300 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@74593b1d lockFactory=org.apache.lucene.store.NativeFSLockFactory@1980174d; maxCacheMB=0.267578125 maxMergeSizeMB=0.271484375)) fullCopy=false
[junit4:junit4]   2> 19175 T981 C91 P58137 REQ /replication {wt=filestream&command=filecontent&qt=/replication&generation=2&checksum=true&file=segments_2} status=0 QTime=0 
[junit4:junit4]   2> 19176 T1021 C89 P54300 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 19177 T1021 C89 P54300 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 19178 T1021 C89 P54300 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 19178 T1021 C89 P54300 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5594612a lockFactory=org.apache.lucene.store.NativeFSLockFactory@22cf3f4f),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5594612a lockFactory=org.apache.lucene.store.NativeFSLockFactory@22cf3f4f),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 19179 T1021 C89 P54300 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 19179 T1021 C89 P54300 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 19179 T1021 C89 P54300 oass.SolrIndexSearcher.<init> Opening Searcher@669540ec main
[junit4:junit4]   2> 19180 T1020 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@669540ec main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4]   2> 19181 T1021 C89 P54300 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 19181 T1021 C89 P54300 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 19181 T1021 C89 P54300 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 19181 T1021 C89 P54300 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 19182 T1021 C89 P54300 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 19274 T979 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 19279 T979 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 19281 T979 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 19301 T979 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 19305 T979 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 19311 T979 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 19313 T979 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 19313 T979 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 19314 T979 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 19316 T979 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 19317 T979 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 19317 T979 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 19318 T979 oasc.SolrCore.<init> [onenodecollectioncore] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1364020438239/onenodecollectioncore/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1364020434854/onenodecollection/
[junit4:junit4]   2> 19318 T979 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3447d61
[junit4:junit4]   2> 19319 T979 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 19320 T979 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1364020434854/onenodecollection
[junit4:junit4]   2> 19321 T979 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1364020434854/onenodecollection/index/
[junit4:junit4]   2> 19321 T979 oasc.SolrCore.initIndex WARNING [onenodecollectioncore] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1364020434854/onenodecollection/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 19322 T979 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1364020434854/onenodecollection/index
[junit4:junit4]   2> 19324 T979 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@68c5d51 lockFactory=org.apache.lucene.store.NativeFSLockFactory@253a1fd3),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 19325 T979 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 19328 T979 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 19328 T979 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 19329 T979 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 19330 T979 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 19331 T979 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 19331 T979 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 19332 T979 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 19333 T979 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 19333 T979 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 19337 T979 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 19354 T979 oass.SolrIndexSearcher.<init> Opening Searcher@6563f341 main
[junit4:junit4]   2> 19354 T979 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1364020434854/onenodecollection/tlog
[junit4:junit4]   2> 19355 T979 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 19355 T979 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 19360 T1042 oasc.SolrCore.registerSearcher [onenodecollectioncore] Registered new searcher Searcher@6563f341 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 19361 T979 oasc.ZkController.publish publishing core=onenodecollectioncore state=down
[junit4:junit4]   2> 20029 T967 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 20030 T967 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core_node_name":"5",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:56280_",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"recovering",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:56280"}
[junit4:junit4]   2> 20037 T967 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core_node_name":"4",
[junit4:junit4]   2> 	  "shard":"shard2",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:54300_",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:54300"}
[junit4:junit4]   2> 20043 T967 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "core":"onenodecollectioncore",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "collection":"onenodecollection",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:58137_",
[junit4:junit4]   2> 	  "roles":"none",
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:58137"}
[junit4:junit4]   2> 20043 T967 oasc.Overseer$ClusterStateUpdater.createCollection Create collection onenodecollection with numShards 1
[junit4:junit4]   2> 20043 T967 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 20049 T1035 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 20050 T986 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 20050 T1002 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 20050 T966 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 20050 T973 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 20050 T1018 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 20366 T979 oasc.CoreContainer.registerCore registering core: onenodecollectioncore
[junit4:junit4]   2> 20366 T979 oasc.ZkController.register Register replica - core:onenodecollectioncore address:http://127.0.0.1:58137 collection:onenodecollection shard:shard1
[junit4:junit4]   2> 20368 T979 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leader_elect/shard1/election
[junit4:junit4]   2> 20382 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a90006 type:delete cxid:0xac zxid:0xc2 txntype:-1 reqpath:n/a Error Path:/solr/collections/onenodecollection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/onenodecollection/leaders
[junit4:junit4]   2> 20383 T979 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 20384 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a90006 type:create cxid:0xad zxid:0xc3 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 20388 T979 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 20389 T979 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 20389 T979 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:58137/onenodecollectioncore/
[junit4:junit4]   2> 20390 T979 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 20390 T979 oasc.SyncStrategy.syncToMe http://127.0.0.1:58137/onenodecollectioncore/ has no replicas
[junit4:junit4]   2> 20390 T979 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:58137/onenodecollectioncore/
[junit4:junit4]   2> 20391 T979 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leaders/shard1
[junit4:junit4]   2> 20399 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a90006 type:create cxid:0xb8 zxid:0xc7 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 20849 T997 oass.SolrDispatchFilter.handleAdminRequest /admin/cores {wt=javabin&coreNodeName=5&core=collection1&nodeName=127.0.0.1:56280_&action=PREPRECOVERY&version=2&checkLive=true&state=recovering&onlyIfLeader=true} status=0 QTime=2001 
[junit4:junit4]   2> 21563 T967 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 21580 T973 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 21580 T966 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 21580 T1018 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 21580 T1002 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 21580 T986 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 21581 T1035 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 21608 T979 oasc.ZkController.register We are http://127.0.0.1:58137/onenodecollectioncore/ and leader is http://127.0.0.1:58137/onenodecollectioncore/
[junit4:junit4]   2> 21609 T979 oasc.ZkController.register No LogReplay needed for core=onenodecollectioncore baseURL=http://127.0.0.1:58137
[junit4:junit4]   2> 21609 T979 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 21610 T979 oasc.ZkController.publish publishing core=onenodecollectioncore state=active
[junit4:junit4]   2> 21612 T979 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 21614 T979 oass.SolrDispatchFilter.handleAdminRequest /admin/cores {wt=javabin&collection=onenodecollection&dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1364020434854/onenodecollection&action=CREATE&version=2&numShards=1&roles=none&name=onenodecollectioncore} status=0 QTime=2755 
[junit4:junit4]   2> 21615 T944 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: onenodecollection failOnTimeout:true timeout (sec):230
[junit4:junit4]   2> 21616 T944 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 22619 T944 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2>  C90_STATE=coll:collection1 core:collection1 props:{core=collection1, collection=collection1, shard=shard1, node_name=127.0.0.1:56280_, state=recovering, base_url=http://127.0.0.1:56280}
[junit4:junit4]   2> 22850 T1038 C90 P56280 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:39811/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 22850 T1038 C90 P56280 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:56280 START replicas=[http://127.0.0.1:39811/collection1/] nUpdates=100
[junit4:junit4]   2> 22851 T1038 C90 P56280 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 22851 T1038 C90 P56280 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 22851 T1038 C90 P56280 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 22852 T1038 C90 P56280 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 22852 T1038 C90 P56280 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 22852 T1038 C90 P56280 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:39811/collection1/. core=collection1
[junit4:junit4]   2> 22852 T1038 C90 P56280 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C92 name=collection1 org.apache.solr.core.SolrCore@5a058ac6 url=http://127.0.0.1:39811/collection1 node=127.0.0.1:39811_ C92_STATE=coll:collection1 core:collection1 props:{core=collection1, collection=collection1, shard=shard1, node_name=127.0.0.1:39811_, state=active, base_url=http://127.0.0.1:39811, leader=true}
[junit4:junit4]   2> 22857 T997 C92 P39811 REQ /get {wt=javabin&getVersions=100&qt=/get&distrib=false&version=2} status=0 QTime=0 
[junit4:junit4]   2> 22858 T995 C92 P39811 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 22861 T995 C92 P39811 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@753b9796 lockFactory=org.apache.lucene.store.NativeFSLockFactory@24fef8d2),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 22862 T995 C92 P39811 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 22863 T995 C92 P39811 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@753b9796 lockFactory=org.apache.lucene.store.NativeFSLockFactory@24fef8d2),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@753b9796 lockFactory=org.apache.lucene.store.NativeFSLockFactory@24fef8d2),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 22864 T995 C92 P39811 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 22864 T995 C92 P39811 oass.SolrIndexSearcher.<init> Opening Searcher@64ba9e07 realtime
[junit4:junit4]   2> 22865 T995 C92 P39811 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 22865 T995 C92 P39811 /update {wt=javabin&softCommit=false&waitSearcher=true&commit_end_point=true&version=2&openSearcher=false&commit=true} {commit=} 0 7
[junit4:junit4]   2> 22866 T1038 C90 P56280 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 22866 T1038 C90 P56280 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 22868 T998 C92 P39811 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 22868 T998 C92 P39811 REQ /replication {wt=javabin&command=indexversion&qt=/replication&version=2} status=0 QTime=1 
[junit4:junit4]   2> 22869 T1038 C90 P56280 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4]   2> 22869 T1038 C90 P56280 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 22869 T1038 C90 P56280 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 22871 T997 C92 P39811 REQ /replication {wt=javabin&command=filelist&qt=/replication&generation=2&version=2} status=0 QTime=1 
[junit4:junit4]   2> 22871 T1038 C90 P56280 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4]   2> 22872 T1038 C90 P56280 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/jetty4/index.20130323193417721
[junit4:junit4]   2> 22872 T1038 C90 P56280 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@189a3ca7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1fb172dc; maxCacheMB=0.267578125 maxMergeSizeMB=0.271484375)) fullCopy=false
[junit4:junit4]   2> 22875 T995 C92 P39811 REQ /replication {wt=filestream&command=filecontent&qt=/replication&generation=2&checksum=true&file=segments_2} status=0 QTime=1 
[junit4:junit4]   2> 22876 T1038 C90 P56280 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 22877 T1038 C90 P56280 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 22877 T1038 C90 P56280 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 22879 T1038 C90 P56280 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@686b51d lockFactory=org.apache.lucene.store.NativeFSLockFactory@2b744374),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@686b51d lockFactory=org.apache.lucene.store.NativeFSLockFactory@2b744374),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 22879 T1038 C90 P56280 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 22879 T1038 C90 P56280 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 22880 T1038 C90 P56280 oass.SolrIndexSearcher.<init> Opening Searcher@22f17d70 main
[junit4:junit4]   2> 22881 T1037 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@22f17d70 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4]   2> 22882 T1038 C90 P56280 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 22882 T1038 C90 P56280 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 22882 T1038 C90 P56280 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 22883 T1038 C90 P56280 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 22884 T1038 C90 P56280 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 23092 T967 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 23094 T967 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "core":"onenodecollectioncore",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "collection":"onenodecollection",
[junit4:junit4]   2> 	  "core_node_name":"127.0.0.1:58137__onenodecollectioncore",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:58137_",
[junit4:junit4]   2> 	  "roles":"none",
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:58137"}
[junit4:junit4]   2> 23101 T967 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core_node_name":"5",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:56280_",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:56280"}
[junit4:junit4]   2> 23109 T973 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 23109 T1018 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 23109 T1035 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 23109 T986 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 23109 T1002 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 23109 T966 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 23622 T944 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 23624 T944 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: onenodecollection
[junit4:junit4]   2> 23625 T944 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 23640 T944 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:58621 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@75bcdde7
[junit4:junit4]   2> 23642 T1045 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:58621. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 23642 T944 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 23642 T1045 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:58621, initiating session
[junit4:junit4]   2> 23643 T946 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:46331
[junit4:junit4]   2> 23643 T946 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:46331
[junit4:junit4]   2> 23644 T948 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d95f417a9000d with negotiated timeout 10000 for client /127.0.0.1:46331
[junit4:junit4]   2> 23644 T1045 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:58621, sessionid = 0x13d95f417a9000d, negotiated timeout = 10000
[junit4:junit4]   2> 23645 T1046 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@75bcdde7 name:ZooKeeperConnection Watcher:127.0.0.1:58621 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 23645 T944 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 23744 T949 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d95f417a9000d
[junit4:junit4]   2> 23745 T1046 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 23745 T946 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:46331 which had sessionid 0x13d95f417a9000d
[junit4:junit4]   2> 23745 T944 oaz.ZooKeeper.close Session: 0x13d95f417a9000d closed
[junit4:junit4]   2> 23747 T949 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d95f417a90004
[junit4:junit4]   2> 23747 T973 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 23748 T946 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:46281 which had sessionid 0x13d95f417a90004
[junit4:junit4]   2> 23747 T944 oaz.ZooKeeper.close Session: 0x13d95f417a90004 closed
[junit4:junit4]   2> 23751 T944 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 49239
[junit4:junit4]   2> 23752 T944 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=7976772
[junit4:junit4]   2> 24620 T967 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 24621 T967 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "collection":"control_collection",
[junit4:junit4]   2> 	  "core_node_name":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:49239_",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:49239"}
[junit4:junit4]   2> 24629 T1002 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 24629 T1035 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 24629 T1018 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 24629 T986 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 24630 T966 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 25754 T944 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 25755 T944 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 25759 T944 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@7f0eb31e
[junit4:junit4]   2> 25765 T944 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4]   2> 25765 T944 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 25766 T944 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 25766 T944 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 25767 T944 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 25768 T944 oasc.CachingDirectoryFactory.close Closing directory when closing factory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/control/data
[junit4:junit4]   2> 25768 T944 oasc.CachingDirectoryFactory.closeDirectory Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/control/data
[junit4:junit4]   2> 25769 T944 oasc.CachingDirectoryFactory.close Closing directory when closing factory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/control/data/index
[junit4:junit4]   2> 25769 T944 oasc.CachingDirectoryFactory.closeDirectory Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/control/data/index
[junit4:junit4]   2> 25771 T967 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89392443218788355-127.0.0.1:49239_-n_0000000000) am no longer a leader.
[junit4:junit4]   2> 25772 T949 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d95f417a90003
[junit4:junit4]   2> 25774 T1002 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 25774 T966 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 25775 T966 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 25775 T946 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:46275 which had sessionid 0x13d95f417a90003
[junit4:junit4]   2> 25775 T1018 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 25775 T966 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 25774 T944 oaz.ZooKeeper.close Session: 0x13d95f417a90003 closed
[junit4:junit4]   2> 25775 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a90006 type:delete cxid:0xc6 zxid:0xe3 txntype:-1 reqpath:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for /solr/overseer_elect/leader
[junit4:junit4]   2> 25775 T1018 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 25776 T966 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 25777 T1035 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 25777 T986 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 25778 T1035 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 25779 T1002 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 25781 T986 oasc.Overseer.start Overseer (id=89392443218788358-127.0.0.1:58137_-n_0000000001) starting
[junit4:junit4]   2> 25782 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a90006 type:create cxid:0xcb zxid:0xe5 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 25784 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a90006 type:create cxid:0xcc zxid:0xe6 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 25786 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a90006 type:create cxid:0xce zxid:0xe7 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 25788 T949 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d95f417a90006 type:create cxid:0xd0 zxid:0xe8 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 25791 T986 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 25791 T1048 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 25794 T986 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 25795 T1047 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 25797 T944 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4]   2> 25799 T1047 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 25800 T1047 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "collection":"control_collection",
[junit4:junit4]   2> 	  "core_node_name":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:49239_",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:49239"}
[junit4:junit4]   2> 25808 T986 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 25808 T1002 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 25808 T1018 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 25808 T1035 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 25849 T944 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 58137
[junit4:junit4]   2> 25849 T944 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1697825671
[junit4:junit4]   2> 27317 T1047 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 27319 T1047 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4]   2> 	  "core":"onenodecollectioncore",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "collection":"onenodecollection",
[junit4:junit4]   2> 	  "core_node_name":"127.0.0.1:58137__onenodecollectioncore",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:58137_",
[junit4:junit4]   2> 	  "roles":"none",
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:58137"}
[junit4:junit4]   2> 27325 T1047 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core_node_name":"2",
[junit4:junit4]   2> 	  "shard":"shard2",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:58137_",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:58137"}
[junit4:junit4]   2> 27332 T1035 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 27332 T1018 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 27332 T1002 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 27333 T986 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 28854 T944 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 28855 T944 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 28858 T944 oasc.ZkController.publish publishing core=onenodecollectioncore state=down
[junit4:junit4]   2> 28862 T944 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@2b3fd0d0
[junit4:junit4]   2> 28867 T944 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4]   2> 28868 T944 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 28868 T944 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 28869 T944 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 28872 T944 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 28873 T944 oasc.CachingDirectoryFactory.close Closing directory when closing factory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/jetty1/index
[junit4:junit4]   2> 28874 T944 oasc.CachingDirectoryFactory.closeDirectory Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/jetty1/index
[junit4:junit4]   2> 28874 T944 oasc.CachingDirectoryFactory.close Closing directory when closing factory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/jetty1
[junit4:junit4]   2> 28874 T944 oasc.CachingDirectoryFactory.closeDirectory Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1364020434854/jetty1
[junit4:junit4]   2> 28875 T944 oasc.SolrCore.close [onenodecollectioncore]  CLOSING SolrCore org.apache.solr.core.SolrCore@30594c5f
[junit4:junit4]   2> 28883 T944 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4]   2> 28883 T944 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 28884 T944 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 28884 T944 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 28885 T944 oasc.SolrCore.closeSearcher [onenodecollectioncore] Closing main searcher on request.
[junit4:junit4]   2> 28886 T944 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1364020434854/onenodecollection/index
[junit4:junit4]   2> 28887 T944 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1364020434854/onenodecollection/index
[junit4:junit4]   2> 28887 T944 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1364020434854/onenodecollection
[junit4:junit4]   2> 28888 T944 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1364020434854/onenodecollection
[junit4:junit4]   2> 28889 T1047 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89392443218788358-127.0.0.1:58137_-n_0000000001) am no longer a leader.
[junit4:junit4]   2> 28890 T949 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d95f417a90006
[junit4:junit4]   2> 28892 T1035 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 28893 T1018 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_no

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

  1>     /solr/overseer_elect/election/89392446339481612-127.0.0.1:49195_nxifn-n_0000000004 (0)
[junit4:junit4]   1>     /solr/overseer_elect/election/89392446339481606-127.0.0.1:53712_nxifn-n_0000000001 (0)
[junit4:junit4]   1>     /solr/overseer_elect/election/89392446339481603-127.0.0.1:59189_nxifn-n_0000000000 (0)
[junit4:junit4]   1>     /solr/overseer_elect/election/89392446339481610-127.0.0.1:50255_nxifn-n_0000000003 (0)
[junit4:junit4]   1>     /solr/overseer_elect/election/89392446339481608-127.0.0.1:48739_nxifn-n_0000000002 (0)
[junit4:junit4]   1>    /solr/overseer_elect/leader (0)
[junit4:junit4]   1>    DATA:
[junit4:junit4]   1>        {"id":"89392446339481603-127.0.0.1:59189_nxifn-n_0000000000"}
[junit4:junit4]   1> 
[junit4:junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=UnloadDistributedZkTest -Dtests.method=testDistribSearch -Dtests.seed=B6D7B904D28757ED -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ro_RO -Dtests.timezone=America/Argentina/Mendoza -Dtests.file.encoding=UTF-8
[junit4:junit4] FAILURE  137s J0 | UnloadDistributedZkTest.testDistribSearch <<<
[junit4:junit4]    > Throwable #1: java.lang.AssertionError: Still found shard2 in collection test_unload_shard_and_collection
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([B6D7B904D28757ED:3731371CA5D837D1]:0)
[junit4:junit4]    > 	at org.junit.Assert.fail(Assert.java:93)
[junit4:junit4]    > 	at org.apache.solr.cloud.UnloadDistributedZkTest.testUnloadShardAndCollection(UnloadDistributedZkTest.java:127)
[junit4:junit4]    > 	at org.apache.solr.cloud.UnloadDistributedZkTest.doTest(UnloadDistributedZkTest.java:77)
[junit4:junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:806)
[junit4:junit4]    > 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4:junit4]    > 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
[junit4:junit4]    > 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4:junit4]    > 	at java.lang.reflect.Method.invoke(Method.java:487)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
[junit4:junit4]    > 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4]    > 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4]    > 	at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   2> 137144 T2360 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4]   2> 137152 T2359 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
[junit4:junit4]   2> 137548 T2363 oazs.SessionTrackerImpl.run SessionTrackerImpl exited loop!
[junit4:junit4]   2> NOTE: test params are: codec=Asserting, sim=DefaultSimilarity, locale=ro_RO, timezone=America/Argentina/Mendoza
[junit4:junit4]   2> NOTE: Linux 3.2.0-39-generic amd64/Oracle Corporation 1.8.0-ea (64-bit)/cpus=8,threads=1,free=58885392,total=174718976
[junit4:junit4]   2> NOTE: All tests run in this JVM: [SearchHandlerTest, DirectUpdateHandlerOptimizeTest, TestSolrDeletionPolicy1, ZkControllerTest, BinaryUpdateRequestHandlerTest, TestRealTimeGet, SOLR749Test, TestRemoteStreaming, DirectSolrConnectionTest, TestFieldTypeCollectionResource, DocValuesTest, TestSearchPerf, BasicFunctionalityTest, QueryParsingTest, TestQuerySenderListener, QueryElevationComponentTest, TestFuzzyAnalyzedSuggestions, SolrIndexSplitterTest, SolrCoreTest, AliasIntegrationTest, SystemInfoHandlerTest, SynonymTokenizerTest, CoreAdminHandlerTest, TestSort, TestSweetSpotSimilarityFactory, LukeRequestHandlerTest, ClusterStateUpdateTest, TestReplicationHandler, TermVectorComponentTest, PolyFieldTest, ResponseLogComponentTest, SchemaVersionSpecificBehaviorTest, SpatialFilterTest, CacheHeaderTest, TestConfig, TestQueryUtils, CircularListTest, TestValueSourceCache, TestStressRecovery, PrimitiveFieldTypeTest, DistributedSpellCheckComponentTest, DistributedTermsComponentTest, OverseerTest, TermsComponentTest, TestSolrDeletionPolicy2, TestFaceting, TestCharFilters, TestDocSet, BadComponentTest, TestLRUCache, MoreLikeThisHandlerTest, TestPseudoReturnFields, TestXIncludeConfig, PluginInfoTest, TestPHPSerializedResponseWriter, FieldMutatingUpdateProcessorTest, TestPhraseSuggestions, TestPropInjectDefaults, PreAnalyzedFieldTest, TestSolrIndexConfig, DateFieldTest, LegacyHTMLStripCharFilterTest, MBeansHandlerTest, TestFastLRUCache, SolrInfoMBeanTest, TestReversedWildcardFilterFactory, TestBadConfig, BasicDistributedZkTest, UnloadDistributedZkTest]
[junit4:junit4] Completed on J0 in 137.69s, 1 test, 1 failure <<< FAILURES!

[...truncated 423 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:375: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:355: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:183: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:449: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1209: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:873: There were test failures: 272 suites, 1146 tests, 1 error, 1 failure, 13 ignored (7 assumptions)

Total time: 41 minutes 37 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Description set: Java: 64bit/jdk1.8.0-ea-b82 -XX:+UseSerialGC
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message