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 C3E9EF36B for ; Mon, 1 Apr 2013 02:38:41 +0000 (UTC) Received: (qmail 32857 invoked by uid 500); 1 Apr 2013 02:38:39 -0000 Delivered-To: apmail-lucene-dev-archive@lucene.apache.org Received: (qmail 32729 invoked by uid 500); 1 Apr 2013 02:38:39 -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 32713 invoked by uid 99); 1 Apr 2013 02:38:39 -0000 Received: from nike.apache.org (HELO nike.apache.org) (192.87.106.230) by apache.org (qpsmtpd/0.29) with ESMTP; Mon, 01 Apr 2013 02:38:39 +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; Mon, 01 Apr 2013 02:38:16 +0000 Received: from serv1 (localhost.localdomain [127.0.0.1]) by mail.sd-datasolutions.de (Postfix) with ESMTP id 3F43514AA031 for ; Mon, 1 Apr 2013 02:37:55 +0000 (UTC) Date: Mon, 1 Apr 2013 02:33:46 +0000 (UTC) From: Policeman Jenkins Server To: dev@lucene.apache.org Message-ID: <2024641132.49.1364783875227.JavaMail.jenkins@serv1.sd-datasolutions.de> Subject: [JENKINS] Lucene-Solr-4.x-Linux (32bit/jdk1.8.0-ea-b82) - Build # 4911 - Failure! MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="----=_Part_48_2133941408.1364783626537" X-Jenkins-Job: Lucene-Solr-4.x-Linux X-Jenkins-Result: FAILURE X-Virus-Checked: Checked by ClamAV on apache.org ------=_Part_48_2133941408.1364783626537 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/4911/ Java: 32bit/jdk1.8.0-ea-b82 -client -XX:+UseParallelGC 1 tests failed. REGRESSION: org.apache.solr.cloud.BasicDistributedZk2Test.testDistribSearc= h Error Message: Server at http://127.0.0.1:53193/fbvf/q/onenodecollectioncore returned non = ok status:404, message:Can not find: /fbvf/q/onenodecollectioncore/update Stack Trace: org.apache.solr.common.SolrException: Server at http://127.0.0.1:53193/fbvf= /q/onenodecollectioncore returned non ok status:404, message:Can not find: = /fbvf/q/onenodecollectioncore/update =09at __randomizedtesting.SeedInfo.seed([D899F88634ED3C:813E17E0F16B8D00]: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 9413 lines...] [junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test [junit4:junit4] 1> INFO - 2013-04-01 02:24:55.873; org.apache.solr.BaseD= istributedSearchTestCase; Setting hostContext system property: /fbvf/q [junit4:junit4] 1> INFO - 2013-04-01 02:24:55.878; org.apache.solr.SolrT= estCaseJ4; ###Starting testDistribSearch [junit4:junit4] 1> INFO - 2013-04-01 02:24:55.879; 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-01 02:24:55.879; org.apache.solr.cloud= .ZkTestServer$ZKServerMain; Starting server [junit4:junit4] 1> INFO - 2013-04-01 02:24:55.880; org.apache.zookeeper.= server.ZooKeeperServer; tickTime set to 1000 [junit4:junit4] 1> INFO - 2013-04-01 02:24:55.880; org.apache.zookeeper.= server.ZooKeeperServer; minSessionTimeout set to -1 [junit4:junit4] 1> INFO - 2013-04-01 02:24:55.880; org.apache.zookeeper.= server.ZooKeeperServer; maxSessionTimeout set to -1 [junit4:junit4] 1> INFO - 2013-04-01 02:24:55.881; org.apache.zookeeper.= server.NIOServerCnxnFactory; binding to port 0.0.0.0/0.0.0.0:0 [junit4:junit4] 1> INFO - 2013-04-01 02:24:55.882; org.apache.zookeeper.= server.persistence.FileTxnSnapLog; Snapshotting: 0x0 to /mnt/ssd/jenkins/wo= rkspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.sol= r.cloud.BasicDistributedZk2Test-1364783095878/zookeeper/server1/data/versio= n-2/snapshot.0 [junit4:junit4] 1> INFO - 2013-04-01 02:24:55.979; org.apache.solr.cloud= .ZkTestServer; start zk server on port:58488 [junit4:junit4] 1> INFO - 2013-04-01 02:24:55.980; org.apache.zookeeper.= ZooKeeper; Initiating client connection, connectString=3D127.0.0.1:58488 se= ssionTimeout=3D10000 watcher=3Dorg.apache.solr.common.cloud.ConnectionManag= er@dee340 [junit4:junit4] 1> INFO - 2013-04-01 02:24:55.981; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-01 02:24:55.981; org.apache.zookeeper.= ClientCnxn$SendThread; Opening socket connection to server localhost.locald= omain/127.0.0.1:58488. Will not attempt to authenticate using SASL (access = denied ("javax.security.auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 1> INFO - 2013-04-01 02:24:55.982; org.apache.zookeeper.= ClientCnxn$SendThread; Socket connection established to localhost.localdoma= in/127.0.0.1:58488, initiating session [junit4:junit4] 1> INFO - 2013-04-01 02:24:55.982; org.apache.zookeeper.= server.NIOServerCnxnFactory; Accepted socket connection from /127.0.0.1:492= 62 [junit4:junit4] 1> INFO - 2013-04-01 02:24:55.983; org.apache.zookeeper.= server.ZooKeeperServer; Client attempting to establish new session at /127.= 0.0.1:49262 [junit4:junit4] 1> INFO - 2013-04-01 02:24:55.983; org.apache.zookeeper.= server.persistence.FileTxnLog; Creating new log file: log.1 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.057; org.apache.zookeeper.= server.ZooKeeperServer; Established session 0x13dc369604a0000 with negotiat= ed timeout 10000 for client /127.0.0.1:49262 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.057; org.apache.zookeeper.= ClientCnxn$SendThread; Session establishment complete on server localhost.l= ocaldomain/127.0.0.1:58488, sessionid =3D 0x13dc369604a0000, negotiated tim= eout =3D 10000 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.058; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@dee340 name:ZooKeeperConnection Watcher:127.0.0.1:58488 got event Wa= tchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.058; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.059; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /solr [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.062; org.apache.zookeeper.= server.PrepRequestProcessor; Processed session termination for sessionid: 0= x13dc369604a0000 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.062; org.apache.zookeeper.= ZooKeeper; Session: 0x13dc369604a0000 closed [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.063; org.apache.zookeeper.= server.NIOServerCnxn; Closed socket connection for client /127.0.0.1:49262 = which had sessionid 0x13dc369604a0000 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.062; org.apache.zookeeper.= ClientCnxn$EventThread; EventThread shut down [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.063; org.apache.zookeeper.= ZooKeeper; Initiating client connection, connectString=3D127.0.0.1:58488/so= lr sessionTimeout=3D10000 watcher=3Dorg.apache.solr.common.cloud.Connection= Manager@190aab [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.065; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.065; org.apache.zookeeper.= ClientCnxn$SendThread; Opening socket connection to server localhost.locald= omain/127.0.0.1:58488. Will not attempt to authenticate using SASL (access = denied ("javax.security.auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.065; org.apache.zookeeper.= ClientCnxn$SendThread; Socket connection established to localhost.localdoma= in/127.0.0.1:58488, initiating session [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.065; org.apache.zookeeper.= server.NIOServerCnxnFactory; Accepted socket connection from /127.0.0.1:492= 63 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.066; org.apache.zookeeper.= server.ZooKeeperServer; Client attempting to establish new session at /127.= 0.0.1:49263 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.067; org.apache.zookeeper.= server.ZooKeeperServer; Established session 0x13dc369604a0001 with negotiat= ed timeout 10000 for client /127.0.0.1:49263 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.067; org.apache.zookeeper.= ClientCnxn$SendThread; Session establishment complete on server localhost.l= ocaldomain/127.0.0.1:58488, sessionid =3D 0x13dc369604a0001, negotiated tim= eout =3D 10000 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.067; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@190aab name:ZooKeeperConnection Watcher:127.0.0.1:58488/solr got eve= nt WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.067; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.068; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.070; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1/shards [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.072; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/control_collection [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.073; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/control_collection/shards [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.075; org.apache.solr.cloud= .AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to= /configs/conf1/solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.076; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.079; org.apache.solr.cloud= .AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs= /conf1/schema.xml [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.080; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/schema.xml [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.083; org.apache.solr.cloud= .AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /conf= igs/conf1/stopwords.txt [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.084; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/stopwords.txt [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.086; org.apache.solr.cloud= .AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /conf= igs/conf1/protwords.txt [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.086; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/protwords.txt [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.088; org.apache.solr.cloud= .AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /confi= gs/conf1/currency.xml [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.089; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/currency.xml [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.091; org.apache.solr.cloud= .AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.js= on to /configs/conf1/open-exchange-rates.json [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.091; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/open-exchange-rates.json [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.093; org.apache.solr.cloud= .AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accen= t.txt to /configs/conf1/mapping-ISOLatin1Accent.txt [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.094; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/mapping-ISOLatin1Accent.txt [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.096; org.apache.solr.cloud= .AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /c= onfigs/conf1/old_synonyms.txt [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.096; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/old_synonyms.txt [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.099; org.apache.solr.cloud= .AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /confi= gs/conf1/synonyms.txt [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.100; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/synonyms.txt [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.102; org.apache.zookeeper.= server.PrepRequestProcessor; Processed session termination for sessionid: 0= x13dc369604a0001 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.102; org.apache.zookeeper.= ZooKeeper; Session: 0x13dc369604a0001 closed [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.102; org.apache.zookeeper.= server.NIOServerCnxn; Closed socket connection for client /127.0.0.1:49263 = which had sessionid 0x13dc369604a0001 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.102; org.apache.zookeeper.= ClientCnxn$EventThread; EventThread shut down [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.159; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.176; org.eclipse.jetty.ser= ver.AbstractConnector; Started SelectChannelConnector@127.0.0.1:57533 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.177; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.177; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.178; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: /mnt/ssd/jenkins/= workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.s= olr.cloud.BasicDistributedZk2Test-controljetty-1364783096103 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.178; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/w= orkspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.so= lr.cloud.BasicDistributedZk2Test-controljetty-1364783096103/solr.xml [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.178; org.apache.solr.core.= CoreContainer; New CoreContainer 24963546 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.179; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/wor= kspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr= .cloud.BasicDistributedZk2Test-controljetty-1364783096103/' [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.179; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins= /workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.= solr.cloud.BasicDistributedZk2Test-controljetty-1364783096103/' [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.197; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.198; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.198; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.199; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.199; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.199; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.200; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.200; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.201; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.201; 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-01 02:24:56.208; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.219; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:58488/solr [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.220; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.220; org.apache.zookeeper.= ZooKeeper; Initiating client connection, connectString=3D127.0.0.1:58488 se= ssionTimeout=3D60000 watcher=3Dorg.apache.solr.common.cloud.ConnectionManag= er@1e06e40 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.221; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.221; org.apache.zookeeper.= ClientCnxn$SendThread; Opening socket connection to server localhost.locald= omain/127.0.0.1:58488. Will not attempt to authenticate using SASL (access = denied ("javax.security.auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.222; org.apache.zookeeper.= ClientCnxn$SendThread; Socket connection established to localhost.localdoma= in/127.0.0.1:58488, initiating session [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.222; org.apache.zookeeper.= server.NIOServerCnxnFactory; Accepted socket connection from /127.0.0.1:492= 64 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.223; org.apache.zookeeper.= server.ZooKeeperServer; Client attempting to establish new session at /127.= 0.0.1:49264 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.224; org.apache.zookeeper.= server.ZooKeeperServer; Established session 0x13dc369604a0002 with negotiat= ed timeout 20000 for client /127.0.0.1:49264 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.224; org.apache.zookeeper.= ClientCnxn$SendThread; Session establishment complete on server localhost.l= ocaldomain/127.0.0.1:58488, sessionid =3D 0x13dc369604a0002, negotiated tim= eout =3D 20000 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.224; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@1e06e40 name:ZooKeeperConnection Watcher:127.0.0.1:58488 got event W= atchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.224; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.226; org.apache.zookeeper.= server.PrepRequestProcessor; Processed session termination for sessionid: 0= x13dc369604a0002 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.226; org.apache.zookeeper.= ZooKeeper; Session: 0x13dc369604a0002 closed [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.226; org.apache.zookeeper.= server.NIOServerCnxn; Closed socket connection for client /127.0.0.1:49264 = which had sessionid 0x13dc369604a0002 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.226; org.apache.zookeeper.= ClientCnxn$EventThread; EventThread shut down [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.227; 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-01 02:24:56.230; org.apache.zookeeper.= ZooKeeper; Initiating client connection, connectString=3D127.0.0.1:58488/so= lr sessionTimeout=3D30000 watcher=3Dorg.apache.solr.common.cloud.Connection= Manager@e74407 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.231; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.231; org.apache.zookeeper.= ClientCnxn$SendThread; Opening socket connection to server localhost.locald= omain/127.0.0.1:58488. Will not attempt to authenticate using SASL (access = denied ("javax.security.auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.232; org.apache.zookeeper.= ClientCnxn$SendThread; Socket connection established to localhost.localdoma= in/127.0.0.1:58488, initiating session [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.232; org.apache.zookeeper.= server.NIOServerCnxnFactory; Accepted socket connection from /127.0.0.1:492= 65 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.232; org.apache.zookeeper.= server.ZooKeeperServer; Client attempting to establish new session at /127.= 0.0.1:49265 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.233; org.apache.zookeeper.= server.ZooKeeperServer; Established session 0x13dc369604a0003 with negotiat= ed timeout 20000 for client /127.0.0.1:49265 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.233; org.apache.zookeeper.= ClientCnxn$SendThread; Session establishment complete on server localhost.l= ocaldomain/127.0.0.1:58488, sessionid =3D 0x13dc369604a0003, negotiated tim= eout =3D 20000 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.234; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@e74407 name:ZooKeeperConnection Watcher:127.0.0.1:58488/solr got eve= nt WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.234; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.235; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer/queue [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.237; org.apache.zookeeper.= server.PrepRequestProcessor; Got user-level KeeperException when processing= sessionid:0x13dc369604a0003 type:create cxid:0x7 zxid:0x1b txntype:-1 reqp= ath:n/a Error Path:/solr/overseer Error:KeeperErrorCode =3D NodeExists for = /solr/overseer [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.238; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer/collection-queue-work [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.240; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.241; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:575= 33_fbvf%2Fq [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.242; org.apache.zookeeper.= server.PrepRequestProcessor; Got user-level KeeperException when processing= sessionid:0x13dc369604a0003 type:delete cxid:0x12 zxid:0x1e txntype:-1 req= path:n/a Error Path:/solr/live_nodes/127.0.0.1:57533_fbvf%2Fq Error:KeeperE= rrorCode =3D NoNode for /solr/live_nodes/127.0.0.1:57533_fbvf%2Fq [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.242; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:57533_fbvf%2Fq [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.244; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer_elect/election [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.248; org.apache.zookeeper.= server.PrepRequestProcessor; Got user-level KeeperException when processing= sessionid:0x13dc369604a0003 type:delete cxid:0x20 zxid:0x23 txntype:-1 req= path:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode =3D N= oNode for /solr/overseer_elect/leader [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.248; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer_elect/leader [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.250; org.apache.solr.cloud= .Overseer; Overseer (id=3D89442424971722755-127.0.0.1:57533_fbvf%2Fq-n_0000= 000000) starting [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.250; org.apache.zookeeper.= server.PrepRequestProcessor; Got user-level KeeperException when processing= sessionid:0x13dc369604a0003 type:create cxid:0x25 zxid:0x25 txntype:-1 req= path:n/a Error Path:/solr/overseer Error:KeeperErrorCode =3D NodeExists for= /solr/overseer [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.251; org.apache.zookeeper.= server.PrepRequestProcessor; Got user-level KeeperException when processing= sessionid:0x13dc369604a0003 type:create cxid:0x26 zxid:0x26 txntype:-1 req= path:n/a Error Path:/solr/overseer Error:KeeperErrorCode =3D NodeExists for= /solr/overseer [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.251; org.apache.zookeeper.= server.PrepRequestProcessor; Got user-level KeeperException when processing= sessionid:0x13dc369604a0003 type:create cxid:0x28 zxid:0x27 txntype:-1 req= path:n/a Error Path:/solr/overseer Error:KeeperErrorCode =3D NodeExists for= /solr/overseer [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.252; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer/queue-work [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.254; org.apache.zookeeper.= server.PrepRequestProcessor; Got user-level KeeperException when processing= sessionid:0x13dc369604a0003 type:create cxid:0x2e zxid:0x29 txntype:-1 req= path:n/a Error Path:/solr/overseer Error:KeeperErrorCode =3D NodeExists for= /solr/overseer [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.255; org.apache.solr.cloud= .OverseerCollectionProcessor; Process current queue of collection creations [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.255; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /clusterstate.json [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.257; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /aliases.json [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.258; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.260; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Starting to work on the main queue [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.262; org.apache.solr.core.= CoreContainer; Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/= jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.= apache.solr.cloud.BasicDistributedZk2Test-controljetty-1364783096103/collec= tion1 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.263; org.apache.solr.cloud= .ZkController; Check for collection zkNode:control_collection [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.263; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.263; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/control_collection [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.264; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins= /workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.= solr.cloud.BasicDistributedZk2Test-controljetty-1364783096103/collection1/' [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.265; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x= -Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZ= k2Test-controljetty-1364783096103/collection1/lib/README' to classloader [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.265; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x= -Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZ= k2Test-controljetty-1364783096103/collection1/lib/classes/' to classloader [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.301; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_43 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.343; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.344; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.349; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.754; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.760; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.763; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.771; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.774; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.777; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-01 02:24:56.778; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-01 02:24:56.778; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.779; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-01 02:24:56.779; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-01 02:24:56.779; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.780; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.780; org.apache.solr.core.= SolrCore; [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/= Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.= BasicDistributedZk2Test-controljetty-1364783096103/collection1/, dataDir=3D= ./org.apache.solr.cloud.BasicDistributedZk2Test-1364783095878/control/data/ [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.780; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@48c430 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.781; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.781; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.B= asicDistributedZk2Test-1364783095878/control/data [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.781; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D./org.apache.solr.= cloud.BasicDistributedZk2Test-1364783095878/control/data/index/ [junit4:junit4] 1> WARN - 2013-04-01 02:24:56.782; org.apache.solr.core.= SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.Basic= DistributedZk2Test-1364783095878/control/data/index' doesn't exist. Creatin= g new index... [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.782; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.B= asicDistributedZk2Test-1364783095878/control/data/index [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.783; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@681eee lockFactory=3Dorg.apache.lucene.store.NativeFSLockFact= ory@1d55303),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.783; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.785; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.785; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.785; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.786; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.786; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.786; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.787; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.787; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.787; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.790; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.792; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@434f99 main [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.792; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D./org.apache.solr.cloud.Bas= icDistributedZk2Test-1364783095878/control/data/tlog [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.793; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.793; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.797; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@434f99 main{Standa= rdDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.798; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Ddown [junit4:junit4] 1> INFO - 2013-04-01 02:24:56.798; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-01 02:24:57.762; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-01 02:24:57.763; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D1 message=3D{ [junit4:junit4] 1> "core_node_name":null, [junit4:junit4] 1> "node_name":"127.0.0.1:57533_fbvf%2Fq", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "numShards":"1", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "shard":null, [junit4:junit4] 1> "base_url":"http://127.0.0.1:57533/fbvf/q", [junit4:junit4] 1> "state":"down", [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "collection":"control_collection"} [junit4:junit4] 1> INFO - 2013-04-01 02:24:57.763; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Create collection control_collection with nu= mShards 1 [junit4:junit4] 1> INFO - 2013-04-01 02:24:57.763; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Assigning new node to shard shard=3Dshard1 [junit4:junit4] 1> INFO - 2013-04-01 02:24:57.766; 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-01 02:24:57.800; org.apache.solr.core.= CoreContainer; registering core: collection1 [junit4:junit4] 1> INFO - 2013-04-01 02:24:57.800; org.apache.solr.cloud= .ZkController; Register replica - core:collection1 address:http://127.0.0.1= :57533/fbvf/q collection:control_collection shard:shard1 [junit4:junit4] 1> INFO - 2013-04-01 02:24:57.801; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/control_collection/leader_elec= t/shard1/election [junit4:junit4] 1> INFO - 2013-04-01 02:24:57.805; org.apache.zookeeper.= server.PrepRequestProcessor; Got user-level KeeperException when processing= sessionid:0x13dc369604a0003 type:delete cxid:0x82 zxid:0x35 txntype:-1 req= path:n/a Error Path:/solr/collections/control_collection/leaders Error:Keep= erErrorCode =3D NoNode for /solr/collections/control_collection/leaders [junit4:junit4] 1> INFO - 2013-04-01 02:24:57.806; org.apache.solr.cloud= .ShardLeaderElectionContext; Running the leader process. [junit4:junit4] 1> INFO - 2013-04-01 02:24:57.806; org.apache.zookeeper.= server.PrepRequestProcessor; Got user-level KeeperException when processing= sessionid:0x13dc369604a0003 type:create cxid:0x83 zxid:0x36 txntype:-1 req= path:n/a Error Path:/solr/overseer Error:KeeperErrorCode =3D NodeExists for= /solr/overseer [junit4:junit4] 1> INFO - 2013-04-01 02:24:57.808; org.apache.solr.cloud= .ShardLeaderElectionContext; Enough replicas found to continue. [junit4:junit4] 1> INFO - 2013-04-01 02:24:57.808; org.apache.solr.cloud= .ShardLeaderElectionContext; I may be the new leader - try and sync [junit4:junit4] 1> INFO - 2013-04-01 02:24:57.808; org.apache.solr.cloud= .SyncStrategy; Sync replicas to http://127.0.0.1:57533/fbvf/q/collection1/ [junit4:junit4] 1> INFO - 2013-04-01 02:24:57.808; org.apache.solr.cloud= .SyncStrategy; Sync Success - now sync replicas to me [junit4:junit4] 1> INFO - 2013-04-01 02:24:57.809; org.apache.solr.cloud= .SyncStrategy; http://127.0.0.1:57533/fbvf/q/collection1/ has no replicas [junit4:junit4] 1> INFO - 2013-04-01 02:24:57.809; org.apache.solr.cloud= .ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:57533/fb= vf/q/collection1/ [junit4:junit4] 1> INFO - 2013-04-01 02:24:57.809; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/control_collection/leaders/sha= rd1 [junit4:junit4] 1> INFO - 2013-04-01 02:24:57.812; org.apache.zookeeper.= server.PrepRequestProcessor; Got user-level KeeperException when processing= sessionid:0x13dc369604a0003 type:create cxid:0x8e zxid:0x3a txntype:-1 req= path:n/a Error Path:/solr/overseer Error:KeeperErrorCode =3D NodeExists for= /solr/overseer [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.270; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.275; 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-01 02:24:59.315; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:57533/fbvf/q/collection1/ and leader= is http://127.0.0.1:57533/fbvf/q/collection1/ [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.316; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dcollection1 baseURL=3Dhttp://= 127.0.0.1:57533/fbvf/q [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.316; org.apache.solr.cloud= .ZkController; I am the leader, no recovery necessary [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.316; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Dactive [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.316; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.318; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.318; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/mnt/ssd/jenkins/workspace/Lucene-Solr-4.= x-Linux/solr/build/solr-core/test/J1 [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.319; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.320; 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-01 02:24:59.324; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config: [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.325; org.apache.zookeeper.= ZooKeeper; Initiating client connection, connectString=3D127.0.0.1:58488/so= lr sessionTimeout=3D10000 watcher=3Dorg.apache.solr.common.cloud.Connection= Manager@1600b99 [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.327; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.327; org.apache.zookeeper.= ClientCnxn$SendThread; Opening socket connection to server localhost.locald= omain/127.0.0.1:58488. Will not attempt to authenticate using SASL (access = denied ("javax.security.auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.327; org.apache.zookeeper.= ClientCnxn$SendThread; Socket connection established to localhost.localdoma= in/127.0.0.1:58488, initiating session [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.328; org.apache.zookeeper.= server.NIOServerCnxnFactory; Accepted socket connection from /127.0.0.1:492= 66 [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.328; org.apache.zookeeper.= server.ZooKeeperServer; Client attempting to establish new session at /127.= 0.0.1:49266 [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.329; org.apache.zookeeper.= server.ZooKeeperServer; Established session 0x13dc369604a0004 with negotiat= ed timeout 10000 for client /127.0.0.1:49266 [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.329; org.apache.zookeeper.= ClientCnxn$SendThread; Session establishment complete on server localhost.l= ocaldomain/127.0.0.1:58488, sessionid =3D 0x13dc369604a0004, negotiated tim= eout =3D 10000 [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.329; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@1600b99 name:ZooKeeperConnection Watcher:127.0.0.1:58488/solr got ev= ent WatchedEvent state:SyncConnected type:None path:null path:null type:Non= e [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.330; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.331; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.333; org.apache.solr.cloud= .ChaosMonkey; monkey: init - expire sessions:true cause connection loss:tru= e [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.409; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.410; org.eclipse.jetty.ser= ver.AbstractConnector; Started SelectChannelConnector@127.0.0.1:60563 [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.411; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.411; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.412; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: /mnt/ssd/jenkins/= workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.s= olr.cloud.BasicDistributedZk2Test-jetty1-1364783099333 [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.412; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/w= orkspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.so= lr.cloud.BasicDistributedZk2Test-jetty1-1364783099333/solr.xml [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.413; org.apache.solr.core.= CoreContainer; New CoreContainer 23397450 [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.413; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/wor= kspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr= .cloud.BasicDistributedZk2Test-jetty1-1364783099333/' [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.413; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins= /workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.= solr.cloud.BasicDistributedZk2Test-jetty1-1364783099333/' [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.432; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.432; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.433; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.433; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.433; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.434; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.434; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.434; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.435; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.435; 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-01 02:24:59.442; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.453; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:58488/solr [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.454; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.454; org.apache.zookeeper.= ZooKeeper; Initiating client connection, connectString=3D127.0.0.1:58488 se= ssionTimeout=3D60000 watcher=3Dorg.apache.solr.common.cloud.ConnectionManag= er@7804a2 [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.455; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.455; org.apache.zookeeper.= ClientCnxn$SendThread; Opening socket connection to server localhost.locald= omain/127.0.0.1:58488. Will not attempt to authenticate using SASL (access = denied ("javax.security.auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.456; org.apache.zookeeper.= ClientCnxn$SendThread; Socket connection established to localhost.localdoma= in/127.0.0.1:58488, initiating session [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.456; org.apache.zookeeper.= server.NIOServerCnxnFactory; Accepted socket connection from /127.0.0.1:492= 67 [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.456; org.apache.zookeeper.= server.ZooKeeperServer; Client attempting to establish new session at /127.= 0.0.1:49267 [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.457; org.apache.zookeeper.= server.ZooKeeperServer; Established session 0x13dc369604a0005 with negotiat= ed timeout 20000 for client /127.0.0.1:49267 [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.457; org.apache.zookeeper.= ClientCnxn$SendThread; Session establishment complete on server localhost.l= ocaldomain/127.0.0.1:58488, sessionid =3D 0x13dc369604a0005, negotiated tim= eout =3D 20000 [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.458; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@7804a2 name:ZooKeeperConnection Watcher:127.0.0.1:58488 got event Wa= tchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.458; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.459; org.apache.zookeeper.= server.PrepRequestProcessor; Processed session termination for sessionid: 0= x13dc369604a0005 [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.460; org.apache.zookeeper.= ZooKeeper; Session: 0x13dc369604a0005 closed [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.460; org.apache.zookeeper.= server.NIOServerCnxn; Closed socket connection for client /127.0.0.1:49267 = which had sessionid 0x13dc369604a0005 [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.460; org.apache.zookeeper.= ClientCnxn$EventThread; EventThread shut down [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.460; 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-01 02:24:59.463; org.apache.zookeeper.= ZooKeeper; Initiating client connection, connectString=3D127.0.0.1:58488/so= lr sessionTimeout=3D30000 watcher=3Dorg.apache.solr.common.cloud.Connection= Manager@3fc57b [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.464; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.464; org.apache.zookeeper.= ClientCnxn$SendThread; Opening socket connection to server localhost.locald= omain/127.0.0.1:58488. Will not attempt to authenticate using SASL (access = denied ("javax.security.auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.465; org.apache.zookeeper.= ClientCnxn$SendThread; Socket connection established to localhost.localdoma= in/127.0.0.1:58488, initiating session [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.465; org.apache.zookeeper.= server.NIOServerCnxnFactory; Accepted socket connection from /127.0.0.1:492= 68 [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.465; org.apache.zookeeper.= server.ZooKeeperServer; Client attempting to establish new session at /127.= 0.0.1:49268 [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.466; org.apache.zookeeper.= server.ZooKeeperServer; Established session 0x13dc369604a0006 with negotiat= ed timeout 20000 for client /127.0.0.1:49268 [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.466; org.apache.zookeeper.= ClientCnxn$SendThread; Session establishment complete on server localhost.l= ocaldomain/127.0.0.1:58488, sessionid =3D 0x13dc369604a0006, negotiated tim= eout =3D 20000 [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.467; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@3fc57b name:ZooKeeperConnection Watcher:127.0.0.1:58488/solr got eve= nt WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.467; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.468; org.apache.zookeeper.= server.PrepRequestProcessor; Got user-level KeeperException when processing= sessionid:0x13dc369604a0006 type:create cxid:0x1 zxid:0x48 txntype:-1 reqp= ath:n/a Error Path:/solr/overseer Error:KeeperErrorCode =3D NodeExists for = /solr/overseer [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.469; org.apache.zookeeper.= server.PrepRequestProcessor; Got user-level KeeperException when processing= sessionid:0x13dc369604a0006 type:create cxid:0x3 zxid:0x49 txntype:-1 reqp= ath:n/a Error Path:/solr/overseer Error:KeeperErrorCode =3D NodeExists for = /solr/overseer [junit4:junit4] 1> INFO - 2013-04-01 02:24:59.471; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.473; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:605= 63_fbvf%2Fq [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.474; org.apache.zookeeper.= server.PrepRequestProcessor; Got user-level KeeperException when processing= sessionid:0x13dc369604a0006 type:delete cxid:0xd zxid:0x4a txntype:-1 reqp= ath:n/a Error Path:/solr/live_nodes/127.0.0.1:60563_fbvf%2Fq Error:KeeperEr= rorCode =3D NoNode for /solr/live_nodes/127.0.0.1:60563_fbvf%2Fq [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.474; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:60563_fbvf%2Fq [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.476; 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-01 02:25:00.477; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (2) [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.477; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (2) [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.478; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (2) [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.481; org.apache.solr.core.= CoreContainer; Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/= jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.= apache.solr.cloud.BasicDistributedZk2Test-jetty1-1364783099333/collection1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.482; org.apache.solr.cloud= .ZkController; Check for collection zkNode:collection1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.482; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.482; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/collection1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.483; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins= /workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.= solr.cloud.BasicDistributedZk2Test-jetty1-1364783099333/collection1/' [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.484; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x= -Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZ= k2Test-jetty1-1364783099333/collection1/lib/README' to classloader [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.484; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x= -Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZ= k2Test-jetty1-1364783099333/collection1/lib/classes/' to classloader [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.513; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_43 [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.552; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.553; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.557; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.779; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.780; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D1 message=3D{ [junit4:junit4] 1> "core_node_name":"127.0.0.1:57533_fbvf%2Fq_collectio= n1", [junit4:junit4] 1> "node_name":"127.0.0.1:57533_fbvf%2Fq", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "numShards":"1", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "shard":"shard1", [junit4:junit4] 1> "base_url":"http://127.0.0.1:57533/fbvf/q", [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "collection":"control_collection"} [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.782; 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-01 02:25:00.783; 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-01 02:25:00.783; 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-01 02:25:00.937; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.943; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.946; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.959; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.962; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.965; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-01 02:25:00.966; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-01 02:25:00.966; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.966; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-01 02:25:00.967; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-01 02:25:00.967; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.968; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.968; org.apache.solr.core.= SolrCore; [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/= Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.= BasicDistributedZk2Test-jetty1-1364783099333/collection1/, dataDir=3D./org.= apache.solr.cloud.BasicDistributedZk2Test-1364783095878/jetty1/ [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.968; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@48c430 [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.969; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.969; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.B= asicDistributedZk2Test-1364783095878/jetty1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.969; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D./org.apache.solr.= cloud.BasicDistributedZk2Test-1364783095878/jetty1/index/ [junit4:junit4] 1> WARN - 2013-04-01 02:25:00.970; org.apache.solr.core.= SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.Basic= DistributedZk2Test-1364783095878/jetty1/index' doesn't exist. Creating new = index... [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.970; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.B= asicDistributedZk2Test-1364783095878/jetty1/index [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.971; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@b9db0b lockFactory=3Dorg.apache.lucene.store.NativeFSLockFact= ory@df761b),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.971; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.973; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.973; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.973; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.974; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.975; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.975; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.975; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.975; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.976; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.978; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.981; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@1d66aa4 main [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.981; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D./org.apache.solr.cloud.Bas= icDistributedZk2Test-1364783095878/jetty1/tlog [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.982; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.982; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.986; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@1d66aa4 main{Stand= ardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.988; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Ddown [junit4:junit4] 1> INFO - 2013-04-01 02:25:00.988; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-01 02:25:02.286; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:02.287; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "core_node_name":null, [junit4:junit4] 1> "node_name":"127.0.0.1:60563_fbvf%2Fq", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "shard":null, [junit4:junit4] 1> "base_url":"http://127.0.0.1:60563/fbvf/q", [junit4:junit4] 1> "state":"down", [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "collection":"collection1"} [junit4:junit4] 1> INFO - 2013-04-01 02:25:02.287; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Create collection collection1 with numShards= 2 [junit4:junit4] 1> INFO - 2013-04-01 02:25:02.287; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Assigning new node to shard shard=3Dshard1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:02.291; 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-01 02:25:02.291; 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-01 02:25:02.291; 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-01 02:25:02.989; org.apache.solr.core.= CoreContainer; registering core: collection1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:02.989; org.apache.solr.cloud= .ZkController; Register replica - core:collection1 address:http://127.0.0.1= :60563/fbvf/q collection:collection1 shard:shard1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:02.990; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1/leader_elect/shard= 1/election [junit4:junit4] 1> INFO - 2013-04-01 02:25:02.994; org.apache.zookeeper.= server.PrepRequestProcessor; Got user-level KeeperException when processing= sessionid:0x13dc369604a0006 type:delete cxid:0x4a zxid:0x5a txntype:-1 req= path:n/a Error Path:/solr/collections/collection1/leaders Error:KeeperError= Code =3D NoNode for /solr/collections/collection1/leaders [junit4:junit4] 1> INFO - 2013-04-01 02:25:02.995; org.apache.solr.cloud= .ShardLeaderElectionContext; Running the leader process. [junit4:junit4] 1> INFO - 2013-04-01 02:25:02.995; org.apache.zookeeper.= server.PrepRequestProcessor; Got user-level KeeperException when processing= sessionid:0x13dc369604a0006 type:create cxid:0x4b zxid:0x5b txntype:-1 req= path:n/a Error Path:/solr/overseer Error:KeeperErrorCode =3D NodeExists for= /solr/overseer [junit4:junit4] 1> INFO - 2013-04-01 02:25:02.997; org.apache.solr.cloud= .ShardLeaderElectionContext; Enough replicas found to continue. [junit4:junit4] 1> INFO - 2013-04-01 02:25:02.997; org.apache.solr.cloud= .ShardLeaderElectionContext; I may be the new leader - try and sync [junit4:junit4] 1> INFO - 2013-04-01 02:25:02.997; org.apache.solr.cloud= .SyncStrategy; Sync replicas to http://127.0.0.1:60563/fbvf/q/collection1/ [junit4:junit4] 1> INFO - 2013-04-01 02:25:02.998; org.apache.solr.cloud= .SyncStrategy; Sync Success - now sync replicas to me [junit4:junit4] 1> INFO - 2013-04-01 02:25:02.998; org.apache.solr.cloud= .SyncStrategy; http://127.0.0.1:60563/fbvf/q/collection1/ has no replicas [junit4:junit4] 1> INFO - 2013-04-01 02:25:02.998; org.apache.solr.cloud= .ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:60563/fb= vf/q/collection1/ [junit4:junit4] 1> INFO - 2013-04-01 02:25:02.998; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1/leaders/shard1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.001; org.apache.zookeeper.= server.PrepRequestProcessor; Got user-level KeeperException when processing= sessionid:0x13dc369604a0006 type:create cxid:0x56 zxid:0x5f txntype:-1 req= path:n/a Error Path:/solr/overseer Error:KeeperErrorCode =3D NodeExists for= /solr/overseer [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.795; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.800; 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-01 02:25:03.800; 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-01 02:25:03.800; 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-01 02:25:03.804; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:60563/fbvf/q/collection1/ and leader= is http://127.0.0.1:60563/fbvf/q/collection1/ [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.804; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dcollection1 baseURL=3Dhttp://= 127.0.0.1:60563/fbvf/q [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.804; org.apache.solr.cloud= .ZkController; I am the leader, no recovery necessary [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.804; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Dactive [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.805; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.806; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.806; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/mnt/ssd/jenkins/workspace/Lucene-Solr-4.= x-Linux/solr/build/solr-core/test/J1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.807; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.807; 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-01 02:25:03.877; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.879; org.eclipse.jetty.ser= ver.AbstractConnector; Started SelectChannelConnector@127.0.0.1:53193 [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.879; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.880; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.880; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: /mnt/ssd/jenkins/= workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.s= olr.cloud.BasicDistributedZk2Test-jetty2-1364783103810 [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.881; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/w= orkspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.so= lr.cloud.BasicDistributedZk2Test-jetty2-1364783103810/solr.xml [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.881; org.apache.solr.core.= CoreContainer; New CoreContainer 13050431 [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.882; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/wor= kspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr= .cloud.BasicDistributedZk2Test-jetty2-1364783103810/' [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.882; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins= /workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.= solr.cloud.BasicDistributedZk2Test-jetty2-1364783103810/' [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.901; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.902; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.902; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.903; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.903; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.903; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.904; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.904; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.905; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.905; 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-01 02:25:03.912; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.924; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:58488/solr [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.925; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.925; org.apache.zookeeper.= ZooKeeper; Initiating client connection, connectString=3D127.0.0.1:58488 se= ssionTimeout=3D60000 watcher=3Dorg.apache.solr.common.cloud.ConnectionManag= er@171490f [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.926; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.926; org.apache.zookeeper.= ClientCnxn$SendThread; Opening socket connection to server localhost.locald= omain/127.0.0.1:58488. Will not attempt to authenticate using SASL (access = denied ("javax.security.auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.927; org.apache.zookeeper.= ClientCnxn$SendThread; Socket connection established to localhost.localdoma= in/127.0.0.1:58488, initiating session [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.927; org.apache.zookeeper.= server.NIOServerCnxnFactory; Accepted socket connection from /127.0.0.1:492= 70 [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.928; org.apache.zookeeper.= server.ZooKeeperServer; Client attempting to establish new session at /127.= 0.0.1:49270 [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.928; org.apache.zookeeper.= server.ZooKeeperServer; Established session 0x13dc369604a0007 with negotiat= ed timeout 20000 for client /127.0.0.1:49270 [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.928; org.apache.zookeeper.= ClientCnxn$SendThread; Session establishment complete on server localhost.l= ocaldomain/127.0.0.1:58488, sessionid =3D 0x13dc369604a0007, negotiated tim= eout =3D 20000 [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.929; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@171490f name:ZooKeeperConnection Watcher:127.0.0.1:58488 got event W= atchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.929; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.930; org.apache.zookeeper.= server.PrepRequestProcessor; Processed session termination for sessionid: 0= x13dc369604a0007 [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.931; org.apache.zookeeper.= ZooKeeper; Session: 0x13dc369604a0007 closed [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.931; org.apache.zookeeper.= server.NIOServerCnxn; Closed socket connection for client /127.0.0.1:49270 = which had sessionid 0x13dc369604a0007 [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.931; org.apache.zookeeper.= ClientCnxn$EventThread; EventThread shut down [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.931; 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-01 02:25:03.934; org.apache.zookeeper.= ZooKeeper; Initiating client connection, connectString=3D127.0.0.1:58488/so= lr sessionTimeout=3D30000 watcher=3Dorg.apache.solr.common.cloud.Connection= Manager@12df07b [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.935; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.935; org.apache.zookeeper.= ClientCnxn$SendThread; Opening socket connection to server localhost.locald= omain/127.0.0.1:58488. Will not attempt to authenticate using SASL (access = denied ("javax.security.auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.936; org.apache.zookeeper.= ClientCnxn$SendThread; Socket connection established to localhost.localdoma= in/127.0.0.1:58488, initiating session [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.936; org.apache.zookeeper.= server.NIOServerCnxnFactory; Accepted socket connection from /127.0.0.1:492= 71 [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.937; org.apache.zookeeper.= server.ZooKeeperServer; Client attempting to establish new session at /127.= 0.0.1:49271 [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.937; org.apache.zookeeper.= server.ZooKeeperServer; Established session 0x13dc369604a0008 with negotiat= ed timeout 20000 for client /127.0.0.1:49271 [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.937; org.apache.zookeeper.= ClientCnxn$SendThread; Session establishment complete on server localhost.l= ocaldomain/127.0.0.1:58488, sessionid =3D 0x13dc369604a0008, negotiated tim= eout =3D 20000 [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.938; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@12df07b name:ZooKeeperConnection Watcher:127.0.0.1:58488/solr got ev= ent WatchedEvent state:SyncConnected type:None path:null path:null type:Non= e [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.938; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.939; org.apache.zookeeper.= server.PrepRequestProcessor; Got user-level KeeperException when processing= sessionid:0x13dc369604a0008 type:create cxid:0x1 zxid:0x6c txntype:-1 reqp= ath:n/a Error Path:/solr/overseer Error:KeeperErrorCode =3D NodeExists for = /solr/overseer [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.940; org.apache.zookeeper.= server.PrepRequestProcessor; Got user-level KeeperException when processing= sessionid:0x13dc369604a0008 type:create cxid:0x3 zxid:0x6d txntype:-1 reqp= ath:n/a Error Path:/solr/overseer Error:KeeperErrorCode =3D NodeExists for = /solr/overseer [junit4:junit4] 1> INFO - 2013-04-01 02:25:03.941; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:04.943; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:531= 93_fbvf%2Fq [junit4:junit4] 1> INFO - 2013-04-01 02:25:04.944; org.apache.zookeeper.= server.PrepRequestProcessor; Got user-level KeeperException when processing= sessionid:0x13dc369604a0008 type:delete cxid:0xd zxid:0x6e txntype:-1 reqp= ath:n/a Error Path:/solr/live_nodes/127.0.0.1:53193_fbvf%2Fq Error:KeeperEr= rorCode =3D NoNode for /solr/live_nodes/127.0.0.1:53193_fbvf%2Fq [junit4:junit4] 1> INFO - 2013-04-01 02:25:04.945; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:53193_fbvf%2Fq [junit4:junit4] 1> INFO - 2013-04-01 02:25:04.946; 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-01 02:25:04.947; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-04-01 02:25:04.947; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-04-01 02:25:04.947; 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-01 02:25:04.948; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-04-01 02:25:04.948; 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-01 02:25:04.949; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-04-01 02:25:04.953; org.apache.solr.core.= CoreContainer; Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/= jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.= apache.solr.cloud.BasicDistributedZk2Test-jetty2-1364783103810/collection1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:04.953; org.apache.solr.cloud= .ZkController; Check for collection zkNode:collection1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:04.954; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-01 02:25:04.954; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/collection1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:04.955; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins= /workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.= solr.cloud.BasicDistributedZk2Test-jetty2-1364783103810/collection1/' [junit4:junit4] 1> INFO - 2013-04-01 02:25:04.956; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x= -Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZ= k2Test-jetty2-1364783103810/collection1/lib/README' to classloader [junit4:junit4] 1> INFO - 2013-04-01 02:25:04.956; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x= -Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZ= k2Test-jetty2-1364783103810/collection1/lib/classes/' to classloader [junit4:junit4] 1> INFO - 2013-04-01 02:25:04.987; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_43 [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.026; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.027; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.031; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.304; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.304; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "core_node_name":"127.0.0.1:60563_fbvf%2Fq_collectio= n1", [junit4:junit4] 1> "node_name":"127.0.0.1:60563_fbvf%2Fq", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "shard":"shard1", [junit4:junit4] 1> "base_url":"http://127.0.0.1:60563/fbvf/q", [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "collection":"collection1"} [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.307; 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-01 02:25:05.307; 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-01 02:25:05.307; 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-01 02:25:05.307; 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-01 02:25:05.444; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.450; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.453; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.462; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.465; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.468; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-01 02:25:05.469; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-01 02:25:05.469; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.469; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-01 02:25:05.470; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-01 02:25:05.470; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.471; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.471; org.apache.solr.core.= SolrCore; [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/= Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.= BasicDistributedZk2Test-jetty2-1364783103810/collection1/, dataDir=3D./org.= apache.solr.cloud.BasicDistributedZk2Test-1364783095878/jetty2/ [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.471; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@48c430 [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.472; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.472; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.B= asicDistributedZk2Test-1364783095878/jetty2 [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.472; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D./org.apache.solr.= cloud.BasicDistributedZk2Test-1364783095878/jetty2/index/ [junit4:junit4] 1> WARN - 2013-04-01 02:25:05.472; org.apache.solr.core.= SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.Basic= DistributedZk2Test-1364783095878/jetty2/index' doesn't exist. Creating new = index... [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.473; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.B= asicDistributedZk2Test-1364783095878/jetty2/index [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.474; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@1713f16 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFac= tory@81df03),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.474; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.475; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.476; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.476; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.477; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.477; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.477; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.478; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.478; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.478; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.481; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.483; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@a0d451 main [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.484; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D./org.apache.solr.cloud.Bas= icDistributedZk2Test-1364783095878/jetty2/tlog [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.484; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.484; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.489; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@a0d451 main{Standa= rdDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.492; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Ddown [junit4:junit4] 1> INFO - 2013-04-01 02:25:05.492; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-01 02:25:06.811; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:06.812; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "core_node_name":null, [junit4:junit4] 1> "node_name":"127.0.0.1:53193_fbvf%2Fq", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "shard":null, [junit4:junit4] 1> "base_url":"http://127.0.0.1:53193/fbvf/q", [junit4:junit4] 1> "state":"down", [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "collection":"collection1"} [junit4:junit4] 1> INFO - 2013-04-01 02:25:06.812; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Collection already exists with numShards=3D2 [junit4:junit4] 1> INFO - 2013-04-01 02:25:06.812; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Assigning new node to shard shard=3Dshard2 [junit4:junit4] 1> INFO - 2013-04-01 02:25:06.816; 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-01 02:25:06.816; 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-01 02:25:06.816; 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-01 02:25:06.817; 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-01 02:25:07.493; org.apache.solr.core.= CoreContainer; registering core: collection1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:07.493; org.apache.solr.cloud= .ZkController; Register replica - core:collection1 address:http://127.0.0.1= :53193/fbvf/q collection:collection1 shard:shard2 [junit4:junit4] 1> INFO - 2013-04-01 02:25:07.494; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1/leader_elect/shard= 2/election [junit4:junit4] 1> INFO - 2013-04-01 02:25:07.497; org.apache.zookeeper.= server.PrepRequestProcessor; Got user-level KeeperException when processing= sessionid:0x13dc369604a0008 type:delete cxid:0x49 zxid:0x7d txntype:-1 req= path:n/a Error Path:/solr/collections/collection1/leaders/shard2 Error:Keep= erErrorCode =3D NoNode for /solr/collections/collection1/leaders/shard2 [junit4:junit4] 1> INFO - 2013-04-01 02:25:07.498; org.apache.solr.cloud= .ShardLeaderElectionContext; Running the leader process. [junit4:junit4] 1> INFO - 2013-04-01 02:25:07.498; org.apache.zookeeper.= server.PrepRequestProcessor; Got user-level KeeperException when processing= sessionid:0x13dc369604a0008 type:create cxid:0x4a zxid:0x7e txntype:-1 req= path:n/a Error Path:/solr/overseer Error:KeeperErrorCode =3D NodeExists for= /solr/overseer [junit4:junit4] 1> INFO - 2013-04-01 02:25:07.500; org.apache.solr.cloud= .ShardLeaderElectionContext; Enough replicas found to continue. [junit4:junit4] 1> INFO - 2013-04-01 02:25:07.500; org.apache.solr.cloud= .ShardLeaderElectionContext; I may be the new leader - try and sync [junit4:junit4] 1> INFO - 2013-04-01 02:25:07.500; org.apache.solr.cloud= .SyncStrategy; Sync replicas to http://127.0.0.1:53193/fbvf/q/collection1/ [junit4:junit4] 1> INFO - 2013-04-01 02:25:07.501; org.apache.solr.cloud= .SyncStrategy; Sync Success - now sync replicas to me [junit4:junit4] 1> INFO - 2013-04-01 02:25:07.501; org.apache.solr.cloud= .SyncStrategy; http://127.0.0.1:53193/fbvf/q/collection1/ has no replicas [junit4:junit4] 1> INFO - 2013-04-01 02:25:07.501; org.apache.solr.cloud= .ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:53193/fb= vf/q/collection1/ [junit4:junit4] 1> INFO - 2013-04-01 02:25:07.501; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1/leaders/shard2 [junit4:junit4] 1> INFO - 2013-04-01 02:25:07.503; org.apache.zookeeper.= server.PrepRequestProcessor; Got user-level KeeperException when processing= sessionid:0x13dc369604a0008 type:create cxid:0x54 zxid:0x81 txntype:-1 req= path:n/a Error Path:/solr/overseer Error:KeeperErrorCode =3D NodeExists for= /solr/overseer [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.320; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.325; 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-01 02:25:08.325; 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-01 02:25:08.325; 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-01 02:25:08.325; 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-01 02:25:08.356; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:53193/fbvf/q/collection1/ and leader= is http://127.0.0.1:53193/fbvf/q/collection1/ [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.357; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dcollection1 baseURL=3Dhttp://= 127.0.0.1:53193/fbvf/q [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.357; org.apache.solr.cloud= .ZkController; I am the leader, no recovery necessary [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.357; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Dactive [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.358; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.359; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.360; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/mnt/ssd/jenkins/workspace/Lucene-Solr-4.= x-Linux/solr/build/solr-core/test/J1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.361; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.361; 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-01 02:25:08.435; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.438; org.eclipse.jetty.ser= ver.AbstractConnector; Started SelectChannelConnector@127.0.0.1:44591 [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.438; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.439; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.439; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: /mnt/ssd/jenkins/= workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.s= olr.cloud.BasicDistributedZk2Test-jetty3-1364783108364 [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.440; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/w= orkspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.so= lr.cloud.BasicDistributedZk2Test-jetty3-1364783108364/solr.xml [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.440; org.apache.solr.core.= CoreContainer; New CoreContainer 5528446 [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.441; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/wor= kspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr= .cloud.BasicDistributedZk2Test-jetty3-1364783108364/' [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.441; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins= /workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.= solr.cloud.BasicDistributedZk2Test-jetty3-1364783108364/' [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.462; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.463; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.463; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.464; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.464; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.465; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.465; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.466; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.466; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.466; 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-01 02:25:08.474; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.487; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:58488/solr [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.488; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.488; org.apache.zookeeper.= ZooKeeper; Initiating client connection, connectString=3D127.0.0.1:58488 se= ssionTimeout=3D60000 watcher=3Dorg.apache.solr.common.cloud.ConnectionManag= er@1cde3ac [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.489; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.489; org.apache.zookeeper.= ClientCnxn$SendThread; Opening socket connection to server localhost.locald= omain/127.0.0.1:58488. Will not attempt to authenticate using SASL (access = denied ("javax.security.auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.490; org.apache.zookeeper.= ClientCnxn$SendThread; Socket connection established to localhost.localdoma= in/127.0.0.1:58488, initiating session [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.490; org.apache.zookeeper.= server.NIOServerCnxnFactory; Accepted socket connection from /127.0.0.1:492= 72 [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.491; org.apache.zookeeper.= server.ZooKeeperServer; Client attempting to establish new session at /127.= 0.0.1:49272 [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.491; org.apache.zookeeper.= server.ZooKeeperServer; Established session 0x13dc369604a0009 with negotiat= ed timeout 20000 for client /127.0.0.1:49272 [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.491; org.apache.zookeeper.= ClientCnxn$SendThread; Session establishment complete on server localhost.l= ocaldomain/127.0.0.1:58488, sessionid =3D 0x13dc369604a0009, negotiated tim= eout =3D 20000 [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.492; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@1cde3ac name:ZooKeeperConnection Watcher:127.0.0.1:58488 got event W= atchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.492; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.493; org.apache.zookeeper.= server.PrepRequestProcessor; Processed session termination for sessionid: 0= x13dc369604a0009 [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.494; org.apache.zookeeper.= ZooKeeper; Session: 0x13dc369604a0009 closed [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.494; org.apache.zookeeper.= server.NIOServerCnxn; Closed socket connection for client /127.0.0.1:49272 = which had sessionid 0x13dc369604a0009 [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.494; org.apache.zookeeper.= ClientCnxn$EventThread; EventThread shut down [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.494; 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-01 02:25:08.498; org.apache.zookeeper.= ZooKeeper; Initiating client connection, connectString=3D127.0.0.1:58488/so= lr sessionTimeout=3D30000 watcher=3Dorg.apache.solr.common.cloud.Connection= Manager@155f8ed [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.499; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.499; org.apache.zookeeper.= ClientCnxn$SendThread; Opening socket connection to server localhost.locald= omain/127.0.0.1:58488. Will not attempt to authenticate using SASL (access = denied ("javax.security.auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.500; org.apache.zookeeper.= ClientCnxn$SendThread; Socket connection established to localhost.localdoma= in/127.0.0.1:58488, initiating session [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.500; org.apache.zookeeper.= server.NIOServerCnxnFactory; Accepted socket connection from /127.0.0.1:492= 73 [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.500; org.apache.zookeeper.= server.ZooKeeperServer; Client attempting to establish new session at /127.= 0.0.1:49273 [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.501; org.apache.zookeeper.= server.ZooKeeperServer; Established session 0x13dc369604a000a with negotiat= ed timeout 20000 for client /127.0.0.1:49273 [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.501; org.apache.zookeeper.= ClientCnxn$SendThread; Session establishment complete on server localhost.l= ocaldomain/127.0.0.1:58488, sessionid =3D 0x13dc369604a000a, negotiated tim= eout =3D 20000 [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.502; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@155f8ed name:ZooKeeperConnection Watcher:127.0.0.1:58488/solr got ev= ent WatchedEvent state:SyncConnected type:None path:null path:null type:Non= e [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.502; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.503; org.apache.zookeeper.= server.PrepRequestProcessor; Got user-level KeeperException when processing= sessionid:0x13dc369604a000a type:create cxid:0x1 zxid:0x8e txntype:-1 reqp= ath:n/a Error Path:/solr/overseer Error:KeeperErrorCode =3D NodeExists for = /solr/overseer [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.504; org.apache.zookeeper.= server.PrepRequestProcessor; Got user-level KeeperException when processing= sessionid:0x13dc369604a000a type:create cxid:0x3 zxid:0x8f txntype:-1 reqp= ath:n/a Error Path:/solr/overseer Error:KeeperErrorCode =3D NodeExists for = /solr/overseer [junit4:junit4] 1> INFO - 2013-04-01 02:25:08.505; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:09.507; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:445= 91_fbvf%2Fq [junit4:junit4] 1> INFO - 2013-04-01 02:25:09.508; org.apache.zookeeper.= server.PrepRequestProcessor; Got user-level KeeperException when processing= sessionid:0x13dc369604a000a type:delete cxid:0xd zxid:0x90 txntype:-1 reqp= ath:n/a Error Path:/solr/live_nodes/127.0.0.1:44591_fbvf%2Fq Error:KeeperEr= rorCode =3D NoNode for /solr/live_nodes/127.0.0.1:44591_fbvf%2Fq [junit4:junit4] 1> INFO - 2013-04-01 02:25:09.509; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:44591_fbvf%2Fq [junit4:junit4] 1> INFO - 2013-04-01 02:25:09.511; 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-01 02:25:09.511; 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-01 02:25:09.512; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-01 02:25:09.512; 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-01 02:25:09.512; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-01 02:25:09.512; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-01 02:25:09.513; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-01 02:25:09.513; 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-01 02:25:09.513; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-01 02:25:09.517; org.apache.solr.core.= CoreContainer; Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/= jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.= apache.solr.cloud.BasicDistributedZk2Test-jetty3-1364783108364/collection1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:09.518; org.apache.solr.cloud= .ZkController; Check for collection zkNode:collection1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:09.518; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-01 02:25:09.519; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/collection1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:09.520; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins= /workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.= solr.cloud.BasicDistributedZk2Test-jetty3-1364783108364/collection1/' [junit4:junit4] 1> INFO - 2013-04-01 02:25:09.520; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x= -Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZ= k2Test-jetty3-1364783108364/collection1/lib/README' to classloader [junit4:junit4] 1> INFO - 2013-04-01 02:25:09.521; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x= -Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZ= k2Test-jetty3-1364783108364/collection1/lib/classes/' to classloader [junit4:junit4] 1> INFO - 2013-04-01 02:25:09.552; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_43 [junit4:junit4] 1> INFO - 2013-04-01 02:25:09.601; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-01 02:25:09.602; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema [junit4:junit4] 1> INFO - 2013-04-01 02:25:09.607; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-01 02:25:09.829; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:09.830; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "core_node_name":"127.0.0.1:53193_fbvf%2Fq_collectio= n1", [junit4:junit4] 1> "node_name":"127.0.0.1:53193_fbvf%2Fq", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "shard":"shard2", [junit4:junit4] 1> "base_url":"http://127.0.0.1:53193/fbvf/q", [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "collection":"collection1"} [junit4:junit4] 1> INFO - 2013-04-01 02:25:09.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: 4) [junit4:junit4] 1> INFO - 2013-04-01 02:25:09.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: 4) [junit4:junit4] 1> INFO - 2013-04-01 02:25:09.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: 4) [junit4:junit4] 1> INFO - 2013-04-01 02:25:09.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: 4) [junit4:junit4] 1> INFO - 2013-04-01 02:25:09.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: 4) [junit4:junit4] 1> INFO - 2013-04-01 02:25:09.994; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-01 02:25:10.000; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-01 02:25:10.003; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-01 02:25:10.011; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-01 02:25:10.015; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-01 02:25:10.018; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-01 02:25:10.018; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-01 02:25:10.019; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-01 02:25:10.019; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-01 02:25:10.020; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-01 02:25:10.020; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-01 02:25:10.020; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-01 02:25:10.021; org.apache.solr.core.= SolrCore; [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/= Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.= BasicDistributedZk2Test-jetty3-1364783108364/collection1/, dataDir=3D./org.= apache.solr.cloud.BasicDistributedZk2Test-1364783095878/jetty3/ [junit4:junit4] 1> INFO - 2013-04-01 02:25:10.021; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@48c430 [junit4:junit4] 1> INFO - 2013-04-01 02:25:10.021; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-01 02:25:10.022; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.B= asicDistributedZk2Test-1364783095878/jetty3 [junit4:junit4] 1> INFO - 2013-04-01 02:25:10.022; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D./org.apache.solr.= cloud.BasicDistributedZk2Test-1364783095878/jetty3/index/ [junit4:junit4] 1> WARN - 2013-04-01 02:25:10.023; org.apache.solr.core.= SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.Basic= DistributedZk2Test-1364783095878/jetty3/index' doesn't exist. Creating new = index... [junit4:junit4] 1> INFO - 2013-04-01 02:25:10.023; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.B= asicDistributedZk2Test-1364783095878/jetty3/index [junit4:junit4] 1> INFO - 2013-04-01 02:25:10.024; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@d6e342 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFact= ory@23c9b),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-01 02:25:10.025; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-01 02:25:10.026; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-01 02:25:10.027; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-01 02:25:10.027; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-01 02:25:10.028; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-01 02:25:10.029; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-01 02:25:10.029; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-01 02:25:10.029; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-01 02:25:10.030; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-01 02:25:10.030; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-01 02:25:10.034; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-01 02:25:10.037; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@111ebc9 main [junit4:junit4] 1> INFO - 2013-04-01 02:25:10.037; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D./org.apache.solr.cloud.Bas= icDistributedZk2Test-1364783095878/jetty3/tlog [junit4:junit4] 1> INFO - 2013-04-01 02:25:10.038; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-01 02:25:10.038; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-01 02:25:10.043; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@111ebc9 main{Stand= ardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-01 02:25:10.045; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Ddown [junit4:junit4] 1> INFO - 2013-04-01 02:25:10.045; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-01 02:25:11.338; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:11.339; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "core_node_name":null, [junit4:junit4] 1> "node_name":"127.0.0.1:44591_fbvf%2Fq", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "shard":null, [junit4:junit4] 1> "base_url":"http://127.0.0.1:44591/fbvf/q", [junit4:junit4] 1> "state":"down", [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "collection":"collection1"} [junit4:junit4] 1> INFO - 2013-04-01 02:25:11.339; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Collection already exists with numShards=3D2 [junit4:junit4] 1> INFO - 2013-04-01 02:25:11.339; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Assigning new node to shard shard=3Dshard1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:11.343; 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-01 02:25:11.343; 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-01 02:25:11.343; 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-01 02:25:11.343; 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-01 02:25:11.343; 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-01 02:25:12.047; org.apache.solr.core.= CoreContainer; registering core: collection1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.047; org.apache.solr.cloud= .ZkController; Register replica - core:collection1 address:http://127.0.0.1= :44591/fbvf/q collection:collection1 shard:shard1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.050; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:44591/fbvf/q/collection1/ and leader= is http://127.0.0.1:60563/fbvf/q/collection1/ [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.050; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dcollection1 baseURL=3Dhttp://= 127.0.0.1:44591/fbvf/q [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.050; org.apache.solr.cloud= .ZkController; Core needs to recover:collection1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.050; org.apache.solr.updat= e.DefaultSolrCoreState; Running recovery - first canceling any ongoing reco= very [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.051; org.apache.solr.cloud= .RecoveryStrategy; Starting recovery process. core=3Dcollection1 recoverin= gAfterStartup=3Dtrue [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.051; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.051; org.apache.solr.cloud= .RecoveryStrategy; ###### startupVersions=3D[] [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.052; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Drecovering [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.052; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.052; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/mnt/ssd/jenkins/workspace/Lucene-Solr-4.= x-Linux/solr/build/solr-core/test/J1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.053; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.053; 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-01 02:25:12.056; 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-01 02:25:12.117; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.120; org.eclipse.jetty.ser= ver.AbstractConnector; Started SelectChannelConnector@127.0.0.1:37410 [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.120; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.121; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.121; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: /mnt/ssd/jenkins/= workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.s= olr.cloud.BasicDistributedZk2Test-jetty4-1364783112056 [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.121; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/w= orkspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.so= lr.cloud.BasicDistributedZk2Test-jetty4-1364783112056/solr.xml [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.122; org.apache.solr.core.= CoreContainer; New CoreContainer 19213617 [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.122; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/wor= kspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr= .cloud.BasicDistributedZk2Test-jetty4-1364783112056/' [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.123; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins= /workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.= solr.cloud.BasicDistributedZk2Test-jetty4-1364783112056/' [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.141; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.142; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.142; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.142; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.143; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.143; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.144; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.144; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.144; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.145; 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-01 02:25:12.151; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.163; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:58488/solr [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.163; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.164; org.apache.zookeeper.= ZooKeeper; Initiating client connection, connectString=3D127.0.0.1:58488 se= ssionTimeout=3D60000 watcher=3Dorg.apache.solr.common.cloud.ConnectionManag= er@662127 [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.165; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.165; org.apache.zookeeper.= ClientCnxn$SendThread; Opening socket connection to server localhost.locald= omain/127.0.0.1:58488. Will not attempt to authenticate using SASL (access = denied ("javax.security.auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.166; org.apache.zookeeper.= ClientCnxn$SendThread; Socket connection established to localhost.localdoma= in/127.0.0.1:58488, initiating session [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.166; org.apache.zookeeper.= server.NIOServerCnxnFactory; Accepted socket connection from /127.0.0.1:492= 75 [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.166; org.apache.zookeeper.= server.ZooKeeperServer; Client attempting to establish new session at /127.= 0.0.1:49275 [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.167; org.apache.zookeeper.= server.ZooKeeperServer; Established session 0x13dc369604a000b with negotiat= ed timeout 20000 for client /127.0.0.1:49275 [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.167; org.apache.zookeeper.= ClientCnxn$SendThread; Session establishment complete on server localhost.l= ocaldomain/127.0.0.1:58488, sessionid =3D 0x13dc369604a000b, negotiated tim= eout =3D 20000 [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.168; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@662127 name:ZooKeeperConnection Watcher:127.0.0.1:58488 got event Wa= tchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.168; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.169; org.apache.zookeeper.= server.PrepRequestProcessor; Processed session termination for sessionid: 0= x13dc369604a000b [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.170; org.apache.zookeeper.= server.NIOServerCnxn; Closed socket connection for client /127.0.0.1:49275 = which had sessionid 0x13dc369604a000b [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.170; org.apache.zookeeper.= ZooKeeper; Session: 0x13dc369604a000b closed [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.170; org.apache.zookeeper.= ClientCnxn$EventThread; EventThread shut down [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.171; 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-01 02:25:12.174; org.apache.zookeeper.= ZooKeeper; Initiating client connection, connectString=3D127.0.0.1:58488/so= lr sessionTimeout=3D30000 watcher=3Dorg.apache.solr.common.cloud.Connection= Manager@f7d509 [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.175; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.175; org.apache.zookeeper.= ClientCnxn$SendThread; Opening socket connection to server localhost.locald= omain/127.0.0.1:58488. Will not attempt to authenticate using SASL (access = denied ("javax.security.auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.175; org.apache.zookeeper.= ClientCnxn$SendThread; Socket connection established to localhost.localdoma= in/127.0.0.1:58488, initiating session [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.175; org.apache.zookeeper.= server.NIOServerCnxnFactory; Accepted socket connection from /127.0.0.1:492= 76 [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.176; org.apache.zookeeper.= server.ZooKeeperServer; Client attempting to establish new session at /127.= 0.0.1:49276 [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.177; org.apache.zookeeper.= server.ZooKeeperServer; Established session 0x13dc369604a000c with negotiat= ed timeout 20000 for client /127.0.0.1:49276 [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.177; org.apache.zookeeper.= ClientCnxn$SendThread; Session establishment complete on server localhost.l= ocaldomain/127.0.0.1:58488, sessionid =3D 0x13dc369604a000c, negotiated tim= eout =3D 20000 [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.177; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@f7d509 name:ZooKeeperConnection Watcher:127.0.0.1:58488/solr got eve= nt WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.177; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.178; org.apache.zookeeper.= server.PrepRequestProcessor; Got user-level KeeperException when processing= sessionid:0x13dc369604a000c type:create cxid:0x1 zxid:0xa1 txntype:-1 reqp= ath:n/a Error Path:/solr/overseer Error:KeeperErrorCode =3D NodeExists for = /solr/overseer [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.180; org.apache.zookeeper.= server.PrepRequestProcessor; Got user-level KeeperException when processing= sessionid:0x13dc369604a000c type:create cxid:0x3 zxid:0xa2 txntype:-1 reqp= ath:n/a Error Path:/solr/overseer Error:KeeperErrorCode =3D NodeExists for = /solr/overseer [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.183; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.847; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.848; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "core_node_name":"127.0.0.1:44591_fbvf%2Fq_collectio= n1", [junit4:junit4] 1> "node_name":"127.0.0.1:44591_fbvf%2Fq", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "shard":"shard1", [junit4:junit4] 1> "base_url":"http://127.0.0.1:44591/fbvf/q", [junit4:junit4] 1> "state":"recovering", [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "collection":"collection1"} [junit4:junit4] 1> INFO - 2013-04-01 02:25:12.870; 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-01 02:25:12.870; 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-01 02:25:12.870; 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-01 02:25:12.870; 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-01 02:25:12.870; 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-01 02:25:12.870; 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-01 02:25:13.060; org.apache.solr.servl= et.SolrDispatchFilter; [admin] webapp=3Dnull path=3D/admin/cores params=3D{= core=3Dcollection1&version=3D2&wt=3Djavabin&onlyIfLeader=3Dtrue&state=3Drec= overing&nodeName=3D127.0.0.1:44591_fbvf%252Fq&checkLive=3Dtrue&action=3DPRE= PRECOVERY&coreNodeName=3D127.0.0.1:44591_fbvf%252Fq_collection1} status=3D0= QTime=3D1000=20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.187; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:374= 10_fbvf%2Fq [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.188; org.apache.zookeeper.= server.PrepRequestProcessor; Got user-level KeeperException when processing= sessionid:0x13dc369604a000c type:delete cxid:0xf zxid:0xa7 txntype:-1 reqp= ath:n/a Error Path:/solr/live_nodes/127.0.0.1:37410_fbvf%2Fq Error:KeeperEr= rorCode =3D NoNode for /solr/live_nodes/127.0.0.1:37410_fbvf%2Fq [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.188; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:37410_fbvf%2Fq [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.190; 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-01 02:25:13.191; 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-01 02:25:13.190; 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-01 02:25:13.191; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.191; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.191; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.192; 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-01 02:25:13.192; 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-01 02:25:13.192; 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-01 02:25:13.193; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.193; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.193; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.197; org.apache.solr.core.= CoreContainer; Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/= jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.= apache.solr.cloud.BasicDistributedZk2Test-jetty4-1364783112056/collection1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.197; org.apache.solr.cloud= .ZkController; Check for collection zkNode:collection1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.198; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.198; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/collection1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.199; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins= /workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.= solr.cloud.BasicDistributedZk2Test-jetty4-1364783112056/collection1/' [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.200; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x= -Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZ= k2Test-jetty4-1364783112056/collection1/lib/README' to classloader [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.200; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x= -Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZ= k2Test-jetty4-1364783112056/collection1/lib/classes/' to classloader [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.228; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_43 [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.263; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.264; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.268; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.653; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.665; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.668; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.677; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.680; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.683; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-01 02:25:13.684; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-01 02:25:13.684; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.685; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-01 02:25:13.685; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-01 02:25:13.686; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.686; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.686; org.apache.solr.core.= SolrCore; [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/= Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.= BasicDistributedZk2Test-jetty4-1364783112056/collection1/, dataDir=3D./org.= apache.solr.cloud.BasicDistributedZk2Test-1364783095878/jetty4/ [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.686; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@48c430 [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.687; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.687; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.B= asicDistributedZk2Test-1364783095878/jetty4 [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.688; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D./org.apache.solr.= cloud.BasicDistributedZk2Test-1364783095878/jetty4/index/ [junit4:junit4] 1> WARN - 2013-04-01 02:25:13.688; org.apache.solr.core.= SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.Basic= DistributedZk2Test-1364783095878/jetty4/index' doesn't exist. Creating new = index... [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.688; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.B= asicDistributedZk2Test-1364783095878/jetty4/index [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.689; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@c3709c lockFactory=3Dorg.apache.lucene.store.NativeFSLockFact= ory@196cf2c),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.689; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.691; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.691; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.691; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.692; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.692; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.693; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.693; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.693; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.694; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.696; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.699; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@17981ff main [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.699; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D./org.apache.solr.cloud.Bas= icDistributedZk2Test-1364783095878/jetty4/tlog [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.699; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.700; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.704; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@17981ff main{Stand= ardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.706; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Ddown [junit4:junit4] 1> INFO - 2013-04-01 02:25:13.706; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-01 02:25:14.375; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:14.375; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "core_node_name":null, [junit4:junit4] 1> "node_name":"127.0.0.1:37410_fbvf%2Fq", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "shard":null, [junit4:junit4] 1> "base_url":"http://127.0.0.1:37410/fbvf/q", [junit4:junit4] 1> "state":"down", [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "collection":"collection1"} [junit4:junit4] 1> INFO - 2013-04-01 02:25:14.376; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Collection already exists with numShards=3D2 [junit4:junit4] 1> INFO - 2013-04-01 02:25:14.376; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Assigning new node to shard shard=3Dshard2 [junit4:junit4] 1> INFO - 2013-04-01 02:25:14.427; 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-01 02:25:14.428; 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-01 02:25:14.427; 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-01 02:25:14.427; 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-01 02:25:14.427; 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-01 02:25:14.427; 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-01 02:25:14.707; org.apache.solr.core.= CoreContainer; registering core: collection1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:14.708; org.apache.solr.cloud= .ZkController; Register replica - core:collection1 address:http://127.0.0.1= :37410/fbvf/q collection:collection1 shard:shard2 [junit4:junit4] 1> INFO - 2013-04-01 02:25:14.710; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:37410/fbvf/q/collection1/ and leader= is http://127.0.0.1:53193/fbvf/q/collection1/ [junit4:junit4] 1> INFO - 2013-04-01 02:25:14.710; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dcollection1 baseURL=3Dhttp://= 127.0.0.1:37410/fbvf/q [junit4:junit4] 1> INFO - 2013-04-01 02:25:14.711; org.apache.solr.cloud= .ZkController; Core needs to recover:collection1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:14.711; org.apache.solr.updat= e.DefaultSolrCoreState; Running recovery - first canceling any ongoing reco= very [junit4:junit4] 1> INFO - 2013-04-01 02:25:14.712; org.apache.solr.cloud= .RecoveryStrategy; Starting recovery process. core=3Dcollection1 recoverin= gAfterStartup=3Dtrue [junit4:junit4] 1> INFO - 2013-04-01 02:25:14.712; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:14.712; org.apache.solr.cloud= .RecoveryStrategy; ###### startupVersions=3D[] [junit4:junit4] 1> INFO - 2013-04-01 02:25:14.712; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Drecovering [junit4:junit4] 1> INFO - 2013-04-01 02:25:14.713; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-01 02:25:14.713; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/mnt/ssd/jenkins/workspace/Lucene-Solr-4.= x-Linux/solr/build/solr-core/test/J1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:14.714; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-01 02:25:14.713; 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-01 02:25:14.714; 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-01 02:25:14.718; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:14.720; 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-01 02:25:14.725; org.apache.solr.core.= CoreContainer; Creating SolrCore 'onenodecollectioncore' using instanceDir:= /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test= /J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1364783099333/on= enodecollectioncore [junit4:junit4] 1> INFO - 2013-04-01 02:25:14.725; org.apache.solr.cloud= .ZkController; Check for collection zkNode:onenodecollection [junit4:junit4] 1> INFO - 2013-04-01 02:25:14.726; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:onenodecollection [junit4:junit4] 1> INFO - 2013-04-01 02:25:14.726; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-01 02:25:14.727; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:14.727; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/onenodecollection [junit4:junit4] 1> INFO - 2013-04-01 02:25:14.729; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/onenodecollection [junit4:junit4] 1> INFO - 2013-04-01 02:25:14.730; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins= /workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.= solr.cloud.BasicDistributedZk2Test-jetty1-1364783099333/onenodecollectionco= re/' [junit4:junit4] 1> INFO - 2013-04-01 02:25:14.769; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_43 [junit4:junit4] 1> INFO - 2013-04-01 02:25:14.808; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-01 02:25:14.809; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema [junit4:junit4] 1> INFO - 2013-04-01 02:25:14.813; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.061; org.apache.solr.cloud= .RecoveryStrategy; Attempting to PeerSync from http://127.0.0.1:60563/fbvf/= q/collection1/ core=3Dcollection1 - recoveringAfterStartup=3Dtrue [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.062; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dcollection1 url=3Dhttp://127.0.0.1:44591/fbvf/= q START replicas=3D[http://127.0.0.1:60563/fbvf/q/collection1/] nUpdates=3D= 100 [junit4:junit4] 1> WARN - 2013-04-01 02:25:15.062; org.apache.solr.updat= e.PeerSync; no frame of reference to tell of we've missed updates [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.063; org.apache.solr.cloud= .RecoveryStrategy; PeerSync Recovery was not successful - trying replicatio= n. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.063; org.apache.solr.cloud= .RecoveryStrategy; Starting Replication Recovery. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.064; org.apache.solr.cloud= .RecoveryStrategy; Begin buffering updates. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.064; org.apache.solr.updat= e.UpdateLog; Starting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog= =3Dnull} [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.064; org.apache.solr.cloud= .RecoveryStrategy; Attempting to replicate from http://127.0.0.1:60563/fbvf= /q/collection1/. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.064; 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-01 02:25:15.068; org.apache.solr.core.= SolrCore; [collection1] webapp=3D/fbvf/q path=3D/get params=3D{version=3D2&= qt=3D/get&wt=3Djavabin&getVersions=3D100&distrib=3Dfalse} status=3D0 QTime= =3D0=20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.069; 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-01 02:25:15.071; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@b9db0b lockFactory=3Dorg.apache.lucene.store.NativeFSLockFact= ory@df761b),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.071; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.072; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@b9db0b lockFactory=3Dorg.apache.lucene.store.NativeFSLockFact= ory@df761b),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@b9db0b lockFactory=3Dorg.apache.lucene.store.NativeFSLockFact= ory@df761b),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_2] [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.072; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 2[segments_2] [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.073; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@155e778 realtime [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.074; org.apache.solr.updat= e.DirectUpdateHandler2; end_commit_flush [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.074; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/fbvf/q path=3D/upda= te params=3D{commit_end_point=3Dtrue&commit=3Dtrue&version=3D2&wt=3Djavabin= &waitSearcher=3Dtrue&softCommit=3Dfalse&openSearcher=3Dfalse} {commit=3D} 0= 5 [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.075; org.apache.solr.handl= er.ReplicationHandler; Commits will be reserved for 10000 [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.075; org.apache.solr.handl= er.SnapPuller; No value set for 'pollInterval'. Timer Task not started. [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.083; org.apache.solr.handl= er.ReplicationHandler; Commits will be reserved for 10000 [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.083; org.apache.solr.core.= SolrCore; [collection1] webapp=3D/fbvf/q path=3D/replication params=3D{vers= ion=3D2&qt=3D/replication&wt=3Djavabin&command=3Dindexversion} status=3D0 Q= Time=3D7=20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.084; org.apache.solr.handl= er.SnapPuller; Master's generation: 2 [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.084; org.apache.solr.handl= er.SnapPuller; Slave's generation: 1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.084; org.apache.solr.handl= er.SnapPuller; Starting replication process [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.086; org.apache.solr.core.= SolrCore; [collection1] webapp=3D/fbvf/q path=3D/replication params=3D{vers= ion=3D2&qt=3D/replication&wt=3Djavabin&command=3Dfilelist&generation=3D2} s= tatus=3D0 QTime=3D0=20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.086; org.apache.solr.handl= er.SnapPuller; Number of files in latest index in master: 1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.087; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.B= asicDistributedZk2Test-1364783095878/jetty3/index.20130331222515087 [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.087; org.apache.solr.handl= er.SnapPuller; Starting download to MockDirWrapper(org.apache.lucene.store.= RAMDirectory@103ec6a lockFactory=3Dorg.apache.lucene.store.NativeFSLockFact= ory@692f03) fullCopy=3Dfalse [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.089; org.apache.solr.core.= SolrCore; [collection1] webapp=3D/fbvf/q path=3D/replication params=3D{file= =3Dsegments_2&qt=3D/replication&wt=3Dfilestream&command=3Dfilecontent&gener= ation=3D2&checksum=3Dtrue} status=3D0 QTime=3D0=20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.091; org.apache.solr.handl= er.SnapPuller; Total time taken for download : 0 secs [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.092; org.apache.solr.updat= e.DefaultSolrCoreState; Creating new IndexWriter... [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.092; org.apache.solr.updat= e.DefaultSolrCoreState; Waiting until IndexWriter is unused... core=3Dcolle= ction1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.093; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits:num=3D2 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@d6e342 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFact= ory@23c9b),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@d6e342 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFact= ory@23c9b),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_2] [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.093; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 2[segments_2] [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.094; org.apache.solr.updat= e.DefaultSolrCoreState; New IndexWriter is ready to be used. [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.094; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@c27f8 main [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.095; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@c27f8 main{Standar= dDirectoryReader(segments_2:1:nrt)} [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.096; org.apache.solr.core.= CachingDirectoryFactory; looking to close ./org.apache.solr.cloud.BasicDist= ributedZk2Test-1364783095878/jetty3/index.20130331222515087 [CachedDir<>] [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.096; org.apache.solr.core.= CachingDirectoryFactory; Closing directory: ./org.apache.solr.cloud.BasicDi= stributedZk2Test-1364783095878/jetty3/index.20130331222515087 [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.096; org.apache.solr.core.= CachingDirectoryFactory; Removing directory before core close: ./org.apache= .solr.cloud.BasicDistributedZk2Test-1364783095878/jetty3/index.201303312225= 15087 [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.097; org.apache.solr.cloud= .RecoveryStrategy; No replay needed. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.097; org.apache.solr.cloud= .RecoveryStrategy; Replication Recovery was successful - registering as Act= ive. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.097; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Dactive [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.097; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.098; org.apache.solr.cloud= .RecoveryStrategy; Finished recovery process. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.217; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.223; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.226; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.236; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.239; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.242; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-01 02:25:15.243; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-01 02:25:15.244; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.244; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-01 02:25:15.245; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-01 02:25:15.245; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.245; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.246; org.apache.solr.core.= SolrCore; [onenodecollectioncore] Opening new SolrCore at /mnt/ssd/jenkins/= workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.s= olr.cloud.BasicDistributedZk2Test-jetty1-1364783099333/onenodecollectioncor= e/, dataDir=3D/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/s= olr-core/test/J1/./solrtest-BasicDistributedZk2Test-1364783095878/onenodeco= llection/ [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.246; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@48c430 [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.247; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.247; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspac= e/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistri= butedZk2Test-1364783095878/onenodecollection [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.248; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D/mnt/ssd/jenkins/w= orkspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-Basi= cDistributedZk2Test-1364783095878/onenodecollection/index/ [junit4:junit4] 1> WARN - 2013-04-01 02:25:15.248; org.apache.solr.core.= SolrCore; [onenodecollectioncore] Solr index directory '/mnt/ssd/jenkins/wo= rkspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-Basic= DistributedZk2Test-1364783095878/onenodecollection/index' doesn't exist. Cr= eating new index... [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.248; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspac= e/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistri= butedZk2Test-1364783095878/onenodecollection/index [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.250; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@1cd321e lockFactory=3Dorg.apache.lucene.store.NativeFSLockFac= tory@1a154d9),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.250; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.251; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.252; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.252; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.253; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.253; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.254; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.254; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.254; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.255; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.257; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.260; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@134685a main [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.260; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D/mnt/ssd/jenkins/workspace/= Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistribu= tedZk2Test-1364783095878/onenodecollection/tlog [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.261; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.261; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.264; org.apache.solr.core.= SolrCore; [onenodecollectioncore] Registered new searcher Searcher@134685a = main{StandardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.266; org.apache.solr.cloud= .ZkController; publishing core=3Donenodecollectioncore state=3Ddown [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.932; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.932; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "core_node_name":"127.0.0.1:37410_fbvf%2Fq_collectio= n1", [junit4:junit4] 1> "node_name":"127.0.0.1:37410_fbvf%2Fq", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "shard":"shard2", [junit4:junit4] 1> "base_url":"http://127.0.0.1:37410/fbvf/q", [junit4:junit4] 1> "state":"recovering", [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "collection":"collection1"} [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.935; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "core_node_name":"127.0.0.1:44591_fbvf%2Fq_collectio= n1", [junit4:junit4] 1> "node_name":"127.0.0.1:44591_fbvf%2Fq", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "shard":"shard1", [junit4:junit4] 1> "base_url":"http://127.0.0.1:44591/fbvf/q", [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "collection":"collection1"} [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.938; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D1 message=3D{ [junit4:junit4] 1> "core_node_name":null, [junit4:junit4] 1> "node_name":"127.0.0.1:60563_fbvf%2Fq", [junit4:junit4] 1> "core":"onenodecollectioncore", [junit4:junit4] 1> "numShards":"1", [junit4:junit4] 1> "roles":"none", [junit4:junit4] 1> "shard":null, [junit4:junit4] 1> "base_url":"http://127.0.0.1:60563/fbvf/q", [junit4:junit4] 1> "state":"down", [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "collection":"onenodecollection"} [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.938; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Create collection onenodecollection with num= Shards 1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.938; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Assigning new node to shard shard=3Dshard1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:15.941; 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-01 02:25:15.942; 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-01 02:25:15.942; 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-01 02:25:15.942; 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-01 02:25:15.941; 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-01 02:25:15.941; 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-01 02:25:16.268; org.apache.solr.core.= CoreContainer; registering core: onenodecollectioncore [junit4:junit4] 1> INFO - 2013-04-01 02:25:16.269; org.apache.solr.cloud= .ZkController; Register replica - core:onenodecollectioncore address:http:/= /127.0.0.1:60563/fbvf/q collection:onenodecollection shard:shard1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:16.270; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/onenodecollection/leader_elect= /shard1/election [junit4:junit4] 1> INFO - 2013-04-01 02:25:16.274; org.apache.zookeeper.= server.PrepRequestProcessor; Got user-level KeeperException when processing= sessionid:0x13dc369604a0006 type:delete cxid:0xac zxid:0xc2 txntype:-1 req= path:n/a Error Path:/solr/collections/onenodecollection/leaders Error:Keepe= rErrorCode =3D NoNode for /solr/collections/onenodecollection/leaders [junit4:junit4] 1> INFO - 2013-04-01 02:25:16.274; org.apache.solr.cloud= .ShardLeaderElectionContext; Running the leader process. [junit4:junit4] 1> INFO - 2013-04-01 02:25:16.275; org.apache.zookeeper.= server.PrepRequestProcessor; Got user-level KeeperException when processing= sessionid:0x13dc369604a0006 type:create cxid:0xad zxid:0xc3 txntype:-1 req= path:n/a Error Path:/solr/overseer Error:KeeperErrorCode =3D NodeExists for= /solr/overseer [junit4:junit4] 1> INFO - 2013-04-01 02:25:16.277; org.apache.solr.cloud= .ShardLeaderElectionContext; Enough replicas found to continue. [junit4:junit4] 1> INFO - 2013-04-01 02:25:16.277; org.apache.solr.cloud= .ShardLeaderElectionContext; I may be the new leader - try and sync [junit4:junit4] 1> INFO - 2013-04-01 02:25:16.277; org.apache.solr.cloud= .SyncStrategy; Sync replicas to http://127.0.0.1:60563/fbvf/q/onenodecollec= tioncore/ [junit4:junit4] 1> INFO - 2013-04-01 02:25:16.278; org.apache.solr.cloud= .SyncStrategy; Sync Success - now sync replicas to me [junit4:junit4] 1> INFO - 2013-04-01 02:25:16.278; org.apache.solr.cloud= .SyncStrategy; http://127.0.0.1:60563/fbvf/q/onenodecollectioncore/ has no = replicas [junit4:junit4] 1> INFO - 2013-04-01 02:25:16.279; org.apache.solr.cloud= .ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:60563/fb= vf/q/onenodecollectioncore/ [junit4:junit4] 1> INFO - 2013-04-01 02:25:16.279; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/onenodecollection/leaders/shar= d1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:16.282; org.apache.zookeeper.= server.PrepRequestProcessor; Got user-level KeeperException when processing= sessionid:0x13dc369604a0006 type:create cxid:0xb8 zxid:0xc7 txntype:-1 req= path:n/a Error Path:/solr/overseer Error:KeeperErrorCode =3D NodeExists for= /solr/overseer [junit4:junit4] 1> INFO - 2013-04-01 02:25:16.718; org.apache.solr.servl= et.SolrDispatchFilter; [admin] webapp=3Dnull path=3D/admin/cores params=3D{= core=3Dcollection1&version=3D2&wt=3Djavabin&onlyIfLeader=3Dtrue&state=3Drec= overing&nodeName=3D127.0.0.1:37410_fbvf%252Fq&checkLive=3Dtrue&action=3DPRE= PRECOVERY&coreNodeName=3D127.0.0.1:37410_fbvf%252Fq_collection1} status=3D0= QTime=3D2000=20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:17.449; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:17.455; 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-01 02:25:17.455; 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-01 02:25:17.455; 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-01 02:25:17.455; 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-01 02:25:17.455; 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-01 02:25:17.455; 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-01 02:25:17.485; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:60563/fbvf/q/onenodecollectioncore/ = and leader is http://127.0.0.1:60563/fbvf/q/onenodecollectioncore/ [junit4:junit4] 1> INFO - 2013-04-01 02:25:17.486; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Donenodecollectioncore baseURL= =3Dhttp://127.0.0.1:60563/fbvf/q [junit4:junit4] 1> INFO - 2013-04-01 02:25:17.486; org.apache.solr.cloud= .ZkController; I am the leader, no recovery necessary [junit4:junit4] 1> INFO - 2013-04-01 02:25:17.487; org.apache.solr.cloud= .ZkController; publishing core=3Donenodecollectioncore state=3Dactive [junit4:junit4] 1> INFO - 2013-04-01 02:25:17.488; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:17.489; org.apache.solr.servl= et.SolrDispatchFilter; [admin] webapp=3Dnull path=3D/admin/cores params=3D{= version=3D2&numShards=3D1&roles=3Dnone&dataDir=3D/mnt/ssd/jenkins/workspace= /Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistrib= utedZk2Test-1364783095878/onenodecollection&wt=3Djavabin&name=3Donenodecoll= ectioncore&action=3DCREATE&collection=3Donenodecollection} status=3D0 QTime= =3D2764=20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:17.490; org.apache.solr.cloud= .AbstractDistribZkTestBase; Wait for recoveries to finish - collection: one= nodecollection failOnTimeout:true timeout (sec):230 [junit4:junit4] 1> INFO - 2013-04-01 02:25:17.493; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:18.494; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:18.719; org.apache.solr.cloud= .RecoveryStrategy; Attempting to PeerSync from http://127.0.0.1:53193/fbvf/= q/collection1/ core=3Dcollection1 - recoveringAfterStartup=3Dtrue [junit4:junit4] 1> INFO - 2013-04-01 02:25:18.720; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dcollection1 url=3Dhttp://127.0.0.1:37410/fbvf/= q START replicas=3D[http://127.0.0.1:53193/fbvf/q/collection1/] nUpdates=3D= 100 [junit4:junit4] 1> WARN - 2013-04-01 02:25:18.721; org.apache.solr.updat= e.PeerSync; no frame of reference to tell of we've missed updates [junit4:junit4] 1> INFO - 2013-04-01 02:25:18.721; org.apache.solr.cloud= .RecoveryStrategy; PeerSync Recovery was not successful - trying replicatio= n. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:18.722; org.apache.solr.cloud= .RecoveryStrategy; Starting Replication Recovery. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:18.722; org.apache.solr.cloud= .RecoveryStrategy; Begin buffering updates. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:18.722; org.apache.solr.updat= e.UpdateLog; Starting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog= =3Dnull} [junit4:junit4] 1> INFO - 2013-04-01 02:25:18.723; org.apache.solr.cloud= .RecoveryStrategy; Attempting to replicate from http://127.0.0.1:53193/fbvf= /q/collection1/. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:18.723; 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-01 02:25:18.728; org.apache.solr.core.= SolrCore; [collection1] webapp=3D/fbvf/q path=3D/get params=3D{version=3D2&= qt=3D/get&wt=3Djavabin&getVersions=3D100&distrib=3Dfalse} status=3D0 QTime= =3D0=20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:18.729; 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-01 02:25:18.730; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@1713f16 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFac= tory@81df03),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-01 02:25:18.731; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-01 02:25:18.731; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@1713f16 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFac= tory@81df03),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@1713f16 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFac= tory@81df03),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_2] [junit4:junit4] 1> INFO - 2013-04-01 02:25:18.732; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 2[segments_2] [junit4:junit4] 1> INFO - 2013-04-01 02:25:18.732; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@ec4f17 realtime [junit4:junit4] 1> INFO - 2013-04-01 02:25:18.732; org.apache.solr.updat= e.DirectUpdateHandler2; end_commit_flush [junit4:junit4] 1> INFO - 2013-04-01 02:25:18.733; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/fbvf/q path=3D/upda= te params=3D{commit_end_point=3Dtrue&commit=3Dtrue&version=3D2&wt=3Djavabin= &waitSearcher=3Dtrue&softCommit=3Dfalse&openSearcher=3Dfalse} {commit=3D} 0= 4 [junit4:junit4] 1> INFO - 2013-04-01 02:25:18.733; org.apache.solr.handl= er.ReplicationHandler; Commits will be reserved for 10000 [junit4:junit4] 1> INFO - 2013-04-01 02:25:18.734; org.apache.solr.handl= er.SnapPuller; No value set for 'pollInterval'. Timer Task not started. [junit4:junit4] 1> INFO - 2013-04-01 02:25:18.735; org.apache.solr.handl= er.ReplicationHandler; Commits will be reserved for 10000 [junit4:junit4] 1> INFO - 2013-04-01 02:25:18.735; org.apache.solr.core.= SolrCore; [collection1] webapp=3D/fbvf/q path=3D/replication params=3D{vers= ion=3D2&qt=3D/replication&wt=3Djavabin&command=3Dindexversion} status=3D0 Q= Time=3D1=20 [junit4:junit4] 1> INFO - 2013-04-01 02:25:18.736; org.apache.solr.handl= er.SnapPuller; Master's generation: 2 [junit4:junit4] 1> INFO - 2013-04-01 02:25:18.736; org.apache.solr.handl= er.SnapPuller; Slave's generation: 1 [junit4:junit4] 1> INFO - 2013-04-01 02:25:18.736; org.apache.solr.handl= er.SnapPuller; Starting replication process [junit4:ju [...truncated too long message...] loser [junit4:junit4] 1> INFO - 2013-04-01 02:25:28.956; org.apache.solr.core.= SolrCore; [collection1] Closing main searcher on request. [junit4:junit4] 1> INFO - 2013-04-01 02:25:28.956; org.apache.solr.core.= CachingDirectoryFactory; Closing MockDirectoryFactory - 2 directories curre= ntly being tracked [junit4:junit4] 1> INFO - 2013-04-01 02:25:28.956; org.apache.solr.core.= CachingDirectoryFactory; looking to close ./org.apache.solr.cloud.BasicDist= ributedZk2Test-1364783095878/jetty4 [CachedDir<= >] [junit4:junit4] 1> INFO - 2013-04-01 02:25:28.957; org.apache.solr.core.= CachingDirectoryFactory; Closing directory: ./org.apache.solr.cloud.BasicDi= stributedZk2Test-1364783095878/jetty4 [junit4:junit4] 1> INFO - 2013-04-01 02:25:28.957; org.apache.solr.core.= CachingDirectoryFactory; looking to close ./org.apache.solr.cloud.BasicDist= ributedZk2Test-1364783095878/jetty4/index [CachedDir<>] [junit4:junit4] 1> INFO - 2013-04-01 02:25:28.957; org.apache.solr.core.= CachingDirectoryFactory; Closing directory: ./org.apache.solr.cloud.BasicDi= stributedZk2Test-1364783095878/jetty4/index [junit4:junit4] 1> INFO - 2013-04-01 02:25:28.958; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; According to ZK I (id=3D89442424971722764-12= 7.0.0.1:37410_fbvf%2Fq-n_0000000004) am no longer a leader. [junit4:junit4] 1> INFO - 2013-04-01 02:25:28.958; org.apache.zookeeper.= server.PrepRequestProcessor; Processed session termination for sessionid: 0= x13dc369604a000c [junit4:junit4] 1> INFO - 2013-04-01 02:25:28.959; 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-01 02:25:28.959; org.apache.zookeeper.= ZooKeeper; Session: 0x13dc369604a000c closed [junit4:junit4] 1> INFO - 2013-04-01 02:25:28.959; org.apache.zookeeper.= server.NIOServerCnxn; Closed socket connection for client /127.0.0.1:49276 = which had sessionid 0x13dc369604a000c [junit4:junit4] 1> WARN - 2013-04-01 02:25:28.960; org.apache.solr.commo= n.cloud.ZkStateReader$2; ZooKeeper watch triggered, but Solr cannot talk to= ZK [junit4:junit4] 1> WARN - 2013-04-01 02:25:28.960; org.apache.solr.commo= n.cloud.ZkStateReader$3; ZooKeeper watch triggered, but Solr cannot talk to= ZK [junit4:junit4] 1> INFO - 2013-04-01 02:25:28.961; org.apache.zookeeper.= ClientCnxn$EventThread; EventThread shut down [junit4:junit4] 1> INFO - 2013-04-01 02:25:28.982; org.eclipse.jetty.ser= ver.handler.ContextHandler; stopped o.e.j.s.ServletContextHandler{/fbvf/q,n= ull} [junit4:junit4] 1> INFO - 2013-04-01 02:25:29.036; org.apache.solr.SolrT= estCaseJ4; ###Ending testDistribSearch [junit4:junit4] 1> INFO - 2013-04-01 02:25:29.037; org.apache.zookeeper.= server.ZooKeeperServer; shutting down [junit4:junit4] 1> INFO - 2013-04-01 02:25:29.037; org.apache.zookeeper.= server.SessionTrackerImpl; Shutting down [junit4:junit4] 1> INFO - 2013-04-01 02:25:29.037; org.apache.zookeeper.= server.PrepRequestProcessor; Shutting down [junit4:junit4] 1> INFO - 2013-04-01 02:25:29.038; org.apache.zookeeper.= server.SyncRequestProcessor; Shutting down [junit4:junit4] 1> INFO - 2013-04-01 02:25:29.038; org.apache.zookeeper.= server.PrepRequestProcessor; PrepRequestProcessor exited loop! [junit4:junit4] 1> INFO - 2013-04-01 02:25:29.038; org.apache.zookeeper.= server.SyncRequestProcessor; SyncRequestProcessor exited! [junit4:junit4] 1> INFO - 2013-04-01 02:25:29.039; org.apache.zookeeper.= server.FinalRequestProcessor; shutdown of request processor complete [junit4:junit4] 1> INFO - 2013-04-01 02:25:29.040; org.apache.solr.cloud= .ZkTestServer; connecting to 127.0.0.1:58488 58488 [junit4:junit4] 1> INFO - 2013-04-01 02:25:29.041; org.apache.zookeeper.= server.NIOServerCnxnFactory; NIOServerCnxn factory exited run method [junit4:junit4] 1> INFO - 2013-04-01 02:25:29.042; org.apache.zookeeper.= server.ZooKeeperServer; shutting down [junit4:junit4] 1> INFO - 2013-04-01 02:25:29.042; org.apache.zookeeper.= server.SessionTrackerImpl; Shutting down [junit4:junit4] 1> INFO - 2013-04-01 02:25:29.042; org.apache.zookeeper.= server.PrepRequestProcessor; Shutting down [junit4:junit4] 1> INFO - 2013-04-01 02:25:29.042; org.apache.zookeeper.= server.SyncRequestProcessor; Shutting down [junit4:junit4] 1> INFO - 2013-04-01 02:25:29.043; org.apache.zookeeper.= server.FinalRequestProcessor; shutdown of request processor complete [junit4:junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-So= lr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Tes= t-1364783095878 [junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=3DBasicDist= ributedZk2Test -Dtests.method=3DtestDistribSearch -Dtests.seed=3DD899F88634= ED3C -Dtests.multiplier=3D3 -Dtests.slow=3Dtrue -Dtests.locale=3Dno_NO -Dte= sts.timezone=3DUS/Eastern -Dtests.file.encoding=3DISO-8859-1 [junit4:junit4] ERROR 33.2s J1 | BasicDistributedZk2Test.testDistribSearc= h <<< [junit4:junit4] > Throwable #1: org.apache.solr.common.SolrException: Se= rver at http://127.0.0.1:53193/fbvf/q/onenodecollectioncore returned non ok= status:404, message:Can not find: /fbvf/q/onenodecollectioncore/update [junit4:junit4] > =09at __randomizedtesting.SeedInfo.seed([D899F88634ED3= C:813E17E0F16B8D00]: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-01 02:25:29.055; org.apache.solr.SolrT= estCaseJ4; ###deleteCore [junit4:junit4] 2> 33185 T1733 ccr.ThreadLeakControl.checkThreadLeaks WAR= NING Will linger awaiting termination of 2 leaked thread(s). [junit4:junit4] 1> INFO - 2013-04-01 02:25:30.000; org.apache.zookeeper.= server.SessionTrackerImpl; SessionTrackerImpl exited loop! [junit4:junit4] 2> NOTE: test params are: codec=3DSimpleText, sim=3DRando= mSimilarityProvider(queryNorm=3Dfalse,coord=3Dyes): {}, locale=3Dno_NO, tim= ezone=3DUS/Eastern [junit4:junit4] 2> NOTE: Linux 3.2.0-39-generic i386/Oracle Corporation 1= .8.0-ea (32-bit)/cpus=3D8,threads=3D2,free=3D12351784,total=3D275906560 [junit4:junit4] 2> NOTE: All tests run in this JVM: [TestJmxIntegration, = TestPropInject, DirectUpdateHandlerTest, RequiredFieldsTest, TestSuggestSpe= llingConverter, CopyFieldTest, TestQuerySenderNoQuery, DisMaxRequestHandler= Test, TestRTGBase, DOMUtilTest, TestBinaryField, TestElisionMultitermQuery,= SampleTest, SimplePostToolTest, TestStressReorder, ZkNodePropsTest, CoreCo= ntainerCoreInitFailuresTest, TestCodecSupport, TestComponentsName, TestSolr= 4Spatial, SuggesterWFSTTest, TestSchemaResource, OutputWriterTest, TestFiel= dTypeResource, TestUniqueKeyFieldResource, SpellCheckCollatorTest, HardAuto= CommitTest, FieldAnalysisRequestHandlerTest, TestRandomFaceting, DocValuesM= ultiTest, TimeZoneUtilsTest, UniqFieldsUpdateProcessorFactoryTest, IndexSch= emaRuntimeFieldTest, RequestHandlersTest, TestCopyFieldCollectionResource, = SolrRequestParserTest, SolrCmdDistributorTest, SolrIndexConfigTest, XmlUpda= teRequestHandlerTest, TestCollationField, OpenExchangeRatesOrgProviderTest,= MultiTermTest, TestFoldingMultitermQuery, SpellCheckComponentTest, SolrCor= eCheckLockOnStartupTest, ChaosMonkeySafeLeaderTest, BadIndexSchemaTest, Tes= tLazyCores, TestBM25SimilarityFactory, BadCopyFieldTest, SolrPluginUtilsTes= t, TestSchemaNameResource, SpellPossibilityIteratorTest, TestZkChroot, Test= CSVLoader, HighlighterConfigTest, TestDistributedSearch, TestJmxMonitoredMa= p, TestHashPartitioner, TestAtomicUpdateErrorCases, DebugComponentTest, Col= lectionsAPIDistributedZkTest, TestBinaryResponseWriter, DateMathParserTest,= TestSchemaSimilarityResource, BasicDistributedZk2Test] [junit4:junit4] Completed on J1 in 34.22s, 1 test, 1 error <<< FAILURES! [...truncated 453 lines...] BUILD FAILED /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:381: The followi= ng error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:361: The followi= ng error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The followin= g error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:183: The fo= llowing error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:448:= The following error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:12= 34: The following error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:87= 8: There were test failures: 283 suites, 1167 tests, 1 error, 13 ignored (7= assumptions) Total time: 41 minutes 51 seconds Build step 'Invoke Ant' marked build as failure Archiving artifacts Recording test results Description set: Java: 32bit/jdk1.8.0-ea-b82 -client -XX:+UseParallelGC Email was triggered for: Failure Sending email for trigger: Failure ------=_Part_48_2133941408.1364783626537 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_48_2133941408.1364783626537--