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 (32bit/jdk1.8.0-ea-b79) - Build # 4815 - Still Failing!
Date Thu, 21 Mar 2013 23:38:43 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/4815/
Java: 32bit/jdk1.8.0-ea-b79 -server -XX:+UseSerialGC

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

Error Message:
Server at http://127.0.0.1:47128/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:47128/onenodecollectioncore returned non ok status:404, message:Can not find: /onenodecollectioncore/update
	at __randomizedtesting.SeedInfo.seed([BD18299FF51C3446:3CFEA7878243547A]: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:196)
	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([BD18299FF51C3446:3CFEA7878243547A]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.cloud.UnloadDistributedZkTest.testUnloadShardAndCollection(UnloadDistributedZkTest.java:124)
	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 9260 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4:junit4]   2> 0 T1738 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4]   2> 3 T1738 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-1363908457676
[junit4:junit4]   2> 4 T1738 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 4 T1739 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4]   2> 5 T1739 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4]   2> 5 T1739 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4]   2> 5 T1739 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4]   2> 5 T1739 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 6 T1739 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-1363908457675/zookeeper/server1/data/version-2/snapshot.0
[junit4:junit4]   2> 104 T1738 oasc.ZkTestServer.run start zk server on port:41498
[junit4:junit4]   2> 105 T1738 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:41498 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@95b5ce
[junit4:junit4]   2> 105 T1744 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:41498. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 105 T1738 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 106 T1744 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:41498, initiating session
[junit4:junit4]   2> 106 T1740 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:37391
[junit4:junit4]   2> 106 T1740 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:37391
[junit4:junit4]   2> 106 T1742 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 751 T1742 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8f4774ce0000 with negotiated timeout 10000 for client /127.0.0.1:37391
[junit4:junit4]   2> 751 T1744 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:41498, sessionid = 0x13d8f4774ce0000, negotiated timeout = 10000
[junit4:junit4]   2> 752 T1745 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@95b5ce name:ZooKeeperConnection Watcher:127.0.0.1:41498 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 752 T1738 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 752 T1738 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 755 T1743 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d8f4774ce0000
[junit4:junit4]   2> 756 T1745 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 756 T1740 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:37391 which had sessionid 0x13d8f4774ce0000
[junit4:junit4]   2> 756 T1738 oaz.ZooKeeper.close Session: 0x13d8f4774ce0000 closed
[junit4:junit4]   2> 757 T1738 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:41498/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@525cac
[junit4:junit4]   2> 757 T1738 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 758 T1746 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:41498. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 758 T1740 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:37392
[junit4:junit4]   2> 758 T1746 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:41498, initiating session
[junit4:junit4]   2> 759 T1740 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:37392
[junit4:junit4]   2> 759 T1742 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8f4774ce0001 with negotiated timeout 10000 for client /127.0.0.1:37392
[junit4:junit4]   2> 759 T1746 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:41498, sessionid = 0x13d8f4774ce0001, negotiated timeout = 10000
[junit4:junit4]   2> 760 T1747 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@525cac name:ZooKeeperConnection Watcher:127.0.0.1:41498/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 760 T1738 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 760 T1738 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 763 T1738 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 764 T1738 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 766 T1738 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 767 T1738 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> 768 T1738 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 771 T1738 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> 771 T1738 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 774 T1738 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> 774 T1738 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 776 T1738 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> 776 T1738 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 778 T1738 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> 778 T1738 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 780 T1738 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> 780 T1738 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 782 T1738 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> 782 T1738 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 784 T1738 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> 785 T1738 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 786 T1738 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> 787 T1738 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 788 T1743 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d8f4774ce0001
[junit4:junit4]   2> 789 T1747 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 789 T1740 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:37392 which had sessionid 0x13d8f4774ce0001
[junit4:junit4]   2> 789 T1738 oaz.ZooKeeper.close Session: 0x13d8f4774ce0001 closed
[junit4:junit4]   2> 845 T1738 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 852 T1738 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52708
[junit4:junit4]   2> 853 T1738 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 854 T1738 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 854 T1738 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-1363908458462
[junit4:junit4]   2> 854 T1738 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-1363908458462/solr.xml
[junit4:junit4]   2> 855 T1738 oasc.CoreContainer.<init> New CoreContainer 26355114
[junit4:junit4]   2> 855 T1738 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-1363908458462/'
[junit4:junit4]   2> 856 T1738 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-1363908458462/'
[junit4:junit4]   2> 875 T1738 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 875 T1738 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 875 T1738 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 876 T1738 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 876 T1738 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 876 T1738 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 877 T1738 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 877 T1738 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 877 T1738 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 878 T1738 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 883 T1738 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 893 T1738 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:41498/solr
[junit4:junit4]   2> 893 T1738 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 894 T1738 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:41498 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@d153dd
[junit4:junit4]   2> 894 T1738 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 894 T1757 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:41498. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 895 T1757 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:41498, initiating session
[junit4:junit4]   2> 895 T1740 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:37393
[junit4:junit4]   2> 896 T1740 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:37393
[junit4:junit4]   2> 896 T1757 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:41498, sessionid = 0x13d8f4774ce0002, negotiated timeout = 20000
[junit4:junit4]   2> 896 T1742 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8f4774ce0002 with negotiated timeout 20000 for client /127.0.0.1:37393
[junit4:junit4]   2> 897 T1758 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d153dd name:ZooKeeperConnection Watcher:127.0.0.1:41498 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 897 T1738 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 898 T1743 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d8f4774ce0002
[junit4:junit4]   2> 898 T1758 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 898 T1740 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:37393 which had sessionid 0x13d8f4774ce0002
[junit4:junit4]   2> 898 T1738 oaz.ZooKeeper.close Session: 0x13d8f4774ce0002 closed
[junit4:junit4]   2> 899 T1738 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 901 T1738 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:41498/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1841ba5
[junit4:junit4]   2> 902 T1738 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 902 T1759 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:41498. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 903 T1759 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:41498, initiating session
[junit4:junit4]   2> 903 T1740 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:37394
[junit4:junit4]   2> 903 T1740 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:37394
[junit4:junit4]   2> 904 T1742 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8f4774ce0003 with negotiated timeout 20000 for client /127.0.0.1:37394
[junit4:junit4]   2> 904 T1759 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:41498, sessionid = 0x13d8f4774ce0003, negotiated timeout = 20000
[junit4:junit4]   2> 904 T1760 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1841ba5 name:ZooKeeperConnection Watcher:127.0.0.1:41498/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 904 T1738 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 906 T1738 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4]   2> 908 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce0003 type:create cxid:0x7 zxid:0x1b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 908 T1738 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4]   2> 911 T1738 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 912 T1738 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52708_
[junit4:junit4]   2> 913 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce0003 type:delete cxid:0x12 zxid:0x1e txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:52708_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:52708_
[junit4:junit4]   2> 913 T1738 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52708_
[junit4:junit4]   2> 915 T1738 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 919 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce0003 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> 919 T1738 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 921 T1738 oasc.Overseer.start Overseer (id=89385104682385411-127.0.0.1:52708_-n_0000000000) starting
[junit4:junit4]   2> 922 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce0003 type:create cxid:0x25 zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 922 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce0003 type:create cxid:0x26 zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 923 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce0003 type:create cxid:0x28 zxid:0x27 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 924 T1738 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4]   2> 925 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce0003 type:create cxid:0x2e zxid:0x29 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 926 T1762 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 926 T1738 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 928 T1738 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4]   2> 929 T1738 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 930 T1761 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 932 T1763 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-1363908458462/collection1
[junit4:junit4]   2> 932 T1763 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 933 T1763 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 933 T1763 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 934 T1763 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-1363908458462/collection1/'
[junit4:junit4]   2> 934 T1763 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-1363908458462/collection1/lib/README' to classloader
[junit4:junit4]   2> 934 T1763 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-1363908458462/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 972 T1763 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 1000 T1763 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 1001 T1763 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 1004 T1763 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 1334 T1763 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 1340 T1763 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 1342 T1763 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 1351 T1763 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1354 T1763 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1357 T1763 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1358 T1763 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 1358 T1763 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 1358 T1763 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1359 T1763 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 1359 T1763 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 1359 T1763 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 1360 T1763 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-1363908458462/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/control/data/
[junit4:junit4]   2> 1360 T1763 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1a57f3f
[junit4:junit4]   2> 1360 T1763 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 1361 T1763 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/control/data
[junit4:junit4]   2> 1361 T1763 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/control/data/index/
[junit4:junit4]   2> 1361 T1763 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/control/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 1362 T1763 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/control/data/index
[junit4:junit4]   2> 1363 T1763 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@d9f988 lockFactory=org.apache.lucene.store.NativeFSLockFactory@23e3b2),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 1364 T1763 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 1366 T1763 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 1366 T1763 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 1367 T1763 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 1368 T1763 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 1368 T1763 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 1368 T1763 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 1369 T1763 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 1369 T1763 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 1369 T1763 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 1373 T1763 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 1375 T1763 oass.SolrIndexSearcher.<init> Opening Searcher@149f188 main
[junit4:junit4]   2> 1375 T1763 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/control/data/tlog
[junit4:junit4]   2> 1376 T1763 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 1376 T1763 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 1379 T1764 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@149f188 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 1379 T1763 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 1379 T1763 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 2433 T1761 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2434 T1761 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "collection":"control_collection",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:52708_",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:52708",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"1",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "state":"down"}
[junit4:junit4]   2> 2434 T1761 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4]   2> 2434 T1761 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 2437 T1760 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> 3380 T1763 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 3381 T1763 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52708 collection:control_collection shard:shard1
[junit4:junit4]   2> 3381 T1763 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4]   2> 3387 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce0003 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> 3387 T1763 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 3387 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce0003 type:create cxid:0x83 zxid:0x36 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3389 T1763 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 3389 T1763 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 3389 T1763 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52708/collection1/
[junit4:junit4]   2> 3389 T1763 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 3390 T1763 oasc.SyncStrategy.syncToMe http://127.0.0.1:52708/collection1/ has no replicas
[junit4:junit4]   2> 3390 T1763 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52708/collection1/
[junit4:junit4]   2> 3390 T1763 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4]   2> 3392 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce0003 type:create cxid:0x8e zxid:0x3a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3940 T1761 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3947 T1760 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> 3995 T1763 oasc.ZkController.register We are http://127.0.0.1:52708/collection1/ and leader is http://127.0.0.1:52708/collection1/
[junit4:junit4]   2> 3995 T1763 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52708
[junit4:junit4]   2> 3995 T1763 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 3995 T1763 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 3995 T1763 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 3997 T1763 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3997 T1738 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 3998 T1738 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 3998 T1738 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 4001 T1738 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 4001 T1738 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:41498/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@16d5c7b
[junit4:junit4]   2> 4002 T1738 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 4002 T1766 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:41498. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 4003 T1766 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:41498, initiating session
[junit4:junit4]   2> 4003 T1740 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:37397
[junit4:junit4]   2> 4003 T1740 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:37397
[junit4:junit4]   2> 4004 T1742 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8f4774ce0004 with negotiated timeout 10000 for client /127.0.0.1:37397
[junit4:junit4]   2> 4004 T1766 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:41498, sessionid = 0x13d8f4774ce0004, negotiated timeout = 10000
[junit4:junit4]   2> 4004 T1767 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@16d5c7b name:ZooKeeperConnection Watcher:127.0.0.1:41498/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 4004 T1738 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 4006 T1738 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 4007 T1738 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   2> 4070 T1738 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 4073 T1738 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:54134
[junit4:junit4]   2> 4074 T1738 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 4074 T1738 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 4075 T1738 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-1363908461679
[junit4:junit4]   2> 4075 T1738 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-1363908461679/solr.xml
[junit4:junit4]   2> 4076 T1738 oasc.CoreContainer.<init> New CoreContainer 28625978
[junit4:junit4]   2> 4076 T1738 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-1363908461679/'
[junit4:junit4]   2> 4076 T1738 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-1363908461679/'
[junit4:junit4]   2> 4110 T1738 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 4110 T1738 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 4111 T1738 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 4111 T1738 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 4111 T1738 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 4112 T1738 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 4112 T1738 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 4112 T1738 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 4113 T1738 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 4113 T1738 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 4118 T1738 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 4128 T1738 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:41498/solr
[junit4:junit4]   2> 4128 T1738 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 4128 T1738 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:41498 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@15fae58
[junit4:junit4]   2> 4129 T1777 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:41498. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 4129 T1738 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 4130 T1777 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:41498, initiating session
[junit4:junit4]   2> 4130 T1740 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:37398
[junit4:junit4]   2> 4130 T1740 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:37398
[junit4:junit4]   2> 4131 T1742 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8f4774ce0005 with negotiated timeout 20000 for client /127.0.0.1:37398
[junit4:junit4]   2> 4131 T1777 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:41498, sessionid = 0x13d8f4774ce0005, negotiated timeout = 20000
[junit4:junit4]   2> 4131 T1778 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15fae58 name:ZooKeeperConnection Watcher:127.0.0.1:41498 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 4131 T1738 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 4132 T1743 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d8f4774ce0005
[junit4:junit4]   2> 4133 T1778 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 4133 T1740 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:37398 which had sessionid 0x13d8f4774ce0005
[junit4:junit4]   2> 4133 T1738 oaz.ZooKeeper.close Session: 0x13d8f4774ce0005 closed
[junit4:junit4]   2> 4134 T1738 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 4137 T1738 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:41498/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@6b2057
[junit4:junit4]   2> 4138 T1779 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:41498. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 4138 T1738 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 4138 T1779 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:41498, initiating session
[junit4:junit4]   2> 4138 T1740 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:37399
[junit4:junit4]   2> 4138 T1740 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:37399
[junit4:junit4]   2> 4139 T1742 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8f4774ce0006 with negotiated timeout 20000 for client /127.0.0.1:37399
[junit4:junit4]   2> 4139 T1779 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:41498, sessionid = 0x13d8f4774ce0006, negotiated timeout = 20000
[junit4:junit4]   2> 4139 T1780 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6b2057 name:ZooKeeperConnection Watcher:127.0.0.1:41498/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 4139 T1738 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 4140 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce0006 type:create cxid:0x1 zxid:0x48 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4141 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce0006 type:create cxid:0x3 zxid:0x49 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4142 T1738 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 5144 T1738 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54134_
[junit4:junit4]   2> 5145 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce0006 type:delete cxid:0xd zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:54134_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:54134_
[junit4:junit4]   2> 5145 T1738 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54134_
[junit4:junit4]   2> 5148 T1767 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 5148 T1760 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 5148 T1780 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 5148 T1760 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> 5152 T1781 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-1363908461679/collection1
[junit4:junit4]   2> 5152 T1781 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 5153 T1781 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 5153 T1781 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 5154 T1781 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-1363908461679/collection1/'
[junit4:junit4]   2> 5154 T1781 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-1363908461679/collection1/lib/README' to classloader
[junit4:junit4]   2> 5154 T1781 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-1363908461679/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 5178 T1781 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 5209 T1781 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 5209 T1781 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 5213 T1781 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 5452 T1761 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 5452 T1761 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "collection":"control_collection",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:52708_",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:52708",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "state":"active"}
[junit4:junit4]   2> 5455 T1780 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> 5455 T1760 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> 5455 T1767 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> 5546 T1781 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 5565 T1781 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 5568 T1781 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 5577 T1781 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 5580 T1781 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 5583 T1781 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 5583 T1781 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 5584 T1781 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 5584 T1781 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 5585 T1781 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 5585 T1781 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 5585 T1781 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 5585 T1781 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-1363908461679/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/jetty1/
[junit4:junit4]   2> 5585 T1781 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1a57f3f
[junit4:junit4]   2> 5586 T1781 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 5586 T1781 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/jetty1
[junit4:junit4]   2> 5586 T1781 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/jetty1/index/
[junit4:junit4]   2> 5586 T1781 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 5587 T1781 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/jetty1/index
[junit4:junit4]   2> 5588 T1781 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@f9d08e lockFactory=org.apache.lucene.store.NativeFSLockFactory@114a175),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 5588 T1781 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 5590 T1781 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 5590 T1781 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 5590 T1781 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 5591 T1781 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 5591 T1781 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 5591 T1781 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 5591 T1781 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 5592 T1781 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 5592 T1781 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 5594 T1781 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 5596 T1781 oass.SolrIndexSearcher.<init> Opening Searcher@128b7f7 main
[junit4:junit4]   2> 5596 T1781 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/jetty1/tlog
[junit4:junit4]   2> 5597 T1781 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 5597 T1781 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 5599 T1782 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@128b7f7 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 5601 T1781 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 5601 T1781 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 6958 T1761 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6959 T1761 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:54134_",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:54134",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"2",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "state":"down"}
[junit4:junit4]   2> 6959 T1761 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4]   2> 6959 T1761 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4]   2> 6963 T1780 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> 6963 T1760 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> 6963 T1767 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> 7602 T1781 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 7602 T1781 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:54134 collection:collection1 shard:shard2
[junit4:junit4]   2> 7603 T1781 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4]   2> 7606 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce0006 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> 7607 T1781 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 7607 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce0006 type:create cxid:0x4b zxid:0x5b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7608 T1781 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 7609 T1781 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 7609 T1781 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:54134/collection1/
[junit4:junit4]   2> 7609 T1781 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 7609 T1781 oasc.SyncStrategy.syncToMe http://127.0.0.1:54134/collection1/ has no replicas
[junit4:junit4]   2> 7609 T1781 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:54134/collection1/
[junit4:junit4]   2> 7609 T1781 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4]   2> 7611 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce0006 type:create cxid:0x56 zxid:0x5f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8466 T1761 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8472 T1760 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> 8472 T1767 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> 8472 T1780 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> 8514 T1781 oasc.ZkController.register We are http://127.0.0.1:54134/collection1/ and leader is http://127.0.0.1:54134/collection1/
[junit4:junit4]   2> 8515 T1781 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:54134
[junit4:junit4]   2> 8515 T1781 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 8515 T1781 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 8515 T1781 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 8516 T1781 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8517 T1738 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 8518 T1738 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 8518 T1738 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 8577 T1738 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 8580 T1738 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:47128
[junit4:junit4]   2> 8580 T1738 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 8581 T1738 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 8581 T1738 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-1363908466193
[junit4:junit4]   2> 8581 T1738 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-1363908466193/solr.xml
[junit4:junit4]   2> 8582 T1738 oasc.CoreContainer.<init> New CoreContainer 20594130
[junit4:junit4]   2> 8582 T1738 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-1363908466193/'
[junit4:junit4]   2> 8582 T1738 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-1363908466193/'
[junit4:junit4]   2> 8599 T1738 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 8599 T1738 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 8599 T1738 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 8600 T1738 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 8600 T1738 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 8600 T1738 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 8601 T1738 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 8601 T1738 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 8601 T1738 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 8602 T1738 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 8608 T1738 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 8617 T1738 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:41498/solr
[junit4:junit4]   2> 8618 T1738 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 8618 T1738 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:41498 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@10bb4ca
[junit4:junit4]   2> 8619 T1793 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:41498. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 8619 T1738 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 8620 T1793 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:41498, initiating session
[junit4:junit4]   2> 8620 T1740 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:37400
[junit4:junit4]   2> 8620 T1740 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:37400
[junit4:junit4]   2> 8622 T1742 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8f4774ce0007 with negotiated timeout 20000 for client /127.0.0.1:37400
[junit4:junit4]   2> 8622 T1793 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:41498, sessionid = 0x13d8f4774ce0007, negotiated timeout = 20000
[junit4:junit4]   2> 8622 T1794 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10bb4ca name:ZooKeeperConnection Watcher:127.0.0.1:41498 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 8622 T1738 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 8623 T1743 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d8f4774ce0007
[junit4:junit4]   2> 8623 T1794 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 8623 T1740 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:37400 which had sessionid 0x13d8f4774ce0007
[junit4:junit4]   2> 8623 T1738 oaz.ZooKeeper.close Session: 0x13d8f4774ce0007 closed
[junit4:junit4]   2> 8624 T1738 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 8627 T1738 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:41498/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@b7f377
[junit4:junit4]   2> 8628 T1795 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:41498. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 8628 T1738 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 8629 T1795 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:41498, initiating session
[junit4:junit4]   2> 8629 T1740 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:37401
[junit4:junit4]   2> 8629 T1740 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:37401
[junit4:junit4]   2> 8630 T1742 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8f4774ce0008 with negotiated timeout 20000 for client /127.0.0.1:37401
[junit4:junit4]   2> 8630 T1795 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:41498, sessionid = 0x13d8f4774ce0008, negotiated timeout = 20000
[junit4:junit4]   2> 8630 T1796 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b7f377 name:ZooKeeperConnection Watcher:127.0.0.1:41498/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 8630 T1738 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 8631 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce0008 type:create cxid:0x1 zxid:0x6c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8632 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce0008 type:create cxid:0x3 zxid:0x6d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8633 T1738 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 9635 T1738 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:47128_
[junit4:junit4]   2> 9636 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce0008 type:delete cxid:0xd zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:47128_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:47128_
[junit4:junit4]   2> 9636 T1738 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:47128_
[junit4:junit4]   2> 9638 T1760 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> 9639 T1780 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9639 T1767 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9639 T1767 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> 9639 T1780 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> 9639 T1796 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9640 T1760 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9644 T1797 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-1363908466193/collection1
[junit4:junit4]   2> 9644 T1797 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 9645 T1797 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 9645 T1797 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 9646 T1797 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-1363908466193/collection1/'
[junit4:junit4]   2> 9646 T1797 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-1363908466193/collection1/lib/README' to classloader
[junit4:junit4]   2> 9646 T1797 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-1363908466193/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 9669 T1797 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 9697 T1797 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 9698 T1797 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 9701 T1797 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 9976 T1761 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9976 T1761 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:54134_",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:54134",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"2",
[junit4:junit4]   2> 	  "shard":"shard2",
[junit4:junit4]   2> 	  "state":"active"}
[junit4:junit4]   2> 9979 T1796 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> 9979 T1760 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> 9979 T1767 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> 9979 T1780 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> 10040 T1797 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 10045 T1797 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 10047 T1797 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 10058 T1797 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 10060 T1797 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 10063 T1797 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 10064 T1797 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 10064 T1797 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 10064 T1797 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 10065 T1797 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 10065 T1797 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 10066 T1797 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 10066 T1797 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-1363908466193/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/jetty2/
[junit4:junit4]   2> 10066 T1797 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1a57f3f
[junit4:junit4]   2> 10066 T1797 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 10067 T1797 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/jetty2
[junit4:junit4]   2> 10067 T1797 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/jetty2/index/
[junit4:junit4]   2> 10067 T1797 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 10067 T1797 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/jetty2/index
[junit4:junit4]   2> 10068 T1797 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1b0ce7a lockFactory=org.apache.lucene.store.NativeFSLockFactory@c10913),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 10069 T1797 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 10070 T1797 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 10070 T1797 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 10071 T1797 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 10071 T1797 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 10071 T1797 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 10072 T1797 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 10072 T1797 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 10072 T1797 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 10072 T1797 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 10075 T1797 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 10077 T1797 oass.SolrIndexSearcher.<init> Opening Searcher@146b5fa main
[junit4:junit4]   2> 10077 T1797 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/jetty2/tlog
[junit4:junit4]   2> 10077 T1797 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 10078 T1797 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 10081 T1798 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@146b5fa main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 10082 T1797 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 10082 T1797 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 11483 T1761 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 11484 T1761 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:47128_",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:47128",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"3",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "state":"down"}
[junit4:junit4]   2> 11484 T1761 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4]   2> 11484 T1761 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 11488 T1780 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> 11488 T1796 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> 11488 T1767 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> 11488 T1760 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> 12083 T1797 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 12083 T1797 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:47128 collection:collection1 shard:shard1
[junit4:junit4]   2> 12084 T1797 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 12087 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce0008 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> 12088 T1797 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 12088 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce0008 type:create cxid:0x4a zxid:0x7e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 12089 T1797 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 12089 T1797 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 12090 T1797 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:47128/collection1/
[junit4:junit4]   2> 12090 T1797 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 12090 T1797 oasc.SyncStrategy.syncToMe http://127.0.0.1:47128/collection1/ has no replicas
[junit4:junit4]   2> 12090 T1797 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:47128/collection1/
[junit4:junit4]   2> 12090 T1797 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 12092 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce0008 type:create cxid:0x54 zxid:0x81 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 12991 T1761 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12995 T1767 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> 12995 T1760 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> 12995 T1796 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> 12995 T1780 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> 13045 T1797 oasc.ZkController.register We are http://127.0.0.1:47128/collection1/ and leader is http://127.0.0.1:47128/collection1/
[junit4:junit4]   2> 13046 T1797 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:47128
[junit4:junit4]   2> 13046 T1797 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 13046 T1797 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 13046 T1797 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 13048 T1797 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 13049 T1738 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 13049 T1738 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 13050 T1738 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 13120 T1738 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 13122 T1738 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49786
[junit4:junit4]   2> 13122 T1738 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 13123 T1738 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 13123 T1738 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-1363908470726
[junit4:junit4]   2> 13123 T1738 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-1363908470726/solr.xml
[junit4:junit4]   2> 13124 T1738 oasc.CoreContainer.<init> New CoreContainer 17654
[junit4:junit4]   2> 13124 T1738 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-1363908470726/'
[junit4:junit4]   2> 13125 T1738 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-1363908470726/'
[junit4:junit4]   2> 13142 T1738 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 13143 T1738 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 13143 T1738 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 13144 T1738 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 13144 T1738 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 13144 T1738 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 13145 T1738 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 13145 T1738 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 13145 T1738 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 13146 T1738 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 13152 T1738 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 13161 T1738 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:41498/solr
[junit4:junit4]   2> 13161 T1738 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 13161 T1738 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:41498 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@1f9f96d
[junit4:junit4]   2> 13162 T1738 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 13162 T1809 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:41498. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 13163 T1809 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:41498, initiating session
[junit4:junit4]   2> 13163 T1740 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:37402
[junit4:junit4]   2> 13163 T1740 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:37402
[junit4:junit4]   2> 13164 T1742 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8f4774ce0009 with negotiated timeout 20000 for client /127.0.0.1:37402
[junit4:junit4]   2> 13164 T1809 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:41498, sessionid = 0x13d8f4774ce0009, negotiated timeout = 20000
[junit4:junit4]   2> 13164 T1810 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f9f96d name:ZooKeeperConnection Watcher:127.0.0.1:41498 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 13164 T1738 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 13165 T1743 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d8f4774ce0009
[junit4:junit4]   2> 13166 T1810 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 13166 T1740 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:37402 which had sessionid 0x13d8f4774ce0009
[junit4:junit4]   2> 13166 T1738 oaz.ZooKeeper.close Session: 0x13d8f4774ce0009 closed
[junit4:junit4]   2> 13166 T1738 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 13169 T1738 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:41498/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1c726c5
[junit4:junit4]   2> 13170 T1811 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:41498. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 13169 T1738 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 13170 T1811 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:41498, initiating session
[junit4:junit4]   2> 13170 T1740 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:37403
[junit4:junit4]   2> 13170 T1740 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:37403
[junit4:junit4]   2> 13171 T1742 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8f4774ce000a with negotiated timeout 20000 for client /127.0.0.1:37403
[junit4:junit4]   2> 13171 T1811 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:41498, sessionid = 0x13d8f4774ce000a, negotiated timeout = 20000
[junit4:junit4]   2> 13171 T1812 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c726c5 name:ZooKeeperConnection Watcher:127.0.0.1:41498/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 13171 T1738 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 13172 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce000a type:create cxid:0x1 zxid:0x8e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 13173 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce000a type:create cxid:0x3 zxid:0x8f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 13174 T1738 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 14176 T1738 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49786_
[junit4:junit4]   2> 14177 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce000a type:delete cxid:0xd zxid:0x90 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:49786_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:49786_
[junit4:junit4]   2> 14178 T1738 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49786_
[junit4:junit4]   2> 14184 T1780 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> 14184 T1796 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> 14185 T1767 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> 14186 T1812 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 14185 T1760 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> 14186 T1780 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 14187 T1796 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 14187 T1767 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 14187 T1760 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 14191 T1813 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-1363908470726/collection1
[junit4:junit4]   2> 14191 T1813 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 14192 T1813 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 14192 T1813 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 14193 T1813 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-1363908470726/collection1/'
[junit4:junit4]   2> 14194 T1813 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-1363908470726/collection1/lib/README' to classloader
[junit4:junit4]   2> 14194 T1813 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-1363908470726/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 14221 T1813 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 14277 T1813 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 14278 T1813 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 14281 T1813 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 14499 T1761 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 14499 T1761 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:47128_",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:47128",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"3",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "state":"active"}
[junit4:junit4]   2> 14502 T1796 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> 14502 T1767 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> 14502 T1812 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> 14502 T1780 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> 14502 T1760 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> 14601 T1813 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 14606 T1813 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 14609 T1813 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 14617 T1813 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 14620 T1813 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 14622 T1813 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 14623 T1813 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 14623 T1813 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 14623 T1813 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 14624 T1813 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 14624 T1813 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 14624 T1813 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 14625 T1813 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-1363908470726/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/jetty3/
[junit4:junit4]   2> 14625 T1813 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1a57f3f
[junit4:junit4]   2> 14625 T1813 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 14625 T1813 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/jetty3
[junit4:junit4]   2> 14626 T1813 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/jetty3/index/
[junit4:junit4]   2> 14626 T1813 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 14626 T1813 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/jetty3/index
[junit4:junit4]   2> 14627 T1813 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@15d0cb5 lockFactory=org.apache.lucene.store.NativeFSLockFactory@11e2a9c),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 14627 T1813 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 14629 T1813 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 14629 T1813 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 14629 T1813 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 14630 T1813 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 14630 T1813 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 14630 T1813 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 14630 T1813 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 14631 T1813 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 14631 T1813 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 14633 T1813 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 14635 T1813 oass.SolrIndexSearcher.<init> Opening Searcher@d45473 main
[junit4:junit4]   2> 14635 T1813 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/jetty3/tlog
[junit4:junit4]   2> 14636 T1813 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 14636 T1813 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 14639 T1814 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@d45473 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 14640 T1813 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 14640 T1813 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 16006 T1761 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 16007 T1761 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:49786_",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:49786",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"4",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "state":"down"}
[junit4:junit4]   2> 16007 T1761 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4]   2> 16007 T1761 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4]   2> 16011 T1812 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> 16011 T1767 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> 16011 T1796 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> 16011 T1760 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> 16011 T1780 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> 16641 T1813 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 16641 T1813 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49786 collection:collection1 shard:shard2
[junit4:junit4]   2> 16644 T1813 oasc.ZkController.register We are http://127.0.0.1:49786/collection1/ and leader is http://127.0.0.1:54134/collection1/
[junit4:junit4]   2> 16644 T1813 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49786
[junit4:junit4]   2> 16644 T1813 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 16644 T1813 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C156 name=collection1 org.apache.solr.core.SolrCore@d5d38c url=http://127.0.0.1:49786/collection1 node=127.0.0.1:49786_ C156_STATE=coll:collection1 core:collection1 props:{collection=collection1, core=collection1, node_name=127.0.0.1:49786_, base_url=http://127.0.0.1:49786, state=down}
[junit4:junit4]   2> 16644 T1815 C156 P49786 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 16645 T1815 C156 P49786 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 16645 T1813 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 16645 T1815 C156 P49786 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 16645 T1815 C156 P49786 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 16645 T1738 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 16646 T1815 C156 P49786 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 16646 T1738 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 16646 T1738 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 16739 T1738 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 16742 T1738 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:44797
[junit4:junit4]   2> 16743 T1738 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 16743 T1738 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 16744 T1738 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-1363908474322
[junit4:junit4]   2> 16744 T1738 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-1363908474322/solr.xml
[junit4:junit4]   2> 16745 T1738 oasc.CoreContainer.<init> New CoreContainer 2405903
[junit4:junit4]   2> 16745 T1738 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-1363908474322/'
[junit4:junit4]   2> 16746 T1738 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-1363908474322/'
[junit4:junit4]   2> 16767 T1738 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 16768 T1738 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 16768 T1738 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 16768 T1738 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 16769 T1738 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 16769 T1738 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 16769 T1738 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 16769 T1738 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 16770 T1738 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 16770 T1738 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 16776 T1738 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 16785 T1738 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:41498/solr
[junit4:junit4]   2> 16785 T1738 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 16785 T1738 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:41498 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@70a6f4
[junit4:junit4]   2> 16786 T1738 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 16786 T1826 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:41498. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 16787 T1826 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:41498, initiating session
[junit4:junit4]   2> 16787 T1740 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:37405
[junit4:junit4]   2> 16787 T1740 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:37405
[junit4:junit4]   2> 16788 T1742 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8f4774ce000b with negotiated timeout 20000 for client /127.0.0.1:37405
[junit4:junit4]   2> 16788 T1826 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:41498, sessionid = 0x13d8f4774ce000b, negotiated timeout = 20000
[junit4:junit4]   2> 16788 T1827 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@70a6f4 name:ZooKeeperConnection Watcher:127.0.0.1:41498 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 16789 T1738 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 16790 T1743 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d8f4774ce000b
[junit4:junit4]   2> 16790 T1740 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:37405 which had sessionid 0x13d8f4774ce000b
[junit4:junit4]   2> 16790 T1827 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 16790 T1738 oaz.ZooKeeper.close Session: 0x13d8f4774ce000b closed
[junit4:junit4]   2> 16791 T1738 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 16793 T1738 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:41498/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@102bfd3
[junit4:junit4]   2> 16794 T1828 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:41498. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 16794 T1738 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 16794 T1828 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:41498, initiating session
[junit4:junit4]   2> 16795 T1740 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:37406
[junit4:junit4]   2> 16795 T1740 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:37406
[junit4:junit4]   2> 16795 T1742 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8f4774ce000c with negotiated timeout 20000 for client /127.0.0.1:37406
[junit4:junit4]   2> 16796 T1828 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:41498, sessionid = 0x13d8f4774ce000c, negotiated timeout = 20000
[junit4:junit4]   2> 16796 T1829 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@102bfd3 name:ZooKeeperConnection Watcher:127.0.0.1:41498/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 16796 T1738 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 16797 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce000c type:create cxid:0x1 zxid:0xa1 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 16798 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce000c type:create cxid:0x3 zxid:0xa2 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 16799 T1738 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 17514 T1761 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 17515 T1761 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:49786_",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:49786",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"4",
[junit4:junit4]   2> 	  "shard":"shard2",
[junit4:junit4]   2> 	  "state":"recovering"}
[junit4:junit4]   2> 17518 T1760 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> 17518 T1780 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> 17518 T1767 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> 17518 T1829 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> 17518 T1812 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> 17518 T1796 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> 17650 T1773 oass.SolrDispatchFilter.handleAdminRequest /admin/cores {version=2&onlyIfLeader=true&core=collection1&nodeName=127.0.0.1:49786_&checkLive=true&action=PREPRECOVERY&coreNodeName=4&wt=javabin&state=recovering} status=0 QTime=1000 
[junit4:junit4]   2> 17802 T1738 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44797_
[junit4:junit4]   2> 17803 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce000c type:delete cxid:0xf zxid:0xa7 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:44797_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:44797_
[junit4:junit4]   2> 17804 T1738 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:44797_
[junit4:junit4]   2> 17806 T1760 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> 17807 T1767 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> 17807 T1780 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 17808 T1780 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> 17808 T1829 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 17808 T1812 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 17808 T1796 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 17808 T1829 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> 17808 T1812 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> 17809 T1796 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> 17809 T1767 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 17809 T1760 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 17815 T1830 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-1363908474322/collection1
[junit4:junit4]   2> 17815 T1830 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 17816 T1830 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 17816 T1830 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 17817 T1830 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-1363908474322/collection1/'
[junit4:junit4]   2> 17817 T1830 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-1363908474322/collection1/lib/README' to classloader
[junit4:junit4]   2> 17817 T1830 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-1363908474322/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 17855 T1830 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 17883 T1830 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 17884 T1830 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 17887 T1830 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 18210 T1830 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 18215 T1830 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 18217 T1830 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 18227 T1830 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 18230 T1830 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 18232 T1830 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 18233 T1830 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 18234 T1830 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 18234 T1830 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 18234 T1830 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 18235 T1830 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 18235 T1830 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 18235 T1830 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-1363908474322/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/jetty4/
[junit4:junit4]   2> 18235 T1830 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1a57f3f
[junit4:junit4]   2> 18236 T1830 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 18236 T1830 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/jetty4
[junit4:junit4]   2> 18236 T1830 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/jetty4/index/
[junit4:junit4]   2> 18236 T1830 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 18236 T1830 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/jetty4/index
[junit4:junit4]   2> 18237 T1830 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@17cc986 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1cfc55b),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 18238 T1830 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 18239 T1830 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 18239 T1830 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 18240 T1830 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 18240 T1830 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 18240 T1830 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 18240 T1830 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 18241 T1830 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 18241 T1830 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 18241 T1830 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 18243 T1830 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 18245 T1830 oass.SolrIndexSearcher.<init> Opening Searcher@eaea62 main
[junit4:junit4]   2> 18245 T1830 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/jetty4/tlog
[junit4:junit4]   2> 18246 T1830 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 18246 T1830 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 18249 T1831 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@eaea62 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 18250 T1830 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 18250 T1830 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 19023 T1761 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 19024 T1761 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:44797_",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:44797",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"5",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "state":"down"}
[junit4:junit4]   2> 19024 T1761 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4]   2> 19024 T1761 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 19027 T1796 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> 19027 T1812 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> 19027 T1780 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> 19027 T1760 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> 19027 T1829 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> 19027 T1767 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> 19252 T1830 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 19252 T1830 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:44797 collection:collection1 shard:shard1
[junit4:junit4]   2> 19255 T1830 oasc.ZkController.register We are http://127.0.0.1:44797/collection1/ and leader is http://127.0.0.1:47128/collection1/
[junit4:junit4]   2> 19255 T1830 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:44797
[junit4:junit4]   2> 19255 T1830 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 19255 T1830 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C157 name=collection1 org.apache.solr.core.SolrCore@35c69f url=http://127.0.0.1:44797/collection1 node=127.0.0.1:44797_ C157_STATE=coll:collection1 core:collection1 props:{collection=collection1, core=collection1, node_name=127.0.0.1:44797_, base_url=http://127.0.0.1:44797, state=down}
[junit4:junit4]   2> 19256 T1832 C157 P44797 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 19256 T1832 C157 P44797 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 19256 T1830 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 19256 T1832 C157 P44797 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 19256 T1832 C157 P44797 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 19257 T1738 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 19257 T1738 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 19258 T1832 C157 P44797 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 19258 T1738 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 19261 T1738 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 19262 T1738 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 19266 T1776 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-1363908461679/onenodecollectioncore
[junit4:junit4]   2> 19266 T1776 oasc.ZkController.createCollectionZkNode Check for collection zkNode:onenodecollection
[junit4:junit4]   2> 19266 T1776 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:onenodecollection
[junit4:junit4]   2> 19267 T1776 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4]   2> 19267 T1776 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4]   2> 19268 T1776 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection
[junit4:junit4]   2> 19270 T1776 oasc.ZkController.readConfigName Load collection config from:/collections/onenodecollection
[junit4:junit4]   2> 19270 T1776 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-1363908461679/onenodecollectioncore/'
[junit4:junit4]   2> 19312 T1776 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 19341 T1776 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 19342 T1776 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 19346 T1776 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2>  C156_STATE=coll:collection1 core:collection1 props:{collection=collection1, core=collection1, node_name=127.0.0.1:49786_, base_url=http://127.0.0.1:49786, shard=shard2, state=recovering}
[junit4:junit4]   2> 19651 T1815 C156 P49786 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:54134/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 19652 T1815 C156 P49786 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:49786 START replicas=[http://127.0.0.1:54134/collection1/] nUpdates=100
[junit4:junit4]   2> 19652 T1815 C156 P49786 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 19652 T1815 C156 P49786 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 19653 T1815 C156 P49786 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 19653 T1815 C156 P49786 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 19653 T1815 C156 P49786 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 19653 T1815 C156 P49786 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:54134/collection1/. core=collection1
[junit4:junit4]   2> 19653 T1815 C156 P49786 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C158 name=collection1 org.apache.solr.core.SolrCore@1b475c6 url=http://127.0.0.1:54134/collection1 node=127.0.0.1:54134_ C158_STATE=coll:collection1 core:collection1 props:{collection=collection1, core=collection1, node_name=127.0.0.1:54134_, base_url=http://127.0.0.1:54134, shard=shard2, state=active, leader=true}
[junit4:junit4]   2> 19656 T1774 C158 P54134 REQ /get {version=2&distrib=false&qt=/get&getVersions=100&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 19657 T1773 C158 P54134 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 19659 T1773 C158 P54134 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@f9d08e lockFactory=org.apache.lucene.store.NativeFSLockFactory@114a175),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 19659 T1773 C158 P54134 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 19660 T1773 C158 P54134 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@f9d08e lockFactory=org.apache.lucene.store.NativeFSLockFactory@114a175),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@f9d08e lockFactory=org.apache.lucene.store.NativeFSLockFactory@114a175),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 19660 T1773 C158 P54134 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 19661 T1773 C158 P54134 oass.SolrIndexSearcher.<init> Opening Searcher@a9d03e realtime
[junit4:junit4]   2> 19661 T1773 C158 P54134 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 19662 T1773 C158 P54134 /update {version=2&commit_end_point=true&openSearcher=false&waitSearcher=true&commit=true&wt=javabin&softCommit=false} {commit=} 0 5
[junit4:junit4]   2> 19663 T1815 C156 P49786 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 19663 T1815 C156 P49786 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 19670 T1773 C158 P54134 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 19670 T1773 C158 P54134 REQ /replication {version=2&command=indexversion&qt=/replication&wt=javabin} status=0 QTime=6 
[junit4:junit4]   2> 19671 T1815 C156 P49786 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4]   2> 19671 T1815 C156 P49786 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 19671 T1815 C156 P49786 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 19674 T1774 C158 P54134 REQ /replication {version=2&command=filelist&generation=2&qt=/replication&wt=javabin} status=0 QTime=1 
[junit4:junit4]   2> 19674 T1815 C156 P49786 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4]   2> 19675 T1815 C156 P49786 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/jetty3/index.20130322002757346
[junit4:junit4]   2> 19675 T1815 C156 P49786 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@1074043 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1bab37e) fullCopy=false
[junit4:junit4]   2> 19676 T1776 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 19678 T1775 C158 P54134 REQ /replication {command=filecontent&generation=2&file=segments_2&checksum=true&qt=/replication&wt=filestream} status=0 QTime=1 
[junit4:junit4]   2> 19679 T1815 C156 P49786 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 19679 T1815 C156 P49786 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 19680 T1815 C156 P49786 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 19681 T1815 C156 P49786 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@15d0cb5 lockFactory=org.apache.lucene.store.NativeFSLockFactory@11e2a9c),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@15d0cb5 lockFactory=org.apache.lucene.store.NativeFSLockFactory@11e2a9c),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 19681 T1815 C156 P49786 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 19681 T1815 C156 P49786 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 19681 T1776 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 19682 T1815 C156 P49786 oass.SolrIndexSearcher.<init> Opening Searcher@e8f35b main
[junit4:junit4]   2> 19682 T1814 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@e8f35b main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4]   2> 19683 T1815 C156 P49786 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 19683 T1815 C156 P49786 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 19683 T1815 C156 P49786 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 19683 T1815 C156 P49786 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 19684 T1776 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 19684 T1815 C156 P49786 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 19692 T1776 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 19695 T1776 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 19697 T1776 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 19698 T1776 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 19698 T1776 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 19699 T1776 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 19699 T1776 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 19700 T1776 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 19700 T1776 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 19700 T1776 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-1363908461679/onenodecollectioncore/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1363908457676/onenodecollection/
[junit4:junit4]   2> 19701 T1776 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1a57f3f
[junit4:junit4]   2> 19701 T1776 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 19701 T1776 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1363908457676/onenodecollection
[junit4:junit4]   2> 19702 T1776 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-1363908457676/onenodecollection/index/
[junit4:junit4]   2> 19702 T1776 oasc.SolrCore.initIndex WARNING [onenodecollectioncore] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1363908457676/onenodecollection/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 19702 T1776 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1363908457676/onenodecollection/index
[junit4:junit4]   2> 19704 T1776 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@9e6d0d lockFactory=org.apache.lucene.store.NativeFSLockFactory@f5921c),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 19704 T1776 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 19705 T1776 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 19706 T1776 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 19706 T1776 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 19706 T1776 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 19707 T1776 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 19707 T1776 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 19707 T1776 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 19708 T1776 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 19708 T1776 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 19710 T1776 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 19712 T1776 oass.SolrIndexSearcher.<init> Opening Searcher@1ddb055 main
[junit4:junit4]   2> 19713 T1776 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1363908457676/onenodecollection/tlog
[junit4:junit4]   2> 19713 T1776 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 19713 T1776 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 19716 T1836 oasc.SolrCore.registerSearcher [onenodecollectioncore] Registered new searcher Searcher@1ddb055 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 19716 T1776 oasc.ZkController.publish publishing core=onenodecollectioncore state=down
[junit4:junit4]   2> 20531 T1761 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 20532 T1761 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:44797_",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:44797",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"5",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "state":"recovering"}
[junit4:junit4]   2> 20535 T1761 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:49786_",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:49786",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"4",
[junit4:junit4]   2> 	  "shard":"shard2",
[junit4:junit4]   2> 	  "state":"active"}
[junit4:junit4]   2> 20536 T1761 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "collection":"onenodecollection",
[junit4:junit4]   2> 	  "core":"onenodecollectioncore",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:54134_",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "roles":"none",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:54134",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "state":"down"}
[junit4:junit4]   2> 20537 T1761 oasc.Overseer$ClusterStateUpdater.createCollection Create collection onenodecollection with numShards 1
[junit4:junit4]   2> 20537 T1761 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 20539 T1760 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> 20539 T1767 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> 20539 T1812 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> 20539 T1796 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> 20539 T1829 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> 20539 T1780 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> 20718 T1776 oasc.CoreContainer.registerCore registering core: onenodecollectioncore
[junit4:junit4]   2> 20719 T1776 oasc.ZkController.register Register replica - core:onenodecollectioncore address:http://127.0.0.1:54134 collection:onenodecollection shard:shard1
[junit4:junit4]   2> 20719 T1776 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leader_elect/shard1/election
[junit4:junit4]   2> 20723 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce0006 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> 20724 T1776 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 20724 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce0006 type:create cxid:0xad zxid:0xc3 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 20725 T1776 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 20726 T1776 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 20726 T1776 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:54134/onenodecollectioncore/
[junit4:junit4]   2> 20726 T1776 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 20726 T1776 oasc.SyncStrategy.syncToMe http://127.0.0.1:54134/onenodecollectioncore/ has no replicas
[junit4:junit4]   2> 20727 T1776 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:54134/onenodecollectioncore/
[junit4:junit4]   2> 20727 T1776 oascc.SolrZkClient.makePath makePath: /collections/onenodecollection/leaders/shard1
[junit4:junit4]   2> 20729 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce0006 type:create cxid:0xb8 zxid:0xc7 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 21262 T1789 oass.SolrDispatchFilter.handleAdminRequest /admin/cores {version=2&onlyIfLeader=true&core=collection1&nodeName=127.0.0.1:44797_&checkLive=true&action=PREPRECOVERY&coreNodeName=5&wt=javabin&state=recovering} status=0 QTime=2000 
[junit4:junit4]   2> 22044 T1761 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 22049 T1760 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> 22049 T1812 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> 22049 T1796 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> 22049 T1780 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> 22049 T1767 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> 22049 T1829 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> 22085 T1776 oasc.ZkController.register We are http://127.0.0.1:54134/onenodecollectioncore/ and leader is http://127.0.0.1:54134/onenodecollectioncore/
[junit4:junit4]   2> 22085 T1776 oasc.ZkController.register No LogReplay needed for core=onenodecollectioncore baseURL=http://127.0.0.1:54134
[junit4:junit4]   2> 22085 T1776 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 22085 T1776 oasc.ZkController.publish publishing core=onenodecollectioncore state=active
[junit4:junit4]   2> 22087 T1776 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 22088 T1776 oass.SolrDispatchFilter.handleAdminRequest /admin/cores {version=2&collection=onenodecollection&roles=none&numShards=1&action=CREATE&dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1363908457676/onenodecollection&wt=javabin&name=onenodecollectioncore} status=0 QTime=2823 
[junit4:junit4]   2> 22088 T1738 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: onenodecollection failOnTimeout:true timeout (sec):230
[junit4:junit4]   2> 22089 T1738 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 23090 T1738 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2>  C157_STATE=coll:collection1 core:collection1 props:{collection=collection1, core=collection1, node_name=127.0.0.1:44797_, base_url=http://127.0.0.1:44797, shard=shard1, state=recovering}
[junit4:junit4]   2> 23263 T1832 C157 P44797 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:47128/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 23263 T1832 C157 P44797 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:44797 START replicas=[http://127.0.0.1:47128/collection1/] nUpdates=100
[junit4:junit4]   2> 23264 T1832 C157 P44797 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 23264 T1832 C157 P44797 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 23264 T1832 C157 P44797 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 23264 T1832 C157 P44797 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 23264 T1832 C157 P44797 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 23264 T1832 C157 P44797 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:47128/collection1/. core=collection1
[junit4:junit4]   2> 23264 T1832 C157 P44797 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C159 name=collection1 org.apache.solr.core.SolrCore@cd254c url=http://127.0.0.1:47128/collection1 node=127.0.0.1:47128_ C159_STATE=coll:collection1 core:collection1 props:{collection=collection1, core=collection1, node_name=127.0.0.1:47128_, base_url=http://127.0.0.1:47128, shard=shard1, state=active, leader=true}
[junit4:junit4]   2> 23267 T1790 C159 P47128 REQ /get {version=2&distrib=false&qt=/get&getVersions=100&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 23268 T1789 C159 P47128 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 23269 T1789 C159 P47128 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1b0ce7a lockFactory=org.apache.lucene.store.NativeFSLockFactory@c10913),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 23269 T1789 C159 P47128 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 23269 T1789 C159 P47128 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1b0ce7a lockFactory=org.apache.lucene.store.NativeFSLockFactory@c10913),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1b0ce7a lockFactory=org.apache.lucene.store.NativeFSLockFactory@c10913),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 23270 T1789 C159 P47128 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 23270 T1789 C159 P47128 oass.SolrIndexSearcher.<init> Opening Searcher@1b0d363 realtime
[junit4:junit4]   2> 23270 T1789 C159 P47128 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 23271 T1789 C159 P47128 /update {version=2&commit_end_point=true&openSearcher=false&waitSearcher=true&commit=true&wt=javabin&softCommit=false} {commit=} 0 3
[junit4:junit4]   2> 23271 T1832 C157 P44797 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 23271 T1832 C157 P44797 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 23273 T1791 C159 P47128 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 23273 T1791 C159 P47128 REQ /replication {version=2&command=indexversion&qt=/replication&wt=javabin} status=0 QTime=1 
[junit4:junit4]   2> 23274 T1832 C157 P44797 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4]   2> 23274 T1832 C157 P44797 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 23274 T1832 C157 P44797 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 23275 T1790 C159 P47128 REQ /replication {version=2&command=filelist&generation=2&qt=/replication&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 23276 T1832 C157 P44797 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4]   2> 23277 T1832 C157 P44797 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/jetty4/index.20130322002800948
[junit4:junit4]   2> 23277 T1832 C157 P44797 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@1475044 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1848b4e) fullCopy=false
[junit4:junit4]   2> 23292 T1789 C159 P47128 REQ /replication {command=filecontent&generation=2&file=segments_2&checksum=true&qt=/replication&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 23293 T1832 C157 P44797 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 23294 T1832 C157 P44797 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 23294 T1832 C157 P44797 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 23295 T1832 C157 P44797 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@17cc986 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1cfc55b),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@17cc986 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1cfc55b),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 23295 T1832 C157 P44797 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 23295 T1832 C157 P44797 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 23295 T1832 C157 P44797 oass.SolrIndexSearcher.<init> Opening Searcher@ef52f main
[junit4:junit4]   2> 23296 T1831 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@ef52f main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4]   2> 23296 T1832 C157 P44797 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 23296 T1832 C157 P44797 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 23296 T1832 C157 P44797 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 23296 T1832 C157 P44797 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 23297 T1832 C157 P44797 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 23553 T1761 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 23554 T1761 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "collection":"onenodecollection",
[junit4:junit4]   2> 	  "core":"onenodecollectioncore",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:54134_",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "roles":"none",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:54134",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"127.0.0.1:54134__onenodecollectioncore",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "state":"active"}
[junit4:junit4]   2> 23556 T1761 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:44797_",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:44797",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"5",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "state":"active"}
[junit4:junit4]   2> 23559 T1829 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> 23559 T1760 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> 23559 T1796 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> 23560 T1812 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> 23560 T1780 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> 23559 T1767 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> 24091 T1738 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 24092 T1738 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: onenodecollection
[junit4:junit4]   2> 24093 T1738 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 24097 T1738 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:41498 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@dae750
[junit4:junit4]   2> 24097 T1839 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost.localdomain/127.0.0.1:41498. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 24097 T1738 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 24098 T1740 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:37418
[junit4:junit4]   2> 24098 T1839 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost.localdomain/127.0.0.1:41498, initiating session
[junit4:junit4]   2> 24098 T1740 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:37418
[junit4:junit4]   2> 24099 T1742 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8f4774ce000d with negotiated timeout 10000 for client /127.0.0.1:37418
[junit4:junit4]   2> 24099 T1839 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost.localdomain/127.0.0.1:41498, sessionid = 0x13d8f4774ce000d, negotiated timeout = 10000
[junit4:junit4]   2> 24099 T1840 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@dae750 name:ZooKeeperConnection Watcher:127.0.0.1:41498 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 24099 T1738 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 24127 T1743 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d8f4774ce000d
[junit4:junit4]   2> 24128 T1840 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 24128 T1740 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:37418 which had sessionid 0x13d8f4774ce000d
[junit4:junit4]   2> 24128 T1738 oaz.ZooKeeper.close Session: 0x13d8f4774ce000d closed
[junit4:junit4]   2> 24129 T1743 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d8f4774ce0004
[junit4:junit4]   2> 24129 T1767 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 24129 T1740 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:37397 which had sessionid 0x13d8f4774ce0004
[junit4:junit4]   2> 24129 T1738 oaz.ZooKeeper.close Session: 0x13d8f4774ce0004 closed
[junit4:junit4]   2> 24131 T1738 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 52708
[junit4:junit4]   2> 24132 T1738 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=26355114
[junit4:junit4]   2> 25066 T1761 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 25066 T1761 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4]   2> 	  "collection":"control_collection",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:52708_",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:52708",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "state":"down"}
[junit4:junit4]   2> 25070 T1796 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> 25070 T1780 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> 25070 T1812 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> 25070 T1760 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> 25070 T1829 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> 26133 T1738 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 26133 T1738 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 26135 T1738 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@7ee046
[junit4:junit4]   2> 26138 T1738 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> 26138 T1738 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 26138 T1738 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 26138 T1738 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 26139 T1738 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 26139 T1738 oasc.CachingDirectoryFactory.close Closing directory when closing factory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/control/data
[junit4:junit4]   2> 26139 T1738 oasc.CachingDirectoryFactory.closeDirectory Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/control/data
[junit4:junit4]   2> 26140 T1738 oasc.CachingDirectoryFactory.close Closing directory when closing factory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/control/data/index
[junit4:junit4]   2> 26140 T1738 oasc.CachingDirectoryFactory.closeDirectory Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/control/data/index
[junit4:junit4]   2> 26141 T1761 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89385104682385411-127.0.0.1:52708_-n_0000000000) am no longer a leader.
[junit4:junit4]   2> 26142 T1743 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d8f4774ce0003
[junit4:junit4]   2> 26143 T1760 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> 26143 T1812 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> 26143 T1740 oazs.NIOServerCnxn.doIO WARNING caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13d8f4774ce0003, likely client has closed socket
[junit4:junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4]   2> 	at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   2> 
[junit4:junit4]   2> 26143 T1738 oaz.ZooKeeper.close Session: 0x13d8f4774ce0003 closed
[junit4:junit4]   2> 26144 T1740 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:37394 which had sessionid 0x13d8f4774ce0003
[junit4:junit4]   2> 26143 T1760 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 26144 T1796 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 26144 T1760 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 26143 T1829 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 26144 T1796 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> 26144 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce0006 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> 26145 T1829 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> 26144 T1760 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 26145 T1780 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 26146 T1812 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 26147 T1780 oasc.Overseer.start Overseer (id=89385104682385414-127.0.0.1:54134_-n_0000000001) starting
[junit4:junit4]   2> 26147 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce0006 type:create cxid:0xcb zxid:0xe5 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 26148 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce0006 type:create cxid:0xcc zxid:0xe6 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 26149 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce0006 type:create cxid:0xce zxid:0xe7 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 26150 T1743 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8f4774ce0006 type:create cxid:0xd0 zxid:0xe8 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 26151 T1842 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 26151 T1780 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 26151 T1780 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> 26151 T1841 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 26153 T1841 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 26153 T1841 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "collection":"control_collection",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:52708_",
[junit4:junit4]   2> 	  "numShards":"2",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:52708",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "state":"down"}
[junit4:junit4]   2> 26156 T1780 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> 26156 T1796 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> 26156 T1829 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> 26157 T1812 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> 26166 T1738 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4]   2> 26217 T1738 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 54134
[junit4:junit4]   2> 26218 T1738 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=28625978
[junit4:junit4]   2> 27659 T1841 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 27660 T1841 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:54134_",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:54134",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"2",
[junit4:junit4]   2> 	  "shard":"shard2",
[junit4:junit4]   2> 	  "state":"down"}
[junit4:junit4]   2> 27662 T1841 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4]   2> 	  "collection":"onenodecollection",
[junit4:junit4]   2> 	  "core":"onenodecollectioncore",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:54134_",
[junit4:junit4]   2> 	  "roles":"none",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:54134",
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"127.0.0.1:54134__onenodecollectioncore",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "state":"down"}
[junit4:junit4]   2> 27664 T1829 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> 27664 T1780 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> 27664 T1796 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> 27664 T1812 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> 29221 T1738 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 29221 T1738 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 29223 T1738 oasc.ZkController.publish publishing core=onenodecollectioncore state=down
[junit4:junit4]   2> 29225 T1738 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@1b475c6
[junit4:junit4]   2> 29228 T1738 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> 29229 T1738 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 29229 T1738 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 29230 T1738 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 29232 T1738 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 29232 T1738 oasc.CachingDirectoryFactory.close Closing directory when closing factory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/jetty1
[junit4:junit4]   2> 29233 T1738 oasc.CachingDirectoryFactory.closeDirectory Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/jetty1
[junit4:junit4]   2> 29233 T1738 oasc.CachingDirectoryFactory.close Closing directory when closing factory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/jetty1/index
[junit4:junit4]   2> 29233 T1738 oasc.CachingDirectoryFactory.closeDirectory Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1363908457675/jetty1/index
[junit4:junit4]   2> 29234 T1738 oasc.SolrCore.close [onenodecollectioncore]  CLOSING SolrCore org.apache.solr.core.SolrCore@14a148b
[junit4:junit4]   2> 29239 T1738 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> 29239 T1738 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 29240 T1738 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 29240 T1738 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 29241 T1738 oasc.SolrCore.closeSearcher [onenodecollectioncore] Closing main searcher on request.
[junit4:junit4]   2> 29241 T1738 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1363908457676/onenodecollection
[junit4:junit4]   2> 29241 T1738 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-136390845767

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

 	at org.junit.Assert.fail(Assert.java:93)
