Return-Path: X-Original-To: apmail-lucene-dev-archive@www.apache.org Delivered-To: apmail-lucene-dev-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id B72EAFE18 for ; Sat, 13 Apr 2013 08:43:09 +0000 (UTC) Received: (qmail 65781 invoked by uid 500); 13 Apr 2013 08:43:05 -0000 Delivered-To: apmail-lucene-dev-archive@lucene.apache.org Received: (qmail 65721 invoked by uid 500); 13 Apr 2013 08:43:04 -0000 Mailing-List: contact dev-help@lucene.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@lucene.apache.org Delivered-To: mailing list dev@lucene.apache.org Received: (qmail 65701 invoked by uid 99); 13 Apr 2013 08:43:04 -0000 Received: from nike.apache.org (HELO nike.apache.org) (192.87.106.230) by apache.org (qpsmtpd/0.29) with ESMTP; Sat, 13 Apr 2013 08:43:04 +0000 X-ASF-Spam-Status: No, hits=0.0 required=5.0 tests=NORMAL_HTTP_TO_IP,SPF_PASS,WEIRD_PORT X-Spam-Check-By: apache.org Received-SPF: pass (nike.apache.org: domain of jenkins@thetaphi.de designates 188.138.97.18 as permitted sender) Received: from [188.138.97.18] (HELO mail.sd-datasolutions.de) (188.138.97.18) by apache.org (qpsmtpd/0.29) with ESMTP; Sat, 13 Apr 2013 08:42:41 +0000 Received: from serv1 (localhost.localdomain [127.0.0.1]) by mail.sd-datasolutions.de (Postfix) with ESMTP id 87B4F14AA04B for ; Sat, 13 Apr 2013 08:42:18 +0000 (UTC) Date: Sat, 13 Apr 2013 08:41:30 +0000 (UTC) From: Policeman Jenkins Server To: dev@lucene.apache.org Message-ID: <445110643.85.1365842536770.JavaMail.jenkins@serv1.sd-datasolutions.de> Subject: [JENKINS] Lucene-Solr-trunk-Linux (64bit/jdk1.8.0-ea-b84) - Build # 5141 - Failure! MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="----=_Part_84_1577224863.1365842490593" X-Jenkins-Job: Lucene-Solr-trunk-Linux X-Jenkins-Result: FAILURE X-Virus-Checked: Checked by ClamAV on apache.org ------=_Part_84_1577224863.1365842490593 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/5141/ Java: 64bit/jdk1.8.0-ea-b84 -XX:+UseConcMarkSweepGC 1 tests failed. REGRESSION: org.apache.solr.cloud.BasicDistributedZk2Test.testDistribSearc= h Error Message: Server at http://127.0.0.1:60382/onenodecollectioncore returned non ok stat= us:404, message:Can not find: /onenodecollectioncore/update Stack Trace: org.apache.solr.common.SolrException: Server at http://127.0.0.1:60382/onen= odecollectioncore returned non ok status:404, message:Can not find: /onenod= ecollectioncore/update =09at __randomizedtesting.SeedInfo.seed([9E1AB61E2243A826:1FFC3806551CC81A]= :0) =09at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServ= er.java:375) =09at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServ= er.java:181) =09at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(Ab= stractUpdateRequest.java:117) =09at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:116) =09at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:102) =09at org.apache.solr.cloud.BasicDistributedZk2Test.testNodeWithoutCollecti= onForwarding(BasicDistributedZk2Test.java:197) =09at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributed= Zk2Test.java:89) =09at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseD= istributedSearchTestCase.java:806) =09at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) =09at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.= java:57) =09at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces= sorImpl.java:43) =09at java.lang.reflect.Method.invoke(Method.java:487) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(Randomized= Runner.java:1559) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(Random= izedRunner.java:79) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(Random= izedRunner.java:737) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(Random= izedRunner.java:773) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(Random= izedRunner.java:787) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:53) =09at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRu= leSetupTeardownChained.java:50) =09at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFi= eldCacheSanity.java:51) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:46) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRul= e$1.evaluate(SystemPropertiesInvariantRule.java:55) =09at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleT= hreadAndTestName.java:49) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:70) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:48) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.= run(ThreadLeakControl.java:358) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTa= sk(ThreadLeakControl.java:782) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(Threa= dLeakControl.java:442) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(Ran= domizedRunner.java:746) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(Random= izedRunner.java:648) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(Random= izedRunner.java:682) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(Random= izedRunner.java:693) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:53) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:46) =09at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStor= eClassName.java:42) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRul= e$1.evaluate(SystemPropertiesInvariantRule.java:55) =09at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMeth= odsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) =09at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMeth= odsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRule= AssertionsRequired.java:43) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:48) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:70) =09at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIg= noreTestSuites.java:55) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.= run(ThreadLeakControl.java:358) =09at java.lang.Thread.run(Thread.java:722) Build Log: [...truncated 9180 lines...] [junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.370; org.apache.solr.BaseD= istributedSearchTestCase; Setting hostContext system property: / [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.373; org.apache.solr.SolrT= estCaseJ4; ###Starting testDistribSearch [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.374; org.apache.solr.cloud= .ZkTestServer; STARTING ZK TEST SERVER [junit4:junit4] 1> client port:0.0.0.0/0.0.0.0:0 [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.375; org.apache.solr.cloud= .ZkTestServer$ZKServerMain; Starting server [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.475; org.apache.solr.cloud= .ZkTestServer; start zk server on port:46527 [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.476; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.578; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@52189734 name:ZooKeeperConnection Watcher:127.0.0.1:46527 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.579; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.579; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /solr [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.583; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.584; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@5cdf7307 name:ZooKeeperConnection Watcher:127.0.0.1:46527/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.584; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.584; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.586; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1/shards [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.588; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/control_collection [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.590; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/control_collection/shards [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.592; org.apache.solr.cloud= .AbstractZkTestCase; 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] 1> INFO - 2013-04-13 08:31:22.592; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.596; org.apache.solr.cloud= .AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux= /solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /confi= gs/conf1/schema.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.596; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/schema.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.599; org.apache.solr.cloud= .AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux= /solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /co= nfigs/conf1/stopwords.txt [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.599; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/stopwords.txt [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.601; org.apache.solr.cloud= .AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux= /solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /co= nfigs/conf1/protwords.txt [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.602; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/protwords.txt [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.605; org.apache.solr.cloud= .AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux= /solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /con= figs/conf1/currency.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.605; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/currency.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.607; org.apache.solr.cloud= .AbstractZkTestCase; 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] 1> INFO - 2013-04-13 08:31:22.608; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/open-exchange-rates.json [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.610; org.apache.solr.cloud= .AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux= /solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Acc= ent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.610; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/mapping-ISOLatin1Accent.txt [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.612; org.apache.solr.cloud= .AbstractZkTestCase; 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] 1> INFO - 2013-04-13 08:31:22.613; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/old_synonyms.txt [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.614; org.apache.solr.cloud= .AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux= /solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /con= figs/conf1/synonyms.txt [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.615; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/synonyms.txt [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.686; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.707; org.eclipse.jetty.ser= ver.AbstractConnector; Started SelectChannelConnector@127.0.0.1:33218 [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.707; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.708; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.708; org.apache.solr.core.= SolrResourceLoader; 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-1365841882618 [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.709; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/w= orkspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.= solr.cloud.BasicDistributedZk2Test-controljetty-1365841882618/solr.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.709; org.apache.solr.core.= CoreContainer; New CoreContainer 1944595115 [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.710; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/wor= kspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.so= lr.cloud.BasicDistributedZk2Test-controljetty-1365841882618/' [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.710; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins= /workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apach= e.solr.cloud.BasicDistributedZk2Test-controljetty-1365841882618/' [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.736; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.737; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.737; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.737; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.738; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.738; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.739; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.739; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.740; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.740; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D120000&connTimeout=3D1= 5000&retry=3Dfalse [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.749; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.768; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:46527/solr [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.769; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.770; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.772; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@703b4374 name:ZooKeeperConnection Watcher:127.0.0.1:46527 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.773; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.774; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D500&maxConnectionsPerHost=3D16&socketTimeout=3D120000&connTimeout=3D150= 00 [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.778; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.779; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@6f7a0dda name:ZooKeeperConnection Watcher:127.0.0.1:46527/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.780; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.781; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer/queue [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.784; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer/collection-queue-work [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.787; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.789; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:332= 18_ [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.790; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:33218_ [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.792; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer_elect/election [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.798; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer_elect/leader [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.800; org.apache.solr.cloud= .Overseer; Overseer (id=3D89511813603459075-127.0.0.1:33218_-n_0000000000) = starting [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.803; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer/queue-work [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.807; org.apache.solr.cloud= .OverseerCollectionProcessor; Process current queue of collection creations [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.807; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /clusterstate.json [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.811; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /aliases.json [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.812; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.815; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Starting to work on the main queue [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.818; org.apache.solr.core.= CoreContainer; Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/= jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./or= g.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1365841882618/coll= ection1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.818; org.apache.solr.cloud= .ZkController; Check for collection zkNode:control_collection [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.819; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.819; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/control_collection [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.820; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins= /workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apach= e.solr.cloud.BasicDistributedZk2Test-controljetty-1365841882618/collection1= /' [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.820; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-tru= nk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistribute= dZk2Test-controljetty-1365841882618/collection1/lib/README' to classloader [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.820; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-tru= nk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistribute= dZk2Test-controljetty-1365841882618/collection1/lib/classes/' to classloade= r [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.848; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.888; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.890; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:22.894; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-13 08:31:23.272; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-13 08:31:23.281; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-13 08:31:23.283; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-13 08:31:23.293; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:23.296; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:23.299; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-13 08:31:23.300; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-13 08:31:23.300; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-13 08:31:23.300; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-13 08:31:23.301; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-13 08:31:23.301; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-13 08:31:23.302; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-13 08:31:23.302; org.apache.solr.core.= SolrCore; [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/= Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.clou= d.BasicDistributedZk2Test-controljetty-1365841882618/collection1/, dataDir= =3D./org.apache.solr.cloud.BasicDistributedZk2Test-1365841882374/control/da= ta/ [junit4:junit4] 1> INFO - 2013-04-13 08:31:23.302; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@586d17fe [junit4:junit4] 1> INFO - 2013-04-13 08:31:23.302; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-13 08:31:23.303; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.B= asicDistributedZk2Test-1365841882374/control/data [junit4:junit4] 1> INFO - 2013-04-13 08:31:23.303; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D./org.apache.solr.= cloud.BasicDistributedZk2Test-1365841882374/control/data/index/ [junit4:junit4] 1> WARN - 2013-04-13 08:31:23.303; org.apache.solr.core.= SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.Basic= DistributedZk2Test-1365841882374/control/data/index' doesn't exist. Creatin= g new index... [junit4:junit4] 1> INFO - 2013-04-13 08:31:23.304; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.B= asicDistributedZk2Test-1365841882374/control/data/index [junit4:junit4] 1> INFO - 2013-04-13 08:31:23.305; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@7e9d3dca lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@5e296512),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-13 08:31:23.305; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-13 08:31:23.307; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-13 08:31:23.307; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-13 08:31:23.308; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-13 08:31:23.308; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-13 08:31:23.308; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-13 08:31:23.308; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-13 08:31:23.309; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-13 08:31:23.309; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-13 08:31:23.309; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-13 08:31:23.312; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-13 08:31:23.314; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@439dc4b6 main [junit4:junit4] 1> INFO - 2013-04-13 08:31:23.314; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D./org.apache.solr.cloud.Bas= icDistributedZk2Test-1365841882374/control/data/tlog [junit4:junit4] 1> INFO - 2013-04-13 08:31:23.315; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-13 08:31:23.315; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-13 08:31:23.317; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@439dc4b6 main{Stan= dardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-13 08:31:23.318; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Ddown [junit4:junit4] 1> INFO - 2013-04-13 08:31:23.318; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-13 08:31:24.320; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:24.320; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D1 message=3D{ [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "base_url":"http://127.0.0.1:33218", [junit4:junit4] 1> "core_node_name":null, [junit4:junit4] 1> "numShards":"1", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"control_collection", [junit4:junit4] 1> "shard":null, [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "node_name":"127.0.0.1:33218_", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "state":"down"} [junit4:junit4] 1> INFO - 2013-04-13 08:31:24.321; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Create collection control_collection with nu= mShards 1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:24.321; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Assigning new node to shard=3Dshard1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:24.324; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 1) [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.319; org.apache.solr.core.= CoreContainer; registering core: collection1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.320; org.apache.solr.cloud= .ZkController; Register replica - core:collection1 address:http://127.0.0.1= :33218 collection:control_collection shard:shard1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.320; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/control_collection/leader_elec= t/shard1/election [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.325; org.apache.solr.cloud= .ShardLeaderElectionContext; Running the leader process. [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.327; org.apache.solr.cloud= .ShardLeaderElectionContext; Enough replicas found to continue. [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.327; org.apache.solr.cloud= .ShardLeaderElectionContext; I may be the new leader - try and sync [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.327; org.apache.solr.cloud= .SyncStrategy; Sync replicas to http://127.0.0.1:33218/collection1/ [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.327; org.apache.solr.cloud= .SyncStrategy; Sync Success - now sync replicas to me [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.327; org.apache.solr.cloud= .SyncStrategy; http://127.0.0.1:33218/collection1/ has no replicas [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.328; org.apache.solr.cloud= .ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:33218/co= llection1/ [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.328; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/control_collection/leaders/sha= rd1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.828; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.834; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 1) [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.884; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:33218/collection1/ and leader is htt= p://127.0.0.1:33218/collection1/ [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.884; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dcollection1 baseURL=3Dhttp://= 127.0.0.1:33218 [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.884; org.apache.solr.cloud= .ZkController; I am the leader, no recovery necessary [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.885; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Dactive [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.885; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.886; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.887; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/mnt/ssd/jenkins/workspace/Lucene-Solr-tr= unk-Linux/solr/build/solr-core/test/J1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.888; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.888; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.891; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config: [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.892; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.893; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@36ef00d2 name:ZooKeeperConnection Watcher:127.0.0.1:46527/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.894; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.895; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.897; org.apache.solr.cloud= .ChaosMonkey; monkey: init - expire sessions:true cause connection loss:tru= e [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.955; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.957; org.eclipse.jetty.ser= ver.AbstractConnector; Started SelectChannelConnector@127.0.0.1:41906 [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.958; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.958; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.959; org.apache.solr.core.= SolrResourceLoader; 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-1365841885898 [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.959; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/w= orkspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.= solr.cloud.BasicDistributedZk2Test-jetty1-1365841885898/solr.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.959; org.apache.solr.core.= CoreContainer; New CoreContainer 273201753 [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.960; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/wor= kspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.so= lr.cloud.BasicDistributedZk2Test-jetty1-1365841885898/' [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.960; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins= /workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apach= e.solr.cloud.BasicDistributedZk2Test-jetty1-1365841885898/' [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.979; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.979; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.980; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.980; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.980; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.981; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.981; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.981; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.981; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.982; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D120000&connTimeout=3D1= 5000&retry=3Dfalse [junit4:junit4] 1> INFO - 2013-04-13 08:31:25.987; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-13 08:31:26.002; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:46527/solr [junit4:junit4] 1> INFO - 2013-04-13 08:31:26.002; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-13 08:31:26.003; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-13 08:31:26.006; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@66f4d0ae name:ZooKeeperConnection Watcher:127.0.0.1:46527 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-13 08:31:26.006; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-13 08:31:26.008; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D500&maxConnectionsPerHost=3D16&socketTimeout=3D120000&connTimeout=3D150= 00 [junit4:junit4] 1> INFO - 2013-04-13 08:31:26.011; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-13 08:31:26.013; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@633c36e name:ZooKeeperConnection Watcher:127.0.0.1:46527/solr got ev= ent WatchedEvent state:SyncConnected type:None path:null path:null type:Non= e [junit4:junit4] 1> INFO - 2013-04-13 08:31:26.013; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-13 08:31:26.016; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.019; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:419= 06_ [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.020; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:41906_ [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.022; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 1) [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.023; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (2) [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.024; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (2) [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.024; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (2) [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.028; org.apache.solr.core.= CoreContainer; Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/= jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./or= g.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1365841885898/collection= 1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.029; org.apache.solr.cloud= .ZkController; Check for collection zkNode:collection1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.029; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.030; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/collection1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.031; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins= /workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apach= e.solr.cloud.BasicDistributedZk2Test-jetty1-1365841885898/collection1/' [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.031; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-tru= nk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistribute= dZk2Test-jetty1-1365841885898/collection1/lib/README' to classloader [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.032; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-tru= nk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistribute= dZk2Test-jetty1-1365841885898/collection1/lib/classes/' to classloader [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.056; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.089; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.090; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.094; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.338; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.338; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D1 message=3D{ [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "base_url":"http://127.0.0.1:33218", [junit4:junit4] 1> "core_node_name":"127.0.0.1:33218__collection1", [junit4:junit4] 1> "numShards":"1", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"control_collection", [junit4:junit4] 1> "shard":"shard1", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "node_name":"127.0.0.1:33218_", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "state":"active"} [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.342; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 2) [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.342; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 2) [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.342; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 2) [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.416; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.422; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.424; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.435; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.438; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.441; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-13 08:31:27.442; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-13 08:31:27.443; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.443; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-13 08:31:27.444; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-13 08:31:27.444; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.445; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.445; org.apache.solr.core.= SolrCore; [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/= Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.clou= d.BasicDistributedZk2Test-jetty1-1365841885898/collection1/, dataDir=3D./or= g.apache.solr.cloud.BasicDistributedZk2Test-1365841882374/jetty1/ [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.445; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@586d17fe [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.445; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.446; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.B= asicDistributedZk2Test-1365841882374/jetty1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.446; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D./org.apache.solr.= cloud.BasicDistributedZk2Test-1365841882374/jetty1/index/ [junit4:junit4] 1> WARN - 2013-04-13 08:31:27.446; org.apache.solr.core.= SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.Basic= DistributedZk2Test-1365841882374/jetty1/index' doesn't exist. Creating new = index... [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.446; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.B= asicDistributedZk2Test-1365841882374/jetty1/index [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.448; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@55b24ffc lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@17541e98),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.448; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.450; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.450; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.450; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.451; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.451; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.451; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.451; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.452; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.452; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.454; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.456; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@4a3d4b8c main [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.457; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D./org.apache.solr.cloud.Bas= icDistributedZk2Test-1365841882374/jetty1/tlog [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.457; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.457; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.461; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@4a3d4b8c main{Stan= dardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.463; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Ddown [junit4:junit4] 1> INFO - 2013-04-13 08:31:27.464; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-13 08:31:28.845; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:28.846; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "base_url":"http://127.0.0.1:41906", [junit4:junit4] 1> "core_node_name":null, [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard":null, [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "node_name":"127.0.0.1:41906_", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "state":"down"} [junit4:junit4] 1> INFO - 2013-04-13 08:31:28.846; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Create collection collection1 with numShards= 2 [junit4:junit4] 1> INFO - 2013-04-13 08:31:28.846; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Assigning new node to shard=3Dshard2 [junit4:junit4] 1> INFO - 2013-04-13 08:31:28.850; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 2) [junit4:junit4] 1> INFO - 2013-04-13 08:31:28.850; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 2) [junit4:junit4] 1> INFO - 2013-04-13 08:31:28.850; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 2) [junit4:junit4] 1> INFO - 2013-04-13 08:31:29.465; org.apache.solr.core.= CoreContainer; registering core: collection1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:29.465; org.apache.solr.cloud= .ZkController; Register replica - core:collection1 address:http://127.0.0.1= :41906 collection:collection1 shard:shard2 [junit4:junit4] 1> INFO - 2013-04-13 08:31:29.466; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1/leader_elect/shard= 2/election [junit4:junit4] 1> INFO - 2013-04-13 08:31:29.471; org.apache.solr.cloud= .ShardLeaderElectionContext; Running the leader process. [junit4:junit4] 1> INFO - 2013-04-13 08:31:29.473; org.apache.solr.cloud= .ShardLeaderElectionContext; Enough replicas found to continue. [junit4:junit4] 1> INFO - 2013-04-13 08:31:29.473; org.apache.solr.cloud= .ShardLeaderElectionContext; I may be the new leader - try and sync [junit4:junit4] 1> INFO - 2013-04-13 08:31:29.473; org.apache.solr.cloud= .SyncStrategy; Sync replicas to http://127.0.0.1:41906/collection1/ [junit4:junit4] 1> INFO - 2013-04-13 08:31:29.473; org.apache.solr.cloud= .SyncStrategy; Sync Success - now sync replicas to me [junit4:junit4] 1> INFO - 2013-04-13 08:31:29.474; org.apache.solr.cloud= .SyncStrategy; http://127.0.0.1:41906/collection1/ has no replicas [junit4:junit4] 1> INFO - 2013-04-13 08:31:29.474; org.apache.solr.cloud= .ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:41906/co= llection1/ [junit4:junit4] 1> INFO - 2013-04-13 08:31:29.474; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1/leaders/shard2 [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.354; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.361; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 2) [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.361; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 2) [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.361; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 2) [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.382; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:41906/collection1/ and leader is htt= p://127.0.0.1:41906/collection1/ [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.382; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dcollection1 baseURL=3Dhttp://= 127.0.0.1:41906 [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.382; org.apache.solr.cloud= .ZkController; I am the leader, no recovery necessary [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.383; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Dactive [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.383; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.384; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.385; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/mnt/ssd/jenkins/workspace/Lucene-Solr-tr= unk-Linux/solr/build/solr-core/test/J1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.386; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.386; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.447; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.452; org.eclipse.jetty.ser= ver.AbstractConnector; Started SelectChannelConnector@127.0.0.1:60382 [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.453; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.453; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.454; org.apache.solr.core.= SolrResourceLoader; 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-1365841890389 [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.454; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/w= orkspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.= solr.cloud.BasicDistributedZk2Test-jetty2-1365841890389/solr.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.454; org.apache.solr.core.= CoreContainer; New CoreContainer 1997989546 [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.455; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/wor= kspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.so= lr.cloud.BasicDistributedZk2Test-jetty2-1365841890389/' [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.455; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins= /workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apach= e.solr.cloud.BasicDistributedZk2Test-jetty2-1365841890389/' [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.475; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.476; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.476; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.477; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.477; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.477; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.478; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.478; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.478; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.479; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D120000&connTimeout=3D1= 5000&retry=3Dfalse [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.486; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.500; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:46527/solr [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.501; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.502; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.503; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@4faded3c name:ZooKeeperConnection Watcher:127.0.0.1:46527 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.504; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.505; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D500&maxConnectionsPerHost=3D16&socketTimeout=3D120000&connTimeout=3D150= 00 [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.508; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.509; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@13792602 name:ZooKeeperConnection Watcher:127.0.0.1:46527/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.510; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-13 08:31:30.512; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.515; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:603= 82_ [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.516; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:60382_ [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.518; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 2) [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.518; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 2) [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.518; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 2) [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.519; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.520; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.520; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.521; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.523; org.apache.solr.core.= CoreContainer; Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/= jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./or= g.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1365841890389/collection= 1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.524; org.apache.solr.cloud= .ZkController; Check for collection zkNode:collection1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.524; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.524; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/collection1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.525; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins= /workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apach= e.solr.cloud.BasicDistributedZk2Test-jetty2-1365841890389/collection1/' [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.526; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-tru= nk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistribute= dZk2Test-jetty2-1365841890389/collection1/lib/README' to classloader [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.526; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-tru= nk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistribute= dZk2Test-jetty2-1365841890389/collection1/lib/classes/' to classloader [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.549; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.582; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.584; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.589; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.865; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.866; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "base_url":"http://127.0.0.1:41906", [junit4:junit4] 1> "core_node_name":"127.0.0.1:41906__collection1", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard":"shard2", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "node_name":"127.0.0.1:41906_", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "state":"active"} [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.869; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.869; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.869; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.869; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.921; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.927; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.929; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.943; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.946; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.949; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-13 08:31:31.950; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-13 08:31:31.950; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.950; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-13 08:31:31.951; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-13 08:31:31.952; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.952; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.952; org.apache.solr.core.= SolrCore; [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/= Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.clou= d.BasicDistributedZk2Test-jetty2-1365841890389/collection1/, dataDir=3D./or= g.apache.solr.cloud.BasicDistributedZk2Test-1365841882374/jetty2/ [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.952; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@586d17fe [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.953; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.953; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.B= asicDistributedZk2Test-1365841882374/jetty2 [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.953; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D./org.apache.solr.= cloud.BasicDistributedZk2Test-1365841882374/jetty2/index/ [junit4:junit4] 1> WARN - 2013-04-13 08:31:31.953; org.apache.solr.core.= SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.Basic= DistributedZk2Test-1365841882374/jetty2/index' doesn't exist. Creating new = index... [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.954; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.B= asicDistributedZk2Test-1365841882374/jetty2/index [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.955; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@cbd4925 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFac= tory@7163bf69),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.955; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.957; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.957; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.957; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.958; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.958; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.958; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.959; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.959; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.959; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.961; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.964; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@3d5c1015 main [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.964; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D./org.apache.solr.cloud.Bas= icDistributedZk2Test-1365841882374/jetty2/tlog [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.964; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.965; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.968; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@3d5c1015 main{Stan= dardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.969; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Ddown [junit4:junit4] 1> INFO - 2013-04-13 08:31:31.969; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-13 08:31:33.373; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:33.374; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "base_url":"http://127.0.0.1:60382", [junit4:junit4] 1> "core_node_name":null, [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard":null, [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "node_name":"127.0.0.1:60382_", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "state":"down"} [junit4:junit4] 1> INFO - 2013-04-13 08:31:33.374; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Collection already exists with numShards=3D2 [junit4:junit4] 1> INFO - 2013-04-13 08:31:33.374; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Assigning new node to shard=3Dshard1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:33.378; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-13 08:31:33.378; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-13 08:31:33.378; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-13 08:31:33.379; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-13 08:31:33.970; org.apache.solr.core.= CoreContainer; registering core: collection1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:33.971; org.apache.solr.cloud= .ZkController; Register replica - core:collection1 address:http://127.0.0.1= :60382 collection:collection1 shard:shard1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:33.971; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1/leader_elect/shard= 1/election [junit4:junit4] 1> INFO - 2013-04-13 08:31:33.979; org.apache.solr.cloud= .ShardLeaderElectionContext; Running the leader process. [junit4:junit4] 1> INFO - 2013-04-13 08:31:33.981; org.apache.solr.cloud= .ShardLeaderElectionContext; Enough replicas found to continue. [junit4:junit4] 1> INFO - 2013-04-13 08:31:33.981; org.apache.solr.cloud= .ShardLeaderElectionContext; I may be the new leader - try and sync [junit4:junit4] 1> INFO - 2013-04-13 08:31:33.981; org.apache.solr.cloud= .SyncStrategy; Sync replicas to http://127.0.0.1:60382/collection1/ [junit4:junit4] 1> INFO - 2013-04-13 08:31:33.982; org.apache.solr.cloud= .SyncStrategy; Sync Success - now sync replicas to me [junit4:junit4] 1> INFO - 2013-04-13 08:31:33.982; org.apache.solr.cloud= .SyncStrategy; http://127.0.0.1:60382/collection1/ has no replicas [junit4:junit4] 1> INFO - 2013-04-13 08:31:33.982; org.apache.solr.cloud= .ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:60382/co= llection1/ [junit4:junit4] 1> INFO - 2013-04-13 08:31:33.982; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1/leaders/shard1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:34.886; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:34.892; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-13 08:31:34.892; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-13 08:31:34.892; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-13 08:31:34.892; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-13 08:31:34.938; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:60382/collection1/ and leader is htt= p://127.0.0.1:60382/collection1/ [junit4:junit4] 1> INFO - 2013-04-13 08:31:34.938; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dcollection1 baseURL=3Dhttp://= 127.0.0.1:60382 [junit4:junit4] 1> INFO - 2013-04-13 08:31:34.938; org.apache.solr.cloud= .ZkController; I am the leader, no recovery necessary [junit4:junit4] 1> INFO - 2013-04-13 08:31:34.938; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Dactive [junit4:junit4] 1> INFO - 2013-04-13 08:31:34.939; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-13 08:31:34.940; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:34.941; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/mnt/ssd/jenkins/workspace/Lucene-Solr-tr= unk-Linux/solr/build/solr-core/test/J1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:34.941; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-13 08:31:34.941; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-13 08:31:35.010; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-13 08:31:35.012; org.eclipse.jetty.ser= ver.AbstractConnector; Started SelectChannelConnector@127.0.0.1:45108 [junit4:junit4] 1> INFO - 2013-04-13 08:31:35.013; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-13 08:31:35.013; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-13 08:31:35.014; org.apache.solr.core.= SolrResourceLoader; 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-1365841894944 [junit4:junit4] 1> INFO - 2013-04-13 08:31:35.014; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/w= orkspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.= solr.cloud.BasicDistributedZk2Test-jetty3-1365841894944/solr.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:35.015; org.apache.solr.core.= CoreContainer; New CoreContainer 1280338650 [junit4:junit4] 1> INFO - 2013-04-13 08:31:35.015; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/wor= kspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.so= lr.cloud.BasicDistributedZk2Test-jetty3-1365841894944/' [junit4:junit4] 1> INFO - 2013-04-13 08:31:35.016; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins= /workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apach= e.solr.cloud.BasicDistributedZk2Test-jetty3-1365841894944/' [junit4:junit4] 1> INFO - 2013-04-13 08:31:35.036; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-13 08:31:35.036; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-13 08:31:35.037; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-13 08:31:35.037; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:35.037; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-13 08:31:35.038; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-13 08:31:35.038; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-13 08:31:35.038; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:35.039; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-13 08:31:35.039; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D120000&connTimeout=3D1= 5000&retry=3Dfalse [junit4:junit4] 1> INFO - 2013-04-13 08:31:35.045; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-13 08:31:35.061; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:46527/solr [junit4:junit4] 1> INFO - 2013-04-13 08:31:35.061; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-13 08:31:35.062; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-13 08:31:35.063; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@2e1aad2a name:ZooKeeperConnection Watcher:127.0.0.1:46527 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-13 08:31:35.064; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-13 08:31:35.067; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D500&maxConnectionsPerHost=3D16&socketTimeout=3D120000&connTimeout=3D150= 00 [junit4:junit4] 1> INFO - 2013-04-13 08:31:35.070; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-13 08:31:35.072; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@3ec25446 name:ZooKeeperConnection Watcher:127.0.0.1:46527/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-04-13 08:31:35.072; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-13 08:31:35.075; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.079; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:451= 08_ [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.080; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:45108_ [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.082; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.082; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.083; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.083; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.084; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.084; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.084; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.085; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.085; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.089; org.apache.solr.core.= CoreContainer; Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/= jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./or= g.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1365841894944/collection= 1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.090; org.apache.solr.cloud= .ZkController; Check for collection zkNode:collection1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.090; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.090; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/collection1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.091; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins= /workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apach= e.solr.cloud.BasicDistributedZk2Test-jetty3-1365841894944/collection1/' [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.092; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-tru= nk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistribute= dZk2Test-jetty3-1365841894944/collection1/lib/README' to classloader [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.092; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-tru= nk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistribute= dZk2Test-jetty3-1365841894944/collection1/lib/classes/' to classloader [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.115; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.150; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.152; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.158; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.396; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.396; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "base_url":"http://127.0.0.1:60382", [junit4:junit4] 1> "core_node_name":"127.0.0.1:60382__collection1", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard":"shard1", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "node_name":"127.0.0.1:60382_", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "state":"active"} [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.399; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.399; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.400; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.399; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.399; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.494; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.500; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.502; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.514; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.517; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.521; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-13 08:31:36.522; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-13 08:31:36.523; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.523; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-13 08:31:36.524; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-13 08:31:36.524; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.525; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.525; org.apache.solr.core.= SolrCore; [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/= Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.clou= d.BasicDistributedZk2Test-jetty3-1365841894944/collection1/, dataDir=3D./or= g.apache.solr.cloud.BasicDistributedZk2Test-1365841882374/jetty3/ [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.525; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@586d17fe [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.526; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.526; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.B= asicDistributedZk2Test-1365841882374/jetty3 [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.527; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D./org.apache.solr.= cloud.BasicDistributedZk2Test-1365841882374/jetty3/index/ [junit4:junit4] 1> WARN - 2013-04-13 08:31:36.527; org.apache.solr.core.= SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.Basic= DistributedZk2Test-1365841882374/jetty3/index' doesn't exist. Creating new = index... [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.527; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.B= asicDistributedZk2Test-1365841882374/jetty3/index [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.529; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@2a25b3e9 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@474efe48),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.530; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.532; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.532; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.533; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.534; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.534; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.535; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.535; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.535; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.536; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.539; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.542; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@3f4347b4 main [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.542; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D./org.apache.solr.cloud.Bas= icDistributedZk2Test-1365841882374/jetty3/tlog [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.542; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.543; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.546; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@3f4347b4 main{Stan= dardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.548; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Ddown [junit4:junit4] 1> INFO - 2013-04-13 08:31:36.548; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-13 08:31:37.906; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:37.907; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "base_url":"http://127.0.0.1:45108", [junit4:junit4] 1> "core_node_name":null, [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard":null, [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "node_name":"127.0.0.1:45108_", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "state":"down"} [junit4:junit4] 1> INFO - 2013-04-13 08:31:37.907; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Collection already exists with numShards=3D2 [junit4:junit4] 1> INFO - 2013-04-13 08:31:37.907; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Assigning new node to shard=3Dshard2 [junit4:junit4] 1> INFO - 2013-04-13 08:31:37.910; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:37.910; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:37.911; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:37.911; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:37.911; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.549; org.apache.solr.core.= CoreContainer; registering core: collection1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.549; org.apache.solr.cloud= .ZkController; Register replica - core:collection1 address:http://127.0.0.1= :45108 collection:collection1 shard:shard2 [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.552; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:45108/collection1/ and leader is htt= p://127.0.0.1:41906/collection1/ [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.552; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dcollection1 baseURL=3Dhttp://= 127.0.0.1:45108 [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.552; org.apache.solr.cloud= .ZkController; Core needs to recover:collection1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.552; org.apache.solr.updat= e.DefaultSolrCoreState; Running recovery - first canceling any ongoing reco= very [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.553; org.apache.solr.cloud= .RecoveryStrategy; Starting recovery process. core=3Dcollection1 recoverin= gAfterStartup=3Dtrue [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.553; org.apache.solr.cloud= .RecoveryStrategy; ###### startupVersions=3D[] [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.553; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.553; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Drecovering [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.554; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.554; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/mnt/ssd/jenkins/workspace/Lucene-Solr-tr= unk-Linux/solr/build/solr-core/test/J1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.555; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.555; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.555; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.560; org.apache.solr.handl= er.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:45108_= _collection1, state: recovering, checkLive: true, onlyIfLeader: true [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.626; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.628; org.eclipse.jetty.ser= ver.AbstractConnector; Started SelectChannelConnector@127.0.0.1:42379 [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.629; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.629; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.630; org.apache.solr.core.= SolrResourceLoader; 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-1365841898559 [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.630; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/w= orkspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.= solr.cloud.BasicDistributedZk2Test-jetty4-1365841898559/solr.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.630; org.apache.solr.core.= CoreContainer; New CoreContainer 1124106716 [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.631; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/wor= kspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.so= lr.cloud.BasicDistributedZk2Test-jetty4-1365841898559/' [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.631; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins= /workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apach= e.solr.cloud.BasicDistributedZk2Test-jetty4-1365841898559/' [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.652; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.653; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.653; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.653; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.654; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.654; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.654; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.655; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.655; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.656; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D120000&connTimeout=3D1= 5000&retry=3Dfalse [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.661; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.671; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:46527/solr [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.672; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.673; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.680; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@5367a2f0 name:ZooKeeperConnection Watcher:127.0.0.1:46527 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.680; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.682; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D500&maxConnectionsPerHost=3D16&socketTimeout=3D120000&connTimeout=3D150= 00 [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.684; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.686; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@4b5d9232 name:ZooKeeperConnection Watcher:127.0.0.1:46527/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.686; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-13 08:31:38.689; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.415; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.416; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "base_url":"http://127.0.0.1:45108", [junit4:junit4] 1> "core_node_name":"127.0.0.1:45108__collection1", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard":"shard2", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "node_name":"127.0.0.1:45108_", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "state":"recovering"} [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.420; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.420; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.420; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.420; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.420; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.420; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.560; org.apache.solr.handl= er.admin.CoreAdminHandler; Waited coreNodeName: 127.0.0.1:45108__collection= 1, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds. [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.561; org.apache.solr.servl= et.SolrDispatchFilter; [admin] webapp=3Dnull path=3D/admin/cores params=3D{= nodeName=3D127.0.0.1:45108_&version=3D2&wt=3Djavabin&checkLive=3Dtrue&core= =3Dcollection1&coreNodeName=3D127.0.0.1:45108__collection1&state=3Drecoveri= ng&onlyIfLeader=3Dtrue&action=3DPREPRECOVERY} status=3D0 QTime=3D1001=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.692; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:423= 79_ [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.693; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:42379_ [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.694; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.694; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.695; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.695; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.695; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.695; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.695; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.695; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.696; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.696; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.696; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.697; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.700; org.apache.solr.core.= CoreContainer; Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/= jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./or= g.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1365841898559/collection= 1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.701; org.apache.solr.cloud= .ZkController; Check for collection zkNode:collection1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.701; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.702; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/collection1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.703; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins= /workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apach= e.solr.cloud.BasicDistributedZk2Test-jetty4-1365841898559/collection1/' [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.703; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-tru= nk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistribute= dZk2Test-jetty4-1365841898559/collection1/lib/README' to classloader [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.703; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-tru= nk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistribute= dZk2Test-jetty4-1365841898559/collection1/lib/classes/' to classloader [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.730; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.763; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.764; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:39.768; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.096; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.106; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.108; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.124; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.128; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.133; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-13 08:31:40.134; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-13 08:31:40.135; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.135; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-13 08:31:40.136; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-13 08:31:40.137; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.137; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.137; org.apache.solr.core.= SolrCore; [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/= Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.clou= d.BasicDistributedZk2Test-jetty4-1365841898559/collection1/, dataDir=3D./or= g.apache.solr.cloud.BasicDistributedZk2Test-1365841882374/jetty4/ [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.137; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@586d17fe [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.138; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.138; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.B= asicDistributedZk2Test-1365841882374/jetty4 [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.138; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D./org.apache.solr.= cloud.BasicDistributedZk2Test-1365841882374/jetty4/index/ [junit4:junit4] 1> WARN - 2013-04-13 08:31:40.139; org.apache.solr.core.= SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.Basic= DistributedZk2Test-1365841882374/jetty4/index' doesn't exist. Creating new = index... [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.139; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.B= asicDistributedZk2Test-1365841882374/jetty4/index [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.140; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@6be14617 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@12b599d0),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.141; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.142; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.143; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.143; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.144; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.144; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.144; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.145; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.145; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.146; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.148; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.150; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@11a1d5f8 main [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.151; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D./org.apache.solr.cloud.Bas= icDistributedZk2Test-1365841882374/jetty4/tlog [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.151; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.152; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.155; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@11a1d5f8 main{Stan= dardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.156; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Ddown [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.156; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.925; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.925; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "base_url":"http://127.0.0.1:42379", [junit4:junit4] 1> "core_node_name":null, [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard":null, [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "node_name":"127.0.0.1:42379_", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "state":"down"} [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.926; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Collection already exists with numShards=3D2 [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.926; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Assigning new node to shard=3Dshard1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.929; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.929; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.930; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.929; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.929; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:40.929; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.158; org.apache.solr.core.= CoreContainer; registering core: collection1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.158; org.apache.solr.cloud= .ZkController; Register replica - core:collection1 address:http://127.0.0.1= :42379 collection:collection1 shard:shard1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.160; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:42379/collection1/ and leader is htt= p://127.0.0.1:60382/collection1/ [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.161; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dcollection1 baseURL=3Dhttp://= 127.0.0.1:42379 [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.161; org.apache.solr.cloud= .ZkController; Core needs to recover:collection1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.161; org.apache.solr.updat= e.DefaultSolrCoreState; Running recovery - first canceling any ongoing reco= very [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.161; org.apache.solr.cloud= .RecoveryStrategy; Starting recovery process. core=3Dcollection1 recoverin= gAfterStartup=3Dtrue [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.162; org.apache.solr.cloud= .RecoveryStrategy; ###### startupVersions=3D[] [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.162; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.162; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Drecovering [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.162; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.163; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/mnt/ssd/jenkins/workspace/Lucene-Solr-tr= unk-Linux/solr/build/solr-core/test/J1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.164; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.163; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.164; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.169; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.169; org.apache.solr.handl= er.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:42379_= _collection1, state: recovering, checkLive: true, onlyIfLeader: true [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.170; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.173; org.apache.solr.core.= CoreContainer; Creating SolrCore 'onenodecollectioncore' using instanceDir:= /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1365841885898/= onenodecollectioncore [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.174; org.apache.solr.cloud= .ZkController; Check for collection zkNode:onenodecollection [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.174; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:onenodecollection [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.175; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.176; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.176; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/onenodecollection [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.178; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/onenodecollection [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.179; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins= /workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apach= e.solr.cloud.BasicDistributedZk2Test-jetty1-1365841885898/onenodecollection= core/' [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.204; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.247; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.249; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.253; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.562; org.apache.solr.cloud= .RecoveryStrategy; Attempting to PeerSync from http://127.0.0.1:41906/colle= ction1/ core=3Dcollection1 - recoveringAfterStartup=3Dtrue [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.563; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dcollection1 url=3Dhttp://127.0.0.1:45108 START= replicas=3D[http://127.0.0.1:41906/collection1/] nUpdates=3D100 [junit4:junit4] 1> WARN - 2013-04-13 08:31:41.563; org.apache.solr.updat= e.PeerSync; no frame of reference to tell of we've missed updates [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.564; org.apache.solr.cloud= .RecoveryStrategy; PeerSync Recovery was not successful - trying replicatio= n. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.564; org.apache.solr.cloud= .RecoveryStrategy; Starting Replication Recovery. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.564; org.apache.solr.cloud= .RecoveryStrategy; Begin buffering updates. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.564; org.apache.solr.updat= e.UpdateLog; Starting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog= =3Dnull} [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.564; org.apache.solr.cloud= .RecoveryStrategy; Attempting to replicate from http://127.0.0.1:41906/coll= ection1/. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.564; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.569; org.apache.solr.core.= SolrCore; [collection1] webapp=3D path=3D/get params=3D{version=3D2&getVers= ions=3D100&wt=3Djavabin&distrib=3Dfalse&qt=3D/get} status=3D0 QTime=3D0=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.572; org.apache.solr.updat= e.DirectUpdateHandler2; start commit{,optimize=3Dfalse,openSearcher=3Dfalse= ,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse,prepareCommi= t=3Dfalse} [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.574; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@55b24ffc lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@17541e98),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.574; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.575; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@55b24ffc lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@17541e98),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@55b24ffc lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@17541e98),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_2] [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.575; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 2[segments_2] [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.576; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@231f8cf3 realtime [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.576; org.apache.solr.updat= e.DirectUpdateHandler2; end_commit_flush [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.576; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{version=3D2&openSearcher=3Dfalse&commit_end_point=3Dtrue&wt=3Djavabin= &waitSearcher=3Dtrue&commit=3Dtrue&softCommit=3Dfalse} {commit=3D} 0 4 [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.577; org.apache.solr.handl= er.ReplicationHandler; Commits will be reserved for 10000 [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.578; org.apache.solr.handl= er.SnapPuller; No value set for 'pollInterval'. Timer Task not started. [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.580; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.582; org.apache.solr.handl= er.ReplicationHandler; Commits will be reserved for 10000 [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.582; org.apache.solr.core.= SolrCore; [collection1] webapp=3D path=3D/replication params=3D{version=3D2= &wt=3Djavabin&command=3Dindexversion&qt=3D/replication} status=3D0 QTime=3D= 4=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.583; org.apache.solr.handl= er.SnapPuller; Master's generation: 2 [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.583; org.apache.solr.handl= er.SnapPuller; Slave's generation: 1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.583; org.apache.solr.handl= er.SnapPuller; Starting replication process [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.585; org.apache.solr.core.= SolrCore; [collection1] webapp=3D path=3D/replication params=3D{version=3D2= &wt=3Djavabin&generation=3D2&command=3Dfilelist&qt=3D/replication} status= =3D0 QTime=3D0=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.586; org.apache.solr.handl= er.SnapPuller; Number of files in latest index in master: 1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.586; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.587; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.B= asicDistributedZk2Test-1365841882374/jetty3/index.20130413033141586 [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.587; org.apache.solr.handl= er.SnapPuller; Starting download to MockDirWrapper(org.apache.lucene.store.= RAMDirectory@6bb54805 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFac= tory@47f772db) fullCopy=3Dfalse [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.588; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.589; org.apache.solr.core.= SolrCore; [collection1] webapp=3D path=3D/replication params=3D{checksum=3D= true&wt=3Dfilestream&file=3Dsegments_2&generation=3D2&command=3Dfilecontent= &qt=3D/replication} status=3D0 QTime=3D0=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.599; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.602; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.605; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-13 08:31:41.607; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-13 08:31:41.607; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.607; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-13 08:31:41.608; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-13 08:31:41.609; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.609; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.609; org.apache.solr.core.= SolrCore; [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-1365841885898/onenodecollectionc= ore/, dataDir=3D/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/bui= ld/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1365841882374/oneno= decollection/ [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.610; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@586d17fe [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.610; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.611; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspac= e/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDist= ributedZk2Test-1365841882374/onenodecollection [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.611; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D/mnt/ssd/jenkins/w= orkspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-Ba= sicDistributedZk2Test-1365841882374/onenodecollection/index/ [junit4:junit4] 1> WARN - 2013-04-13 08:31:41.611; org.apache.solr.core.= SolrCore; [onenodecollectioncore] Solr index directory '/mnt/ssd/jenkins/wo= rkspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-Bas= icDistributedZk2Test-1365841882374/onenodecollection/index' doesn't exist. = Creating new index... [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.612; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspac= e/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDist= ributedZk2Test-1365841882374/onenodecollection/index [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.613; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@5f85fc75 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@1e68da87),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.614; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.616; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.616; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.617; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.617; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.618; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.618; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.618; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.619; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.619; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.622; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.624; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@393760b7 main [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.625; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D/mnt/ssd/jenkins/workspace/= Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistri= butedZk2Test-1365841882374/onenodecollection/tlog [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.625; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.626; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.629; org.apache.solr.core.= SolrCore; [onenodecollectioncore] Registered new searcher Searcher@393760b7= main{StandardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.631; org.apache.solr.cloud= .ZkController; publishing core=3Donenodecollectioncore state=3Ddown [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.640; org.apache.solr.handl= er.SnapPuller; Total time taken for download : 0 secs [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.641; org.apache.solr.updat= e.DefaultSolrCoreState; Creating new IndexWriter... [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.641; org.apache.solr.updat= e.DefaultSolrCoreState; Waiting until IndexWriter is unused... core=3Dcolle= ction1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.642; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits:num=3D2 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@2a25b3e9 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@474efe48),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@2a25b3e9 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@474efe48),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_2] [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.642; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 2[segments_2] [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.642; org.apache.solr.updat= e.DefaultSolrCoreState; New IndexWriter is ready to be used. [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.643; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@1aa37a8e main [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.643; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@1aa37a8e main{Stan= dardDirectoryReader(segments_2:1:nrt)} [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.644; org.apache.solr.core.= CachingDirectoryFactory; looking to close ./org.apache.solr.cloud.BasicDist= ributedZk2Test-1365841882374/jetty3/index.20130413033141586 [CachedDir<>] [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.644; org.apache.solr.core.= CachingDirectoryFactory; Closing directory: ./org.apache.solr.cloud.BasicDi= stributedZk2Test-1365841882374/jetty3/index.20130413033141586 [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.644; org.apache.solr.core.= CachingDirectoryFactory; Removing directory before core close: ./org.apache= .solr.cloud.BasicDistributedZk2Test-1365841882374/jetty3/index.201304130331= 41586 [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.644; org.apache.solr.cloud= .RecoveryStrategy; No replay needed. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.644; org.apache.solr.cloud= .RecoveryStrategy; Replication Recovery was successful - registering as Act= ive. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.644; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Dactive [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.644; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-13 08:31:41.646; org.apache.solr.cloud= .RecoveryStrategy; Finished recovery process. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:42.433; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:42.434; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "base_url":"http://127.0.0.1:42379", [junit4:junit4] 1> "core_node_name":"127.0.0.1:42379__collection1", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard":"shard1", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "node_name":"127.0.0.1:42379_", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "state":"recovering"} [junit4:junit4] 1> INFO - 2013-04-13 08:31:42.437; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D1 message=3D{ [junit4:junit4] 1> "roles":"none", [junit4:junit4] 1> "base_url":"http://127.0.0.1:41906", [junit4:junit4] 1> "core_node_name":null, [junit4:junit4] 1> "numShards":"1", [junit4:junit4] 1> "core":"onenodecollectioncore", [junit4:junit4] 1> "collection":"onenodecollection", [junit4:junit4] 1> "shard":null, [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "node_name":"127.0.0.1:41906_", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "state":"down"} [junit4:junit4] 1> INFO - 2013-04-13 08:31:42.437; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Create collection onenodecollection with num= Shards 1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:42.437; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Assigning new node to shard=3Dshard1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:42.440; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "base_url":"http://127.0.0.1:45108", [junit4:junit4] 1> "core_node_name":"127.0.0.1:45108__collection1", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard":"shard2", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "node_name":"127.0.0.1:45108_", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "state":"active"} [junit4:junit4] 1> INFO - 2013-04-13 08:31:42.443; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:42.443; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:42.443; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:42.443; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:42.443; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:42.443; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:42.632; org.apache.solr.core.= CoreContainer; registering core: onenodecollectioncore [junit4:junit4] 1> INFO - 2013-04-13 08:31:42.632; org.apache.solr.cloud= .ZkController; Register replica - core:onenodecollectioncore address:http:/= /127.0.0.1:41906 collection:onenodecollection shard:shard1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:42.633; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/onenodecollection/leader_elect= /shard1/election [junit4:junit4] 1> INFO - 2013-04-13 08:31:42.639; org.apache.solr.cloud= .ShardLeaderElectionContext; Running the leader process. [junit4:junit4] 1> INFO - 2013-04-13 08:31:42.641; org.apache.solr.cloud= .ShardLeaderElectionContext; Enough replicas found to continue. [junit4:junit4] 1> INFO - 2013-04-13 08:31:42.642; org.apache.solr.cloud= .ShardLeaderElectionContext; I may be the new leader - try and sync [junit4:junit4] 1> INFO - 2013-04-13 08:31:42.642; org.apache.solr.cloud= .SyncStrategy; Sync replicas to http://127.0.0.1:41906/onenodecollectioncor= e/ [junit4:junit4] 1> INFO - 2013-04-13 08:31:42.642; org.apache.solr.cloud= .SyncStrategy; Sync Success - now sync replicas to me [junit4:junit4] 1> INFO - 2013-04-13 08:31:42.643; org.apache.solr.cloud= .SyncStrategy; http://127.0.0.1:41906/onenodecollectioncore/ has no replica= s [junit4:junit4] 1> INFO - 2013-04-13 08:31:42.643; org.apache.solr.cloud= .ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:41906/on= enodecollectioncore/ [junit4:junit4] 1> INFO - 2013-04-13 08:31:42.643; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/onenodecollection/leaders/shar= d1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:43.170; org.apache.solr.handl= er.admin.CoreAdminHandler; Waited coreNodeName: 127.0.0.1:42379__collection= 1, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds. [junit4:junit4] 1> INFO - 2013-04-13 08:31:43.170; org.apache.solr.servl= et.SolrDispatchFilter; [admin] webapp=3Dnull path=3D/admin/cores params=3D{= nodeName=3D127.0.0.1:42379_&version=3D2&wt=3Djavabin&checkLive=3Dtrue&core= =3Dcollection1&coreNodeName=3D127.0.0.1:42379__collection1&state=3Drecoveri= ng&onlyIfLeader=3Dtrue&action=3DPREPRECOVERY} status=3D0 QTime=3D2001=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:43.950; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:43.956; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:43.956; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:43.956; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:43.956; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:43.956; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:43.956; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:44.000; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:41906/onenodecollectioncore/ and lea= der is http://127.0.0.1:41906/onenodecollectioncore/ [junit4:junit4] 1> INFO - 2013-04-13 08:31:44.001; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Donenodecollectioncore baseURL= =3Dhttp://127.0.0.1:41906 [junit4:junit4] 1> INFO - 2013-04-13 08:31:44.001; org.apache.solr.cloud= .ZkController; I am the leader, no recovery necessary [junit4:junit4] 1> INFO - 2013-04-13 08:31:44.001; org.apache.solr.cloud= .ZkController; publishing core=3Donenodecollectioncore state=3Dactive [junit4:junit4] 1> INFO - 2013-04-13 08:31:44.003; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:44.004; org.apache.solr.servl= et.SolrDispatchFilter; [admin] webapp=3Dnull path=3D/admin/cores params=3D{= version=3D2&roles=3Dnone&wt=3Djavabin&numShards=3D1&name=3Donenodecollectio= ncore&collection=3Donenodecollection&dataDir=3D/mnt/ssd/jenkins/workspace/L= ucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistrib= utedZk2Test-1365841882374/onenodecollection&action=3DCREATE} status=3D0 QTi= me=3D2831=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:44.005; org.apache.solr.cloud= .AbstractDistribZkTestBase; Wait for recoveries to finish - collection: one= nodecollection failOnTimeout:true timeout (sec):230 [junit4:junit4] 1> INFO - 2013-04-13 08:31:44.005; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.007; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.171; org.apache.solr.cloud= .RecoveryStrategy; Attempting to PeerSync from http://127.0.0.1:60382/colle= ction1/ core=3Dcollection1 - recoveringAfterStartup=3Dtrue [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.172; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dcollection1 url=3Dhttp://127.0.0.1:42379 START= replicas=3D[http://127.0.0.1:60382/collection1/] nUpdates=3D100 [junit4:junit4] 1> WARN - 2013-04-13 08:31:45.172; org.apache.solr.updat= e.PeerSync; no frame of reference to tell of we've missed updates [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.172; org.apache.solr.cloud= .RecoveryStrategy; PeerSync Recovery was not successful - trying replicatio= n. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.172; org.apache.solr.cloud= .RecoveryStrategy; Starting Replication Recovery. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.173; org.apache.solr.cloud= .RecoveryStrategy; Begin buffering updates. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.173; org.apache.solr.updat= e.UpdateLog; Starting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog= =3Dnull} [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.173; org.apache.solr.cloud= .RecoveryStrategy; Attempting to replicate from http://127.0.0.1:60382/coll= ection1/. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.173; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.181; org.apache.solr.core.= SolrCore; [collection1] webapp=3D path=3D/get params=3D{version=3D2&getVers= ions=3D100&wt=3Djavabin&distrib=3Dfalse&qt=3D/get} status=3D0 QTime=3D0=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.184; org.apache.solr.updat= e.DirectUpdateHandler2; start commit{,optimize=3Dfalse,openSearcher=3Dfalse= ,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse,prepareCommi= t=3Dfalse} [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.185; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@cbd4925 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFac= tory@7163bf69),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.185; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.186; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@cbd4925 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFac= tory@7163bf69),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@cbd4925 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFac= tory@7163bf69),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_2] [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.186; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 2[segments_2] [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.187; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@13c9b3de realtime [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.187; org.apache.solr.updat= e.DirectUpdateHandler2; end_commit_flush [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.187; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{version=3D2&openSearcher=3Dfalse&commit_end_point=3Dtrue&wt=3Djavabin= &waitSearcher=3Dtrue&commit=3Dtrue&softCommit=3Dfalse} {commit=3D} 0 3 [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.188; org.apache.solr.handl= er.ReplicationHandler; Commits will be reserved for 10000 [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.188; org.apache.solr.handl= er.SnapPuller; No value set for 'pollInterval'. Timer Task not started. [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.189; org.apache.solr.handl= er.ReplicationHandler; Commits will be reserved for 10000 [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.190; org.apache.solr.core.= SolrCore; [collection1] webapp=3D path=3D/replication params=3D{version=3D2= &wt=3Djavabin&command=3Dindexversion&qt=3D/replication} status=3D0 QTime=3D= 1=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.190; org.apache.solr.handl= er.SnapPuller; Master's generation: 2 [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.190; org.apache.solr.handl= er.SnapPuller; Slave's generation: 1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.190; org.apache.solr.handl= er.SnapPuller; Starting replication process [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.192; org.apache.solr.core.= SolrCore; [collection1] webapp=3D path=3D/replication params=3D{version=3D2= &wt=3Djavabin&generation=3D2&command=3Dfilelist&qt=3D/replication} status= =3D0 QTime=3D0=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.193; org.apache.solr.handl= er.SnapPuller; Number of files in latest index in master: 1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.193; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.B= asicDistributedZk2Test-1365841882374/jetty4/index.20130413033145193 [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.194; org.apache.solr.handl= er.SnapPuller; Starting download to MockDirWrapper(org.apache.lucene.store.= RAMDirectory@612e317d lockFactory=3Dorg.apache.lucene.store.NativeFSLockFac= tory@4d2788e9) fullCopy=3Dfalse [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.196; org.apache.solr.core.= SolrCore; [collection1] webapp=3D path=3D/replication params=3D{checksum=3D= true&wt=3Dfilestream&file=3Dsegments_2&generation=3D2&command=3Dfilecontent= &qt=3D/replication} status=3D0 QTime=3D0=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.247; org.apache.solr.handl= er.SnapPuller; Total time taken for download : 0 secs [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.248; org.apache.solr.updat= e.DefaultSolrCoreState; Creating new IndexWriter... [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.248; org.apache.solr.updat= e.DefaultSolrCoreState; Waiting until IndexWriter is unused... core=3Dcolle= ction1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.250; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits:num=3D2 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@6be14617 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@12b599d0),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@6be14617 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@12b599d0),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_2] [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.250; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 2[segments_2] [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.251; org.apache.solr.updat= e.DefaultSolrCoreState; New IndexWriter is ready to be used. [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.251; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@727ab294 main [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.252; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@727ab294 main{Stan= dardDirectoryReader(segments_2:1:nrt)} [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.253; org.apache.solr.core.= CachingDirectoryFactory; looking to close ./org.apache.solr.cloud.BasicDist= ributedZk2Test-1365841882374/jetty4/index.20130413033145193 [CachedDir<>] [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.253; org.apache.solr.core.= CachingDirectoryFactory; Closing directory: ./org.apache.solr.cloud.BasicDi= stributedZk2Test-1365841882374/jetty4/index.20130413033145193 [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.253; org.apache.solr.core.= CachingDirectoryFactory; Removing directory before core close: ./org.apache= .solr.cloud.BasicDistributedZk2Test-1365841882374/jetty4/index.201304130331= 45193 [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.253; org.apache.solr.cloud= .RecoveryStrategy; No replay needed. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.254; org.apache.solr.cloud= .RecoveryStrategy; Replication Recovery was successful - registering as Act= ive. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.254; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Dactive [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.254; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.256; org.apache.solr.cloud= .RecoveryStrategy; Finished recovery process. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.462; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.463; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D1 message=3D{ [junit4:junit4] 1> "roles":"none", [junit4:junit4] 1> "base_url":"http://127.0.0.1:41906", [junit4:junit4] 1> "core_node_name":"127.0.0.1:41906__onenodecollection= core", [junit4:junit4] 1> "numShards":"1", [junit4:junit4] 1> "core":"onenodecollectioncore", [junit4:junit4] 1> "collection":"onenodecollection", [junit4:junit4] 1> "shard":"shard1", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "node_name":"127.0.0.1:41906_", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "state":"active"} [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.469; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "base_url":"http://127.0.0.1:42379", [junit4:junit4] 1> "core_node_name":"127.0.0.1:42379__collection1", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard":"shard1", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "node_name":"127.0.0.1:42379_", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "state":"active"} [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.475; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.475; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.476; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.476; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.475; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:45.475; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:46.009; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:46.010; org.apache.solr.cloud= .AbstractDistribZkTestBase; Recoveries finished - collection: onenodecollec= tion [junit4:junit4] 1> INFO - 2013-04-13 08:31:46.010; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-13 08:31:46.020; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-13 08:31:46.023; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@73bf6d4e name:ZooKeeperConnection Watcher:127.0.0.1:46527 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-13 08:31:46.023; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> / (2) [junit4:junit4] 1> DATA: [junit4:junit4] 1> =20 [junit4:junit4] 1> /zookeeper (1) [junit4:junit4] 1> DATA: [junit4:junit4] 1> =20 [junit4:junit4] 1> /solr (7) [junit4:junit4] 1> /solr/aliases.json (0) [junit4:junit4] 1> /solr/overseer (3) [junit4:junit4] 1> DATA: [junit4:junit4] 1> =20 [junit4:junit4] 1> /solr/overseer/queue-work (0) [junit4:junit4] 1> /solr/overseer/queue (0) [junit4:junit4] 1> /solr/overseer/collection-queue-work (0) [junit4:junit4] 1> /solr/live_nodes (5) [junit4:junit4] 1> /solr/live_nodes/127.0.0.1:33218_ (0) [junit4:junit4] 1> /solr/live_nodes/127.0.0.1:41906_ (0) [junit4:junit4] 1> /solr/live_nodes/127.0.0.1:60382_ (0) [junit4:junit4] 1> /solr/live_nodes/127.0.0.1:45108_ (0) [junit4:junit4] 1> /solr/live_nodes/127.0.0.1:42379_ (0) [junit4:junit4] 1> /solr/overseer_elect (2) [junit4:junit4] 1> /solr/overseer_elect/election (5) [junit4:junit4] 1> /solr/overseer_elect/election/89511813603459082-12= 7.0.0.1:45108_-n_0000000003 (0) [junit4:junit4] 1> /solr/overseer_elect/election/89511813603459075-12= 7.0.0.1:33218_-n_0000000000 (0) [junit4:junit4] 1> /solr/overseer_elect/election/89511813603459084-12= 7.0.0.1:42379_-n_0000000004 (0) [junit4:junit4] 1> /solr/overseer_elect/election/89511813603459080-12= 7.0.0.1:60382_-n_0000000002 (0) [junit4:junit4] 1> /solr/overseer_elect/election/89511813603459078-12= 7.0.0.1:41906_-n_0000000001 (0) [junit4:junit4] 1> /solr/overseer_elect/leader (0) [junit4:junit4] 1> DATA: [junit4:junit4] 1> {"id":"89511813603459075-127.0.0.1:33218_-n_000= 0000000"} [junit4:junit4] 1> /solr/clusterstate.json (0) [junit4:junit4] 1> DATA: [junit4:junit4] 1> { [junit4:junit4] 1> "onenodecollection":{ [junit4:junit4] 1> "router":"compositeId", [junit4:junit4] 1> "shards":{"shard1":{ [junit4:junit4] 1> "range":"80000000-7fffffff", [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "replicas":{"127.0.0.1:41906__onenodecol= lectioncore":{ [junit4:junit4] 1> "roles":"none", [junit4:junit4] 1> "base_url":"http://127.0.0.1:41906", [junit4:junit4] 1> "core":"onenodecollectioncore", [junit4:junit4] 1> "collection":"onenodecollection", [junit4:junit4] 1> "shard":"shard1", [junit4:junit4] 1> "node_name":"127.0.0.1:41906_", [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "leader":"true"}}}}}, [junit4:junit4] 1> "collection1":{ [junit4:junit4] 1> "router":"compositeId", [junit4:junit4] 1> "shards":{ [junit4:junit4] 1> "shard1":{ [junit4:junit4] 1> "range":"80000000-ffffffff", [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "replicas":{ [junit4:junit4] 1> "127.0.0.1:60382__collection1":{ [junit4:junit4] 1> "base_url":"http://127.0.0.1:60382", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard":"shard1", [junit4:junit4] 1> "node_name":"127.0.0.1:60382_", [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "leader":"true"}, [junit4:junit4] 1> "127.0.0.1:42379__collection1":{ [junit4:junit4] 1> "base_url":"http://127.0.0.1:42379", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard":"shard1", [junit4:junit4] 1> "node_name":"127.0.0.1:42379_", [junit4:junit4] 1> "state":"active"}}}, [junit4:junit4] 1> "shard2":{ [junit4:junit4] 1> "range":"0-7fffffff", [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "replicas":{ [junit4:junit4] 1> "127.0.0.1:41906__collection1":{ [junit4:junit4] 1> "base_url":"http://127.0.0.1:41906", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard":"shard2", [junit4:junit4] 1> "node_name":"127.0.0.1:41906_", [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "leader":"true"}, [junit4:junit4] 1> "127.0.0.1:45108__collection1":{ [junit4:junit4] 1> "base_url":"http://127.0.0.1:45108", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard":"shard2", [junit4:junit4] 1> "node_name":"127.0.0.1:45108_", [junit4:junit4] 1> "state":"active"}}}}}, [junit4:junit4] 1> "control_collection":{ [junit4:junit4] 1> "router":"compositeId", [junit4:junit4] 1> "shards":{"shard1":{ [junit4:junit4] 1> "range":"80000000-7fffffff", [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "replicas":{"127.0.0.1:33218__collection= 1":{ [junit4:junit4] 1> "base_url":"http://127.0.0.1:33218", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"control_collection", [junit4:junit4] 1> "shard":"shard1", [junit4:junit4] 1> "node_name":"127.0.0.1:33218_", [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "leader":"true"}}}}}} [junit4:junit4] 1> /solr/collections (3) [junit4:junit4] 1> /solr/collections/onenodecollection (2) [junit4:junit4] 1> DATA: [junit4:junit4] 1> { [junit4:junit4] 1> "configName":"conf1", [junit4:junit4] 1> "router":"compositeId"} [junit4:junit4] 1> /solr/collections/onenodecollection/leaders (1) [junit4:junit4] 1> /solr/collections/onenodecollection/leaders/shard= 1 (0) [junit4:junit4] 1> DATA: [junit4:junit4] 1> { [junit4:junit4] 1> "base_url":"http://127.0.0.1:41906", [junit4:junit4] 1> "core":"onenodecollectioncore", [junit4:junit4] 1> "node_name":"127.0.0.1:41906_"} [junit4:junit4] 1> /solr/collections/onenodecollection/leader_elect (= 1) [junit4:junit4] 1> /solr/collections/onenodecollection/leader_elect/= shard1 (1) [junit4:junit4] 1> /solr/collections/onenodecollection/leader_elect= /shard1/election (1) [junit4:junit4] 1> /solr/collections/onenodecollection/leader_elec= t/shard1/election/89511813603459078-127.0.0.1:41906__onenodecollectioncore-= n_0000000000 (0) [junit4:junit4] 1> /solr/collections/collection1 (3) [junit4:junit4] 1> DATA: [junit4:junit4] 1> {"configName":"conf1"} [junit4:junit4] 1> /solr/collections/collection1/shards (0) [junit4:junit4] 1> /solr/collections/collection1/leaders (2) [junit4:junit4] 1> /solr/collections/collection1/leaders/shard1 (0) [junit4:junit4] 1> DATA: [junit4:junit4] 1> { [junit4:junit4] 1> "base_url":"http://127.0.0.1:60382", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "node_name":"127.0.0.1:60382_"} [junit4:junit4] 1> /solr/collections/collection1/leaders/shard2 (0) [junit4:junit4] 1> DATA: [junit4:junit4] 1> { [junit4:junit4] 1> "base_url":"http://127.0.0.1:41906", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "node_name":"127.0.0.1:41906_"} [junit4:junit4] 1> /solr/collections/collection1/leader_elect (2) [junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard1= (1) [junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard= 1/election (2) [junit4:junit4] 1> /solr/collections/collection1/leader_elect/shar= d1/election/89511813603459084-127.0.0.1:42379__collection1-n_0000000001 (0) [junit4:junit4] 1> /solr/collections/collection1/leader_elect/shar= d1/election/89511813603459080-127.0.0.1:60382__collection1-n_0000000000 (0) [junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard2= (1) [junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard= 2/election (2) [junit4:junit4] 1> /solr/collections/collection1/leader_elect/shar= d2/election/89511813603459078-127.0.0.1:41906__collection1-n_0000000000 (0) [junit4:junit4] 1> /solr/collections/collection1/leader_elect/shar= d2/election/89511813603459082-127.0.0.1:45108__collection1-n_0000000001 (0) [junit4:junit4] 1> /solr/collections/control_collection (3) [junit4:junit4] 1> DATA: [junit4:junit4] 1> {"configName":"conf1"} [junit4:junit4] 1> /solr/collections/control_collection/shards (0) [junit4:junit4] 1> /solr/collections/control_collection/leaders (1) [junit4:junit4] 1> /solr/collections/control_collection/leaders/shar= d1 (0) [junit4:junit4] 1> DATA: [junit4:junit4] 1> { [junit4:junit4] 1> "base_url":"http://127.0.0.1:33218", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "node_name":"127.0.0.1:33218_"} [junit4:junit4] 1> /solr/collections/control_collection/leader_elect = (1) [junit4:junit4] 1> /solr/collections/control_collection/leader_elect= /shard1 (1) [junit4:junit4] 1> /solr/collections/control_collection/leader_elec= t/shard1/election (1) [junit4:junit4] 1> /solr/collections/control_collection/leader_ele= ct/shard1/election/89511813603459075-127.0.0.1:33218__collection1-n_0000000= 000 (0) [junit4:junit4] 1> /solr/configs (1) [junit4:junit4] 1> /solr/configs/conf1 (9) [junit4:junit4] 1> /solr/configs/conf1/currency.xml (0) [junit4:junit4] 1> DATA: ...supressed... [junit4:junit4] 1> /solr/configs/conf1/stopwords.txt (0) [junit4:junit4] 1> DATA: ...supressed... [junit4:junit4] 1> /solr/configs/conf1/open-exchange-rates.json (0) [junit4:junit4] 1> DATA: [junit4:junit4] 1> { [junit4:junit4] 1> "disclaimer": "This data is not real, it was= synthetically created to match currency.xml. It is modeled after the data= format available from openexchangerates.org. See https://openexchangerate= s.org/documentation for details", [junit4:junit4] 1> "license": "http://www.apache.org/licenses/L= ICENSE-2.0", [junit4:junit4] 1> "timestamp": 1332070464, [junit4:junit4] 1> =20 [junit4:junit4] 1> =20 [junit4:junit4] 1> "IMPORTANT NOTE": "In order for tests to wor= k, this data must be kept in sync with ./currency.xml", [junit4:junit4] 1> =20 [junit4:junit4] 1> =20 [junit4:junit4] 1> "base": "USD", [junit4:junit4] 1> "rates": { [junit4:junit4] 1> "USD": 1, [junit4:junit4] 1> "JPY": 81.29, [junit4:junit4] 1> "EUR": 2.5, [junit4:junit4] 1> "GBP": 0.5, [junit4:junit4] 1> "MXN": 2.0 [junit4:junit4] 1> } [junit4:junit4] 1> } [junit4:junit4] 1> =20 [junit4:junit4] 1> /solr/configs/conf1/solrconfig.xml (0) [junit4:junit4] 1> DATA: ...supressed... [junit4:junit4] 1> /solr/configs/conf1/schema.xml (0) [junit4:junit4] 1> DATA: ...supressed... [junit4:junit4] 1> /solr/configs/conf1/old_synonyms.txt (0) [junit4:junit4] 1> DATA: ...supressed... [junit4:junit4] 1> /solr/configs/conf1/mapping-ISOLatin1Accent.txt (0= ) [junit4:junit4] 1> DATA: ...supressed... [junit4:junit4] 1> /solr/configs/conf1/synonyms.txt (0) [junit4:junit4] 1> DATA: ...supressed... [junit4:junit4] 1> /solr/configs/conf1/protwords.txt (0) [junit4:junit4] 1> DATA: ...supressed... [junit4:junit4] 1>=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:46.060; org.apache.solr.cloud= .ChaosMonkey; monkey: stop shard! 33218 [junit4:junit4] 1> INFO - 2013-04-13 08:31:46.061; org.apache.solr.core.= CoreContainer; Shutting down CoreContainer instance=3D1944595115 [junit4:junit4] 1> INFO - 2013-04-13 08:31:46.984; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:46.984; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3Dnull message=3D{ [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "base_url":"http://127.0.0.1:33218", [junit4:junit4] 1> "core_node_name":"127.0.0.1:33218__collection1", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"control_collection", [junit4:junit4] 1> "shard":"shard1", [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "node_name":"127.0.0.1:33218_", [junit4:junit4] 1> "state":"down"} [junit4:junit4] 1> INFO - 2013-04-13 08:31:46.988; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:46.988; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:46.988; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:46.988; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:46.988; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.062; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Ddown [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.063; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.065; org.apache.solr.core.= SolrCore; [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@6b0= 82599 [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.069; org.apache.solr.updat= e.DirectUpdateHandler2; closing DirectUpdateHandler2{commits=3D0,autocommit= s=3D0,soft autocommits=3D0,optimizes=3D0,rollbacks=3D0,expungeDeletes=3D0,d= ocsPending=3D0,adds=3D0,deletesById=3D0,deletesByQuery=3D0,errors=3D0,cumul= ative_adds=3D0,cumulative_deletesById=3D0,cumulative_deletesByQuery=3D0,cum= ulative_errors=3D0} [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.070; org.apache.solr.updat= e.SolrCoreState; Closing SolrCoreState [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.070; org.apache.solr.updat= e.DefaultSolrCoreState; SolrCoreState ref count has reached 0 - closing Ind= exWriter [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.070; org.apache.solr.updat= e.DefaultSolrCoreState; closing IndexWriter with IndexWriterCloser [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.071; org.apache.solr.core.= SolrCore; [collection1] Closing main searcher on request. [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.072; org.apache.solr.core.= CachingDirectoryFactory; Closing MockDirectoryFactory - 2 directories curre= ntly being tracked [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.072; org.apache.solr.core.= CachingDirectoryFactory; looking to close ./org.apache.solr.cloud.BasicDist= ributedZk2Test-1365841882374/control/data/index [CachedDir<>] [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.072; org.apache.solr.core.= CachingDirectoryFactory; Closing directory: ./org.apache.solr.cloud.BasicDi= stributedZk2Test-1365841882374/control/data/index [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.073; org.apache.solr.core.= CachingDirectoryFactory; looking to close ./org.apache.solr.cloud.BasicDist= ributedZk2Test-1365841882374/control/data [CachedDir<>] [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.073; org.apache.solr.core.= CachingDirectoryFactory; Closing directory: ./org.apache.solr.cloud.BasicDi= stributedZk2Test-1365841882374/control/data [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.074; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; According to ZK I (id=3D89511813603459075-12= 7.0.0.1:33218_-n_0000000000) am no longer a leader. [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.075; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 5) [junit4:junit4] 1> WARN - 2013-04-13 08:31:48.076; org.apache.zookeeper.= server.NIOServerCnxn; caught end of stream exception [junit4:junit4] 1> EndOfStreamException: Unable to read additional data f= rom client sessionid 0x13e02852d090003, likely client has closed socket [junit4:junit4] 1> =09at org.apache.zookeeper.server.NIOServerCnxn.doIO(N= IOServerCnxn.java:220) [junit4:junit4] 1> =09at org.apache.zookeeper.server.NIOServerCnxnFactory= .run(NIOServerCnxnFactory.java:208) [junit4:junit4] 1> =09at java.lang.Thread.run(Thread.java:722) [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.076; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.076; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.076; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.076; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.077; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.077; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.077; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.080; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer_elect/leader [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.081; org.apache.solr.cloud= .Overseer; Overseer (id=3D89511813603459078-127.0.0.1:41906_-n_0000000001) = starting [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.085; org.apache.solr.cloud= .OverseerCollectionProcessor; Process current queue of collection creations [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.085; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Starting to work on the main queue [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.089; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.089; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "base_url":"http://127.0.0.1:33218", [junit4:junit4] 1> "core_node_name":"127.0.0.1:33218__collection1", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"control_collection", [junit4:junit4] 1> "shard":"shard1", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "node_name":"127.0.0.1:33218_", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "state":"down"} [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.092; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.092; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.092; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.093; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.098; org.eclipse.jetty.ser= ver.handler.ContextHandler; stopped o.e.j.s.ServletContextHandler{/,null} [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.149; org.apache.solr.cloud= .ChaosMonkey; monkey: stop shard! 41906 [junit4:junit4] 1> INFO - 2013-04-13 08:31:48.150; org.apache.solr.core.= CoreContainer; Shutting down CoreContainer instance=3D273201753 [junit4:junit4] 1> WARN - 2013-04-13 08:31:49.375; org.apache.solr.commo= n.cloud.ZkStateReader$3; ZooKeeper watch triggered, but Solr cannot talk to= ZK [junit4:junit4] 1> INFO - 2013-04-13 08:31:49.375; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 5) [junit4:junit4] 1> WARN - 2013-04-13 08:31:49.376; org.apache.solr.commo= n.cloud.ZkStateReader$2; ZooKeeper watch triggered, but Solr cannot talk to= ZK [junit4:junit4] 1> INFO - 2013-04-13 08:31:49.597; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-13 08:31:49.598; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3Dnull message=3D{ [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "base_url":"http://127.0.0.1:41906", [junit4:junit4] 1> "core_node_name":"127.0.0.1:41906__collection1", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard":"shard2", [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "node_name":"127.0.0.1:41906_", [junit4:junit4] 1> "state":"down"} [junit4:junit4] 1> INFO - 2013-04-13 08:31:49.601; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3Dnull message=3D{ [junit4:junit4] 1> "roles":"none", [junit4:junit4] 1> "base_url":"http://127.0.0.1:41906", [junit4:junit4] 1> "core_node_name":"127.0.0.1:41906__onenodecollection= core", [junit4:junit4] 1> "core":"onenodecollectioncore", [junit4:junit4] 1> "collection":"onenodecollection", [junit4:junit4] 1> "shard":"shard1", [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "node_name":"127.0.0.1:41906_", [junit4:junit4] 1> "state":"down"} [junit4:junit4] 1> INFO - 2013-04-13 08:31:49.604; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-13 08:31:49.605; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusters [...truncated too long message...] 4] 1> "state":"down"} [junit4:junit4] 1> INFO - 2013-04-13 08:31:53.909; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 1) [junit4:junit4] 1> WARN - 2013-04-13 08:31:53.932; org.apache.solr.commo= n.cloud.ZkStateReader$3; ZooKeeper watch triggered, but Solr cannot talk to= ZK [junit4:junit4] 1> INFO - 2013-04-13 08:31:53.933; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 3) [junit4:junit4] 1> WARN - 2013-04-13 08:31:53.933; org.apache.solr.commo= n.cloud.ZkStateReader$2; ZooKeeper watch triggered, but Solr cannot talk to= ZK [junit4:junit4] 1> INFO - 2013-04-13 08:31:53.952; org.apache.solr.cloud= .ChaosMonkey; monkey: stop shard! 42379 [junit4:junit4] 1> INFO - 2013-04-13 08:31:53.953; org.apache.solr.core.= CoreContainer; Shutting down CoreContainer instance=3D1124106716 [junit4:junit4] 1> INFO - 2013-04-13 08:31:54.954; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Ddown [junit4:junit4] 1> INFO - 2013-04-13 08:31:54.954; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-13 08:31:54.957; org.apache.solr.core.= SolrCore; [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@4ed= 3d8b0 [junit4:junit4] 1> INFO - 2013-04-13 08:31:54.963; org.apache.solr.updat= e.DirectUpdateHandler2; closing DirectUpdateHandler2{commits=3D0,autocommit= s=3D0,soft autocommits=3D0,optimizes=3D0,rollbacks=3D0,expungeDeletes=3D0,d= ocsPending=3D0,adds=3D0,deletesById=3D0,deletesByQuery=3D0,errors=3D0,cumul= ative_adds=3D0,cumulative_deletesById=3D0,cumulative_deletesByQuery=3D0,cum= ulative_errors=3D0} [junit4:junit4] 1> INFO - 2013-04-13 08:31:54.965; org.apache.solr.updat= e.SolrCoreState; Closing SolrCoreState [junit4:junit4] 1> INFO - 2013-04-13 08:31:54.965; org.apache.solr.updat= e.DefaultSolrCoreState; SolrCoreState ref count has reached 0 - closing Ind= exWriter [junit4:junit4] 1> INFO - 2013-04-13 08:31:54.966; org.apache.solr.updat= e.DefaultSolrCoreState; closing IndexWriter with IndexWriterCloser [junit4:junit4] 1> INFO - 2013-04-13 08:31:54.968; org.apache.solr.core.= SolrCore; [collection1] Closing main searcher on request. [junit4:junit4] 1> INFO - 2013-04-13 08:31:54.968; org.apache.solr.core.= CachingDirectoryFactory; Closing MockDirectoryFactory - 2 directories curre= ntly being tracked [junit4:junit4] 1> INFO - 2013-04-13 08:31:54.968; org.apache.solr.core.= CachingDirectoryFactory; looking to close ./org.apache.solr.cloud.BasicDist= ributedZk2Test-1365841882374/jetty4 [CachedDir<= >] [junit4:junit4] 1> INFO - 2013-04-13 08:31:54.969; org.apache.solr.core.= CachingDirectoryFactory; Closing directory: ./org.apache.solr.cloud.BasicDi= stributedZk2Test-1365841882374/jetty4 [junit4:junit4] 1> INFO - 2013-04-13 08:31:54.969; org.apache.solr.core.= CachingDirectoryFactory; looking to close ./org.apache.solr.cloud.BasicDist= ributedZk2Test-1365841882374/jetty4/index [CachedDir<>] [junit4:junit4] 1> INFO - 2013-04-13 08:31:54.969; org.apache.solr.core.= CachingDirectoryFactory; Closing directory: ./org.apache.solr.cloud.BasicDi= stributedZk2Test-1365841882374/jetty4/index [junit4:junit4] 1> INFO - 2013-04-13 08:31:54.970; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; According to ZK I (id=3D89511813603459084-12= 7.0.0.1:42379_-n_0000000004) am no longer a leader. [junit4:junit4] 1> INFO - 2013-04-13 08:31:54.993; org.eclipse.jetty.ser= ver.handler.ContextHandler; stopped o.e.j.s.ServletContextHandler{/,null} [junit4:junit4] 1> WARN - 2013-04-13 08:31:55.039; org.apache.solr.commo= n.cloud.ZkStateReader$3; ZooKeeper watch triggered, but Solr cannot talk to= ZK [junit4:junit4] 1> INFO - 2013-04-13 08:31:55.039; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 2) [junit4:junit4] 1> WARN - 2013-04-13 08:31:55.039; org.apache.solr.commo= n.cloud.ZkStateReader$2; ZooKeeper watch triggered, but Solr cannot talk to= ZK [junit4:junit4] 1> INFO - 2013-04-13 08:31:55.055; org.apache.solr.SolrT= estCaseJ4; ###Ending testDistribSearch [junit4:junit4] 1> INFO - 2013-04-13 08:31:55.058; org.apache.solr.cloud= .ZkTestServer; connecting to 127.0.0.1:46527 46527 [junit4:junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-So= lr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2T= est-1365841882374 [junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=3DBasicDist= ributedZk2Test -Dtests.method=3DtestDistribSearch -Dtests.seed=3D9E1AB61E22= 43A826 -Dtests.multiplier=3D3 -Dtests.slow=3Dtrue -Dtests.locale=3Dis_IS -D= tests.timezone=3DJamaica -Dtests.file.encoding=3DUTF-8 [junit4:junit4] ERROR 32.8s J1 | BasicDistributedZk2Test.testDistribSearc= h <<< [junit4:junit4] > Throwable #1: org.apache.solr.common.SolrException: Se= rver at http://127.0.0.1:60382/onenodecollectioncore returned non ok status= :404, message:Can not find: /onenodecollectioncore/update [junit4:junit4] > =09at __randomizedtesting.SeedInfo.seed([9E1AB61E2243A= 826:1FFC3806551CC81A]:0) [junit4:junit4] > =09at org.apache.solr.client.solrj.impl.HttpSolrServer= .request(HttpSolrServer.java:375) [junit4:junit4] > =09at org.apache.solr.client.solrj.impl.HttpSolrServer= .request(HttpSolrServer.java:181) [junit4:junit4] > =09at org.apache.solr.client.solrj.request.AbstractUpd= ateRequest.process(AbstractUpdateRequest.java:117) [junit4:junit4] > =09at org.apache.solr.client.solrj.SolrServer.add(Solr= Server.java:116) [junit4:junit4] > =09at org.apache.solr.client.solrj.SolrServer.add(Solr= Server.java:102) [junit4:junit4] > =09at org.apache.solr.cloud.BasicDistributedZk2Test.te= stNodeWithoutCollectionForwarding(BasicDistributedZk2Test.java:197) [junit4:junit4] > =09at org.apache.solr.cloud.BasicDistributedZk2Test.do= Test(BasicDistributedZk2Test.java:89) [junit4:junit4] > =09at org.apache.solr.BaseDistributedSearchTestCase.te= stDistribSearch(BaseDistributedSearchTestCase.java:806) [junit4:junit4] > =09at java.lang.Thread.run(Thread.java:722) [junit4:junit4] 1> INFO - 2013-04-13 08:31:55.174; org.apache.solr.SolrT= estCaseJ4; ###deleteCore [junit4:junit4] 2> 32816 T1419 ccr.ThreadLeakControl.checkThreadLeaks WAR= NING Will linger awaiting termination of 2 leaked thread(s). [junit4:junit4] 1> WARN - 2013-04-13 08:31:56.271; org.apache.solr.commo= n.cloud.ZkStateReader$3; ZooKeeper watch triggered, but Solr cannot talk to= ZK [junit4:junit4] 1> INFO - 2013-04-13 08:31:56.272; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 1) [junit4:junit4] 1> WARN - 2013-04-13 08:31:56.272; org.apache.solr.commo= n.cloud.ZkStateReader$2; ZooKeeper watch triggered, but Solr cannot talk to= ZK [junit4:junit4] 2> NOTE: test params are: codec=3DCheapBastard, sim=3DRan= domSimilarityProvider(queryNorm=3Dtrue,coord=3Dcrazy): {}, locale=3Dis_IS, = timezone=3DJamaica [junit4:junit4] 2> NOTE: Linux 3.2.0-40-generic amd64/Oracle Corporation = 1.8.0-ea (64-bit)/cpus=3D8,threads=3D2,free=3D113104248,total=3D208007168 [junit4:junit4] 2> NOTE: All tests run in this JVM: [TestJmxIntegration, = ShardSplitTest, TestMultiCoreConfBootstrap, TestElisionMultitermQuery, Curr= encyFieldXmlFileTest, TestCodecSupport, XsltUpdateRequestHandlerTest, Clust= erStateTest, CoreContainerCoreInitFailuresTest, TestRecovery, DocumentAnaly= sisRequestHandlerTest, StatsComponentTest, TimeZoneUtilsTest, DirectSolrSpe= llCheckerTest, TestComponentsName, TestNumberUtils, NoCacheHeaderTest, Test= Filtering, TestCoreDiscovery, TestRTGBase, SampleTest, TestPostingsSolrHigh= lighter, TestUtils, IndexReaderFactoryTest, CopyFieldTest, SuggesterWFSTTes= t, TestDynamicFieldCollectionResource, PingRequestHandlerTest, TestSolrXMLS= erializer, URLClassifyProcessorTest, TestBinaryResponseWriter, DisMaxReques= tHandlerTest, TestFoldingMultitermQuery, BadCopyFieldTest, SortByFunctionTe= st, FullSolrCloudDistribCmdsTest, OpenCloseCoreStressTest, TestZkChroot, Te= stIndexingPerformance, TestBinaryField, SpellCheckCollatorTest, ChaosMonkey= SafeLeaderTest, DebugComponentTest, TestRandomFaceting, DistanceFunctionTes= t, BasicDistributedZk2Test] [junit4:junit4] Completed on J1 in 34.10s, 1 test, 1 error <<< FAILURES! [...truncated 620 lines...] BUILD FAILED /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:375: The follo= wing error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:355: The follo= wing error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The follow= ing 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:43= 8: The following error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:= 1231: The following error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:= 875: There were test failures: 289 suites, 1200 tests, 1 error, 13 ignored = (7 assumptions) Total time: 35 minutes 8 seconds Build step 'Invoke Ant' marked build as failure Archiving artifacts Recording test results Description set: Java: 64bit/jdk1.8.0-ea-b84 -XX:+UseConcMarkSweepGC Email was triggered for: Failure Sending email for trigger: Failure ------=_Part_84_1577224863.1365842490593 Content-Type: text/plain; charset=us-ascii --------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org For additional commands, e-mail: dev-help@lucene.apache.org ------=_Part_84_1577224863.1365842490593--