[junit4:junit4]    > 	at org.apache.solr.cloud.UnloadDistributedZkTest.testUnloadShardAndCollection(UnloadDistributedZkTest.java:124)
[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> 137782 T1852 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4]   2> 137792 T1851 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 3 leaked thread(s).
[junit4:junit4]   2> 138188 T1855 oazs.SessionTrackerImpl.run SessionTrackerImpl exited loop!
[junit4:junit4]   2> 138879 T1934 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 138879 T1934 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 138880 T1934 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   2> 138880 T1934 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 138880 T1934 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> NOTE: test params are: codec=Lucene42: {intDefault=MockFixedIntBlock(blockSize=1586), _version_=MockFixedIntBlock(blockSize=1586), timestamp=MockFixedIntBlock(blockSize=1586), range_facet_si=PostingsFormat(name=Lucene41WithOrds), a_si=PostingsFormat(name=Lucene41WithOrds), text=Lucene41(blocksize=128), multiDefault=PostingsFormat(name=Lucene41WithOrds), a_t=MockFixedIntBlock(blockSize=1586), range_facet_sl=Lucene41(blocksize=128), range_facet_l=MockFixedIntBlock(blockSize=1586), other_tl1=MockFixedIntBlock(blockSize=1586), id=PostingsFormat(name=Asserting)}, docValues:{timestamp=DocValuesFormat(name=Disk)}, sim=DefaultSimilarity, locale=sr_BA_#Latn, timezone=Pacific/Galapagos
[junit4:junit4]   2> NOTE: Linux 3.2.0-39-generic i386/Oracle Corporation 1.8.0-ea (32-bit)/cpus=8,threads=1,free=59379656,total=302227456
[junit4:junit4]   2> NOTE: All tests run in this JVM: [EchoParamsTest, TestPostingsSolrHighlighter, FieldAnalysisRequestHandlerTest, SolrPluginUtilsTest, TestDFRSimilarityFactory, SpellCheckCollatorTest, TestRTGBase, TestFiltering, IndexSchemaRuntimeFieldTest, TestSuggestSpellingConverter, TestElisionMultitermQuery, TestFieldResource, DocumentAnalysisRequestHandlerTest, IndexReaderFactoryTest, TestCodecSupport, TestDistributedGrouping, TestBM25SimilarityFactory, TestStressReorder, TestLMJelinekMercerSimilarityFactory, HardAutoCommitTest, TestFoldingMultitermQuery, JSONWriterTest, TestJmxIntegration, CurrencyFieldXmlFileTest, TestCollationField, DisMaxRequestHandlerTest, TestMergePolicyConfig, DistanceFunctionTest, RequiredFieldsTest, OutputWriterTest, XsltUpdateRequestHandlerTest, CoreContainerCoreInitFailuresTest, CollectionsAPIDistributedZkTest, TestAtomicUpdateErrorCases, TimeZoneUtilsTest, StatsComponentTest, TestLuceneMatchVersion, SolrCoreCheckLockOnStartupTest, TestQueryTypes, SolrRequestParserTest, ShardRoutingCustomTest, ConvertedLegacyTest, FileUtilsTest, UpdateParamsTest, TestJmxMonitoredMap, URLClassifyProcessorTest, TestOmitPositions, BadIndexSchemaTest, SpellPossibilityIteratorTest, TestUtils, AliasIntegrationTest, TestFastOutputStream, TestSolrXMLSerializer, CopyFieldTest, TestIndexSearcher, DefaultValueUpdateProcessorTest, XmlUpdateRequestHandlerTest, LeaderElectionIntegrationTest, SuggesterWFSTTest, SpellCheckComponentTest, TestPropInject, TestSolrJ, SignatureUpdateProcessorFactoryTest, RequestHandlersTest, NumericFieldsTest, TestFieldTypeCollectionResource, BasicDistributedZkTest, BasicDistributedZk2Test, UnloadDistributedZkTest]
[junit4:junit4] Completed on J1 in 139.07s, 1 test, 1 failure <<< FAILURES!

[...truncated 416 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:1210: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:874: There were test failures: 272 suites, 1145 tests, 1 error, 1 failure, 13 ignored (7 assumptions)

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



Mime
View raw message