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 C1469E0AC for ; Wed, 20 Feb 2013 21:17:18 +0000 (UTC) Received: (qmail 69183 invoked by uid 500); 20 Feb 2013 21:17:17 -0000 Delivered-To: apmail-lucene-dev-archive@lucene.apache.org Received: (qmail 69129 invoked by uid 500); 20 Feb 2013 21:17:16 -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 69119 invoked by uid 99); 20 Feb 2013 21:17:16 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 20 Feb 2013 21:17:16 +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 (athena.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; Wed, 20 Feb 2013 21:17:00 +0000 Received: from serv1 (localhost.localdomain [127.0.0.1]) by mail.sd-datasolutions.de (Postfix) with ESMTP id BE36914AA054; Wed, 20 Feb 2013 21:16:37 +0000 (UTC) Date: Wed, 20 Feb 2013 21:16:23 +0000 (UTC) From: Policeman Jenkins Server To: dev@lucene.apache.org, rmuir@apache.org Message-ID: <329482793.13.1361394997752.JavaMail.jenkins@serv1.sd-datasolutions.de> In-Reply-To: <1578575492.9.1361389786666.JavaMail.jenkins@serv1.sd-datasolutions.de> References: <1578575492.9.1361389786666.JavaMail.jenkins@serv1.sd-datasolutions.de> Subject: [JENKINS] Lucene-Solr-4.x-Linux (64bit/jdk1.8.0-ea-b65) - Build # 4378 - Still Failing! MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="----=_Part_12_1981595989.1361394983777" X-Jenkins-Job: Lucene-Solr-4.x-Linux X-Jenkins-Result: FAILURE X-Virus-Checked: Checked by ClamAV on apache.org ------=_Part_12_1981595989.1361394983777 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/4378/ Java: 64bit/jdk1.8.0-ea-b65 -XX:+UseConcMarkSweepGC 1 tests failed. REGRESSION: org.apache.solr.cloud.UnloadDistributedZkTest.testDistribSearc= h Error Message: Still found shard Stack Trace: java.lang.AssertionError: Still found shard =09at __randomizedtesting.SeedInfo.seed([A50D0AA4BB55AA8F:24EB84BCCC0ACAB3]= :0) =09at org.junit.Assert.fail(Assert.java:93) =09at org.apache.solr.cloud.UnloadDistributedZkTest.testUnloadShardAndColle= ction(UnloadDistributedZkTest.java:120) =09at org.apache.solr.cloud.UnloadDistributedZkTest.doTest(UnloadDistribute= dZkTest.java:73) =09at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseD= istributedSearchTestCase.java:794) =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:474) =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 9597 lines...] [junit4:junit4] Suite: org.apache.solr.cloud.UnloadDistributedZkTest [junit4:junit4] 2> 1 T3230 oas.BaseDistributedSearchTestCase.initHostCont= ext Setting hostContext system property: / [junit4:junit4] 2> 3 T3230 oas.SolrTestCaseJ4.setUp ###Starting testDistr= ibSearch [junit4:junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-So= lr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTes= t-1361394843259 [junit4:junit4] 2> 4 T3230 oasc.ZkTestServer.run STARTING ZK TEST SERVER [junit4:junit4] 2> 4 T3231 oasc.ZkTestServer$ZKServerMain.runFromConfig S= tarting server [junit4:junit4] 2> 6 T3231 oazs.ZooKeeperServer.setTickTime tickTime set = to 1000 [junit4:junit4] 2> 6 T3231 oazs.ZooKeeperServer.setMinSessionTimeout minS= essionTimeout set to -1 [junit4:junit4] 2> 6 T3231 oazs.ZooKeeperServer.setMaxSessionTimeout maxS= essionTimeout set to -1 [junit4:junit4] 2> 6 T3231 oazs.NIOServerCnxnFactory.configure binding to= port 0.0.0.0/0.0.0.0:0 [junit4:junit4] 2> 7 T3231 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to= /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test= /J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361394843258/zookeeper= /server1/data/version-2/snapshot.0 [junit4:junit4] 2> 104 T3230 oasc.ZkTestServer.run start zk server on por= t:35536 [junit4:junit4] 2> 105 T3230 oaz.ZooKeeper. Initiating client conne= ction, connectString=3D127.0.0.1:35536 sessionTimeout=3D10000 watcher=3Dorg= .apache.solr.common.cloud.ConnectionManager@3f9f2f87 [junit4:junit4] 2> 106 T3236 oaz.ClientCnxn$SendThread.logStartConnect Op= ening socket connection to server localhost.localdomain/127.0.0.1:35536. Wi= ll not attempt to authenticate using SASL (access denied ("javax.security.a= uth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 2> 106 T3230 oascc.ConnectionManager.waitForConnected Wai= ting for client to connect to ZooKeeper [junit4:junit4] 2> 107 T3236 oaz.ClientCnxn$SendThread.primeConnection So= cket connection established to localhost.localdomain/127.0.0.1:35536, initi= ating session [junit4:junit4] 2> 107 T3232 oazs.NIOServerCnxnFactory.run Accepted socke= t connection from /127.0.0.1:51778 [junit4:junit4] 2> 107 T3232 oazs.ZooKeeperServer.processConnectRequest C= lient attempting to establish new session at /127.0.0.1:51778 [junit4:junit4] 2> 108 T3234 oazsp.FileTxnLog.append Creating new log fil= e: log.1 [junit4:junit4] 2> 110 T3234 oazs.ZooKeeperServer.finishSessionInit Estab= lished session 0x13cf974be7e0000 with negotiated timeout 10000 for client /= 127.0.0.1:51778 [junit4:junit4] 2> 110 T3236 oaz.ClientCnxn$SendThread.onConnected Sessio= n establishment complete on server localhost.localdomain/127.0.0.1:35536, s= essionid =3D 0x13cf974be7e0000, negotiated timeout =3D 10000 [junit4:junit4] 2> 111 T3237 oascc.ConnectionManager.process Watcher org.= apache.solr.common.cloud.ConnectionManager@3f9f2f87 name:ZooKeeperConnectio= n Watcher:127.0.0.1:35536 got event WatchedEvent state:SyncConnected type:N= one path:null path:null type:None [junit4:junit4] 2> 111 T3230 oascc.ConnectionManager.waitForConnected Cli= ent is connected to ZooKeeper [junit4:junit4] 2> 112 T3230 oascc.SolrZkClient.makePath makePath: /solr [junit4:junit4] 2> 116 T3235 oazs.PrepRequestProcessor.pRequest2Txn Proce= ssed session termination for sessionid: 0x13cf974be7e0000 [junit4:junit4] 2> 116 T3237 oaz.ClientCnxn$EventThread.run EventThread s= hut down [junit4:junit4] 2> 117 T3232 oazs.NIOServerCnxn.closeSock Closed socket c= onnection for client /127.0.0.1:51778 which had sessionid 0x13cf974be7e0000 [junit4:junit4] 2> 116 T3230 oaz.ZooKeeper.close Session: 0x13cf974be7e00= 00 closed [junit4:junit4] 2> 118 T3230 oaz.ZooKeeper. Initiating client conne= ction, connectString=3D127.0.0.1:35536/solr sessionTimeout=3D10000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@7e21d032 [junit4:junit4] 2> 119 T3230 oascc.ConnectionManager.waitForConnected Wai= ting for client to connect to ZooKeeper [junit4:junit4] 2> 120 T3238 oaz.ClientCnxn$SendThread.logStartConnect Op= ening socket connection to server localhost.localdomain/127.0.0.1:35536. Wi= ll not attempt to authenticate using SASL (access denied ("javax.security.a= uth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 2> 120 T3238 oaz.ClientCnxn$SendThread.primeConnection So= cket connection established to localhost.localdomain/127.0.0.1:35536, initi= ating session [junit4:junit4] 2> 120 T3232 oazs.NIOServerCnxnFactory.run Accepted socke= t connection from /127.0.0.1:51779 [junit4:junit4] 2> 121 T3232 oazs.ZooKeeperServer.processConnectRequest C= lient attempting to establish new session at /127.0.0.1:51779 [junit4:junit4] 2> 121 T3234 oazs.ZooKeeperServer.finishSessionInit Estab= lished session 0x13cf974be7e0001 with negotiated timeout 10000 for client /= 127.0.0.1:51779 [junit4:junit4] 2> 121 T3238 oaz.ClientCnxn$SendThread.onConnected Sessio= n establishment complete on server localhost.localdomain/127.0.0.1:35536, s= essionid =3D 0x13cf974be7e0001, negotiated timeout =3D 10000 [junit4:junit4] 2> 122 T3239 oascc.ConnectionManager.process Watcher org.= apache.solr.common.cloud.ConnectionManager@7e21d032 name:ZooKeeperConnectio= n Watcher:127.0.0.1:35536/solr got event WatchedEvent state:SyncConnected t= ype:None path:null path:null type:None [junit4:junit4] 2> 122 T3230 oascc.ConnectionManager.waitForConnected Cli= ent is connected to ZooKeeper [junit4:junit4] 2> 123 T3230 oascc.SolrZkClient.makePath makePath: /colle= ctions/collection1 [junit4:junit4] 2> 129 T3230 oascc.SolrZkClient.makePath makePath: /colle= ctions/collection1/shards [junit4:junit4] 2> 133 T3230 oascc.SolrZkClient.makePath makePath: /colle= ctions/control_collection [junit4:junit4] 2> 136 T3230 oascc.SolrZkClient.makePath makePath: /colle= ctions/control_collection/shards [junit4:junit4] 2> 140 T3230 oasc.AbstractZkTestCase.putConfig put /mnt/s= sd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/= solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml [junit4:junit4] 2> 140 T3230 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/solrconfig.xml [junit4:junit4] 2> 146 T3230 oasc.AbstractZkTestCase.putConfig put /mnt/s= sd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/= solr/collection1/conf/schema.xml to /configs/conf1/schema.xml [junit4:junit4] 2> 147 T3230 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/schema.xml [junit4:junit4] 2> 151 T3230 oasc.AbstractZkTestCase.putConfig put /mnt/s= sd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/= solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt [junit4:junit4] 2> 152 T3230 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/stopwords.txt [junit4:junit4] 2> 155 T3230 oasc.AbstractZkTestCase.putConfig put /mnt/s= sd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/= solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt [junit4:junit4] 2> 156 T3230 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/protwords.txt [junit4:junit4] 2> 160 T3230 oasc.AbstractZkTestCase.putConfig put /mnt/s= sd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/= solr/collection1/conf/currency.xml to /configs/conf1/currency.xml [junit4:junit4] 2> 160 T3230 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/currency.xml [junit4:junit4] 2> 164 T3230 oasc.AbstractZkTestCase.putConfig put /mnt/s= sd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/= solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-excha= nge-rates.json [junit4:junit4] 2> 165 T3230 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/open-exchange-rates.json [junit4:junit4] 2> 169 T3230 oasc.AbstractZkTestCase.putConfig put /mnt/s= sd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/= solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping= -ISOLatin1Accent.txt [junit4:junit4] 2> 169 T3230 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/mapping-ISOLatin1Accent.txt [junit4:junit4] 2> 172 T3230 oasc.AbstractZkTestCase.putConfig put /mnt/s= sd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/= solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt [junit4:junit4] 2> 173 T3230 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/old_synonyms.txt [junit4:junit4] 2> 176 T3230 oasc.AbstractZkTestCase.putConfig put /mnt/s= sd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/= solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt [junit4:junit4] 2> 177 T3230 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/synonyms.txt [junit4:junit4] 2> 181 T3235 oazs.PrepRequestProcessor.pRequest2Txn Proce= ssed session termination for sessionid: 0x13cf974be7e0001 [junit4:junit4] 2> 181 T3239 oaz.ClientCnxn$EventThread.run EventThread s= hut down [junit4:junit4] 2> 181 T3232 oazs.NIOServerCnxn.closeSock Closed socket c= onnection for client /127.0.0.1:51779 which had sessionid 0x13cf974be7e0001 [junit4:junit4] 2> 181 T3230 oaz.ZooKeeper.close Session: 0x13cf974be7e00= 01 closed [junit4:junit4] 2> 242 T3230 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 246 T3230 oejs.AbstractConnector.doStart Started Selec= tChannelConnector@127.0.0.1:36253 [junit4:junit4] 2> 246 T3230 oass.SolrDispatchFilter.init SolrDispatchFil= ter.init() [junit4:junit4] 2> 247 T3230 oasc.SolrResourceLoader.locateSolrHome JNDI = not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 247 T3230 oasc.SolrResourceLoader.locateSolrHome using= system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x= -Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistribut= edZkTest-controljetty-1361394843437 [junit4:junit4] 2> 247 T3230 oasc.CoreContainer$Initializer.initialize lo= oking for solr.xml: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/b= uild/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-cont= roljetty-1361394843437/solr.xml [junit4:junit4] 2> 248 T3230 oasc.CoreContainer. New CoreContainer = 1404903424 [junit4:junit4] 2> 248 T3230 oasc.CoreContainer.load Loading CoreContaine= r using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/b= uild/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-cont= roljetty-1361394843437/' [junit4:junit4] 2> 248 T3230 oasc.SolrResourceLoader. new SolrResou= rceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/= solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTes= t-controljetty-1361394843437/' [junit4:junit4] 2> 261 T3230 oashc.HttpShardHandlerFactory.getParameter S= etting socketTimeout to: 120000 [junit4:junit4] 2> 261 T3230 oashc.HttpShardHandlerFactory.getParameter S= etting urlScheme to: http:// [junit4:junit4] 2> 261 T3230 oashc.HttpShardHandlerFactory.getParameter S= etting connTimeout to: 15000 [junit4:junit4] 2> 262 T3230 oashc.HttpShardHandlerFactory.getParameter S= etting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 262 T3230 oashc.HttpShardHandlerFactory.getParameter S= etting corePoolSize to: 0 [junit4:junit4] 2> 262 T3230 oashc.HttpShardHandlerFactory.getParameter S= etting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 263 T3230 oashc.HttpShardHandlerFactory.getParameter S= etting maxThreadIdleTime to: 5 [junit4:junit4] 2> 263 T3230 oashc.HttpShardHandlerFactory.getParameter S= etting sizeOfQueue to: -1 [junit4:junit4] 2> 263 T3230 oashc.HttpShardHandlerFactory.getParameter S= etting fairnessPolicy to: false [junit4:junit4] 2> 263 T3230 oascsi.HttpClientUtil.createClient Creating = new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000&s= ocketTimeout=3D120000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 268 T3230 oasc.CoreContainer.load Registering Log List= ener [junit4:junit4] 2> 275 T3230 oasc.CoreContainer.initZooKeeper Zookeeper c= lient=3D127.0.0.1:35536/solr [junit4:junit4] 2> 275 T3230 oasc.ZkController.checkChrootPath zkHost inc= ludes chroot [junit4:junit4] 2> 276 T3230 oaz.ZooKeeper. Initiating client conne= ction, connectString=3D127.0.0.1:35536 sessionTimeout=3D60000 watcher=3Dorg= .apache.solr.common.cloud.ConnectionManager@155426e8 [junit4:junit4] 2> 276 T3230 oascc.ConnectionManager.waitForConnected Wai= ting for client to connect to ZooKeeper [junit4:junit4] 2> 277 T3249 oaz.ClientCnxn$SendThread.logStartConnect Op= ening socket connection to server localhost.localdomain/127.0.0.1:35536. Wi= ll not attempt to authenticate using SASL (access denied ("javax.security.a= uth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 2> 278 T3249 oaz.ClientCnxn$SendThread.primeConnection So= cket connection established to localhost.localdomain/127.0.0.1:35536, initi= ating session [junit4:junit4] 2> 278 T3232 oazs.NIOServerCnxnFactory.run Accepted socke= t connection from /127.0.0.1:51780 [junit4:junit4] 2> 278 T3232 oazs.ZooKeeperServer.processConnectRequest C= lient attempting to establish new session at /127.0.0.1:51780 [junit4:junit4] 2> 279 T3234 oazs.ZooKeeperServer.finishSessionInit Estab= lished session 0x13cf974be7e0002 with negotiated timeout 20000 for client /= 127.0.0.1:51780 [junit4:junit4] 2> 279 T3249 oaz.ClientCnxn$SendThread.onConnected Sessio= n establishment complete on server localhost.localdomain/127.0.0.1:35536, s= essionid =3D 0x13cf974be7e0002, negotiated timeout =3D 20000 [junit4:junit4] 2> 280 T3250 oascc.ConnectionManager.process Watcher org.= apache.solr.common.cloud.ConnectionManager@155426e8 name:ZooKeeperConnectio= n Watcher:127.0.0.1:35536 got event WatchedEvent state:SyncConnected type:N= one path:null path:null type:None [junit4:junit4] 2> 280 T3230 oascc.ConnectionManager.waitForConnected Cli= ent is connected to ZooKeeper [junit4:junit4] 2> 281 T3235 oazs.PrepRequestProcessor.pRequest2Txn Proce= ssed session termination for sessionid: 0x13cf974be7e0002 [junit4:junit4] 2> 282 T3232 oazs.NIOServerCnxn.closeSock Closed socket c= onnection for client /127.0.0.1:51780 which had sessionid 0x13cf974be7e0002 [junit4:junit4] 2> 282 T3250 oaz.ClientCnxn$EventThread.run EventThread s= hut down [junit4:junit4] 2> 282 T3230 oaz.ZooKeeper.close Session: 0x13cf974be7e00= 02 closed [junit4:junit4] 2> 282 T3230 oascsi.HttpClientUtil.createClient Creating = new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&soc= ketTimeout=3D120000&connTimeout=3D15000 [junit4:junit4] 2> 284 T3230 oaz.ZooKeeper. Initiating client conne= ction, connectString=3D127.0.0.1:35536/solr sessionTimeout=3D30000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@18362ab [junit4:junit4] 2> 285 T3251 oaz.ClientCnxn$SendThread.logStartConnect Op= ening socket connection to server localhost.localdomain/127.0.0.1:35536. Wi= ll not attempt to authenticate using SASL (access denied ("javax.security.a= uth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 2> 285 T3230 oascc.ConnectionManager.waitForConnected Wai= ting for client to connect to ZooKeeper [junit4:junit4] 2> 286 T3251 oaz.ClientCnxn$SendThread.primeConnection So= cket connection established to localhost.localdomain/127.0.0.1:35536, initi= ating session [junit4:junit4] 2> 286 T3232 oazs.NIOServerCnxnFactory.run Accepted socke= t connection from /127.0.0.1:51781 [junit4:junit4] 2> 286 T3232 oazs.ZooKeeperServer.processConnectRequest C= lient attempting to establish new session at /127.0.0.1:51781 [junit4:junit4] 2> 287 T3234 oazs.ZooKeeperServer.finishSessionInit Estab= lished session 0x13cf974be7e0003 with negotiated timeout 20000 for client /= 127.0.0.1:51781 [junit4:junit4] 2> 287 T3251 oaz.ClientCnxn$SendThread.onConnected Sessio= n establishment complete on server localhost.localdomain/127.0.0.1:35536, s= essionid =3D 0x13cf974be7e0003, negotiated timeout =3D 20000 [junit4:junit4] 2> 287 T3252 oascc.ConnectionManager.process Watcher org.= apache.solr.common.cloud.ConnectionManager@18362ab name:ZooKeeperConnection= Watcher:127.0.0.1:35536/solr got event WatchedEvent state:SyncConnected ty= pe:None path:null path:null type:None [junit4:junit4] 2> 288 T3230 oascc.ConnectionManager.waitForConnected Cli= ent is connected to ZooKeeper [junit4:junit4] 2> 289 T3235 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13cf974be7e0003 type:crea= te cxid:0x2 zxid:0x1a txntype:-1 reqpath:n/a Error Path:/solr/overseer Erro= r:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 290 T3230 oascc.SolrZkClient.makePath makePath: /live_= nodes [junit4:junit4] 2> 292 T3230 oasc.ZkController.createEphemeralLiveNode Re= gister node as live in ZooKeeper:/live_nodes/127.0.0.1:36253_ [junit4:junit4] 2> 293 T3235 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13cf974be7e0003 type:dele= te cxid:0x8 zxid:0x1c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/12= 7.0.0.1:36253_ Error:KeeperErrorCode =3D NoNode for /solr/live_nodes/127.0.= 0.1:36253_ [junit4:junit4] 2> 293 T3230 oascc.SolrZkClient.makePath makePath: /live_= nodes/127.0.0.1:36253_ [junit4:junit4] 2> 295 T3230 oascc.SolrZkClient.makePath makePath: /overs= eer_elect/election [junit4:junit4] 2> 298 T3235 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13cf974be7e0003 type:dele= te cxid:0x16 zxid:0x21 txntype:-1 reqpath:n/a Error Path:/solr/overseer_ele= ct/leader Error:KeeperErrorCode =3D NoNode for /solr/overseer_elect/leader [junit4:junit4] 2> 298 T3230 oascc.SolrZkClient.makePath makePath: /overs= eer_elect/leader [junit4:junit4] 2> 299 T3230 oasc.Overseer.start Overseer (id=3D892203724= 48018435-127.0.0.1:36253_-n_0000000000) starting [junit4:junit4] 2> 300 T3235 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13cf974be7e0003 type:crea= te cxid:0x1b zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 301 T3235 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13cf974be7e0003 type:crea= te cxid:0x1c zxid:0x24 txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 302 T3235 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13cf974be7e0003 type:crea= te cxid:0x1d zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 303 T3235 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13cf974be7e0003 type:crea= te cxid:0x1e zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 304 T3254 oasc.OverseerCollectionProcessor.run Process= current queue of collection creations [junit4:junit4] 2> 304 T3230 oascc.SolrZkClient.makePath makePath: /clust= erstate.json [junit4:junit4] 2> 307 T3230 oascc.ZkStateReader.createClusterStateWatche= rsAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 309 T3253 oasc.Overseer$ClusterStateUpdater.run Starti= ng to work on the main queue [junit4:junit4] 2> 313 T3255 oasc.CoreContainer.create Creating SolrCore = 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x= -Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistribut= edZkTest-controljetty-1361394843437/collection1 [junit4:junit4] 2> 313 T3255 oasc.ZkController.createCollectionZkNode Che= ck for collection zkNode:control_collection [junit4:junit4] 2> 314 T3255 oasc.ZkController.createCollectionZkNode Col= lection zkNode exists [junit4:junit4] 2> 314 T3255 oasc.ZkController.readConfigName Load collec= tion config from:/collections/control_collection [junit4:junit4] 2> 316 T3255 oasc.SolrResourceLoader. new SolrResou= rceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/= solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTes= t-controljetty-1361394843437/collection1/' [junit4:junit4] 2> 317 T3255 oasc.SolrResourceLoader.replaceClassLoader A= dding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/sol= r-core/test/J1/org.apache.solr.cloud.UnloadDistributedZkTest-controljetty-1= 361394843437/collection1/lib/README' to classloader [junit4:junit4] 2> 317 T3255 oasc.SolrResourceLoader.replaceClassLoader A= dding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/sol= r-core/test/J1/org.apache.solr.cloud.UnloadDistributedZkTest-controljetty-1= 361394843437/collection1/lib/classes/' to classloader [junit4:junit4] 2> 344 T3255 oasc.SolrConfig. Using Lucene MatchVer= sion: LUCENE_42 [junit4:junit4] 2> 365 T3255 oasc.SolrConfig. Loaded SolrConfig: so= lrconfig.xml [junit4:junit4] 2> 366 T3255 oass.IndexSchema.readSchema Reading Solr Sch= ema [junit4:junit4] 2> 369 T3255 oass.IndexSchema.readSchema Schema name=3Dte= st [junit4:junit4] 2> 404 T3 oasc.CoreContainer.finalize SEVERE CoreContaine= r was not shutdown prior to finalize(), indicates a bug -- POSSIBLE RESOURC= E LEAK!!! instance=3D914579634 [junit4:junit4] 2> 618 T3255 oass.OpenExchangeRatesOrgProvider.init Initi= alized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 622 T3255 oass.IndexSchema.readSchema default search f= ield in schema is text [junit4:junit4] 2> 623 T3255 oass.IndexSchema.readSchema unique key field= : id [junit4:junit4] 2> 636 T3255 oass.FileExchangeRateProvider.reload Reloadi= ng exchange rates from file currency.xml [junit4:junit4] 2> 639 T3255 oass.FileExchangeRateProvider.reload Reloadi= ng exchange rates from file currency.xml [junit4:junit4] 2> 642 T3255 oass.OpenExchangeRatesOrgProvider.reload Rel= oading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 643 T3255 oass.OpenExchangeRatesOrgProvider.reload Rel= oading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 645 T3255 oasc.SolrCore. [collection1] Opening n= ew SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/= solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-controlje= tty-1361394843437/collection1/, dataDir=3D./org.apache.solr.cloud.UnloadDis= tributedZkTest-1361394843258/control/data/ [junit4:junit4] 2> 645 T3255 oasc.JmxMonitoredMap. JMX monitoring i= s enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBe= anServer@66bba6f9 [junit4:junit4] 2> 645 T3255 oasc.SolrCore.initDirectoryFactory org.apach= e.solr.core.MockDirectoryFactory [junit4:junit4] 2> 646 T3255 oasc.CachingDirectoryFactory.get return new = directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/s= olr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361394843= 258/control/data forceNew:false [junit4:junit4] 2> 646 T3255 oasc.CachingDirectoryFactory.close Releasing= directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr= -core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361394843258= /control/data [junit4:junit4] 2> 646 T3255 oasc.SolrCore.getNewIndexDir New index direc= tory detected: old=3Dnull new=3D./org.apache.solr.cloud.UnloadDistributedZk= Test-1361394843258/control/data/index/ [junit4:junit4] 2> 647 T3255 oasc.SolrCore.initIndex WARNING [collection1= ] Solr index directory './org.apache.solr.cloud.UnloadDistributedZkTest-136= 1394843258/control/data/index' doesn't exist. Creating new index... [junit4:junit4] 2> 647 T3255 oasc.CachingDirectoryFactory.get return new = directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/s= olr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361394843= 258/control/data/index forceNew:false [junit4:junit4] 2> 649 T3255 oasc.SolrDeletionPolicy.onCommit SolrDeletio= nPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@2f35cd2a lockFactory=3Dorg.apache.lucene.store.NativeFSLoc= kFactory@497365df),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_= 1] [junit4:junit4] 2> 649 T3255 oasc.SolrDeletionPolicy.updateCommits newest= commit =3D 1[segments_1] [junit4:junit4] 2> 649 T3255 oasc.CachingDirectoryFactory.close Releasing= directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr= -core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361394843258= /control/data/index [junit4:junit4] 2> 650 T3255 oasup.UpdateRequestProcessorChain.init inser= ting DistributedUpdateProcessorFactory into updateRequestProcessorChain "de= dupe" [junit4:junit4] 2> 651 T3255 oasup.UpdateRequestProcessorChain.init inser= ting DistributedUpdateProcessorFactory into updateRequestProcessorChain "st= ored_sig" [junit4:junit4] 2> 651 T3255 oasup.UpdateRequestProcessorChain.init inser= ting DistributedUpdateProcessorFactory into updateRequestProcessorChain "di= strib-dup-test-chain-implicit" [junit4:junit4] 2> 651 T3255 oasc.RequestHandlers.initHandlersFromConfig = created standard: solr.StandardRequestHandler [junit4:junit4] 2> 652 T3255 oasc.RequestHandlers.initHandlersFromConfig = created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 652 T3255 oasc.RequestHandlers.initHandlersFromConfig = adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 652 T3255 oasc.RequestHandlers.initHandlersFromConfig = created /replication: solr.ReplicationHandler [junit4:junit4] 2> 653 T3255 oasc.RequestHandlers.initHandlersFromConfig = created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 653 T3255 oasc.RequestHandlers.initHandlersFromConfig = created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 656 T3255 oashl.XMLLoader.init xsltCacheLifetimeSecond= s=3D60 [junit4:junit4] 2> 658 T3255 oasc.CachingDirectoryFactory.close Releasing= directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr= -core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361394843258= /control/data [junit4:junit4] 2> 659 T3255 oass.SolrIndexSearcher. Opening Search= er@5970b19a main [junit4:junit4] 2> 659 T3255 oasu.UpdateHandler.clearLog Clearing tlog fi= les, tlogDir=3D./org.apache.solr.cloud.UnloadDistributedZkTest-136139484325= 8/control/data/tlog [junit4:junit4] 2> 660 T3255 oasu.CommitTracker. Hard AutoCommit: d= isabled [junit4:junit4] 2> 660 T3255 oasu.CommitTracker. Soft AutoCommit: d= isabled [junit4:junit4] 2> 662 T3255 oasc.CachingDirectoryFactory.close Releasing= directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr= -core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-1361394843258= /control/data [junit4:junit4] 2> 663 T3256 oasc.SolrCore.registerSearcher [collection1]= Registered new searcher Searcher@5970b19a main{StandardDirectoryReader(seg= ments_1:1)} [junit4:junit4] 2> 663 T3255 oasc.ZkController.publish publishing core=3D= collection1 state=3Ddown [junit4:junit4] 2> 663 T3255 oasc.ZkController.publish numShards not foun= d on descriptor - reading it from system property [junit4:junit4] 2> 664 T3235 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13cf974be7e0003 type:crea= te cxid:0x50 zxid:0x29 txntype:-1 reqpath:n/a Error Path:/solr/overseer/que= ue Error:KeeperErrorCode =3D NoNode for /solr/overseer/queue [junit4:junit4] 2> 1815 T3253 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 1816 T3253 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "collection":"control_collection", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:36253_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:36253", [junit4:junit4] 2> =09 "shard":null, [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"down", [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "core":"collection1"} [junit4:junit4] 2> 1816 T3253 oasc.Overseer$ClusterStateUpdater.createCol= lection Create collection control_collection with numShards 1 [junit4:junit4] 2> 1816 T3253 oasc.Overseer$ClusterStateUpdater.updateSta= te Assigning new node to shard shard=3Dshard1 [junit4:junit4] 2> 1817 T3235 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13cf974be7e0003 type:cre= ate cxid:0x58 zxid:0x2c txntype:-1 reqpath:n/a Error Path:/solr/overseer/qu= eue-work Error:KeeperErrorCode =3D NoNode for /solr/overseer/queue-work [junit4:junit4] 2> 1824 T3252 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 1) [junit4:junit4] 2> 2668 T3255 oasc.CoreContainer.registerCore registering= core: collection1 [junit4:junit4] 2> 2669 T3255 oasc.ZkController.register Register replica= - core:collection1 address:http://127.0.0.1:36253 collection:control_colle= ction shard:shard1 [junit4:junit4] 2> 2670 T3255 oascc.SolrZkClient.makePath makePath: /coll= ections/control_collection/leader_elect/shard1/election [junit4:junit4] 2> 2677 T3235 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13cf974be7e0003 type:del= ete cxid:0x72 zxid:0x36 txntype:-1 reqpath:n/a Error Path:/solr/collections= /control_collection/leaders Error:KeeperErrorCode =3D NoNode for /solr/coll= ections/control_collection/leaders [junit4:junit4] 2> 2678 T3255 oasc.ShardLeaderElectionContext.runLeaderPr= ocess Running the leader process. [junit4:junit4] 2> 2679 T3235 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13cf974be7e0003 type:cre= ate cxid:0x73 zxid:0x37 txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 2688 T3255 oasc.ShardLeaderElectionContext.waitForRepl= icasToComeUp Enough replicas found to continue. [junit4:junit4] 2> 2689 T3255 oasc.ShardLeaderElectionContext.runLeaderPr= ocess I may be the new leader - try and sync [junit4:junit4] 2> 2689 T3255 oasc.SyncStrategy.sync Sync replicas to htt= p://127.0.0.1:36253/collection1/ [junit4:junit4] 2> 2689 T3255 oasc.SyncStrategy.syncReplicas Sync Success= - now sync replicas to me [junit4:junit4] 2> 2690 T3255 oasc.SyncStrategy.syncToMe http://127.0.0.1= :36253/collection1/ has no replicas [junit4:junit4] 2> 2690 T3255 oasc.ShardLeaderElectionContext.runLeaderPr= ocess I am the new leader: http://127.0.0.1:36253/collection1/ [junit4:junit4] 2> 2690 T3255 oascc.SolrZkClient.makePath makePath: /coll= ections/control_collection/leaders/shard1 [junit4:junit4] 2> 2695 T3235 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13cf974be7e0003 type:cre= ate cxid:0x7d zxid:0x3b txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 3329 T3253 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 3339 T3252 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 1) [junit4:junit4] 2> 3349 T3255 oasc.ZkController.register We are http://12= 7.0.0.1:36253/collection1/ and leader is http://127.0.0.1:36253/collection1= / [junit4:junit4] 2> 3349 T3255 oasc.ZkController.register No LogReplay nee= ded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:36253 [junit4:junit4] 2> 3349 T3255 oasc.ZkController.checkRecovery I am the le= ader, no recovery necessary [junit4:junit4] 2> 3349 T3255 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Dactive [junit4:junit4] 2> 3350 T3255 oasc.ZkController.publish numShards not fou= nd on descriptor - reading it from system property [junit4:junit4] 2> 3352 T3255 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 3353 T3230 oass.SolrDispatchFilter.init user.dir=3D/mn= t/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1 [junit4:junit4] 2> 3354 T3230 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() done [junit4:junit4] 2> 3355 T3230 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&fo= llowRedirects=3Dfalse [junit4:junit4] 2> 3360 T3230 oascsi.HttpClientUtil.createClient Creating= new http client, config: [junit4:junit4] 2> 3361 T3230 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:35536/solr sessionTimeout=3D10000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@517fb0a [junit4:junit4] 2> 3362 T3257 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost.localdomain/127.0.0.1:35536. W= ill not attempt to authenticate using SASL (access denied ("javax.security.= auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 2> 3362 T3230 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 3362 T3257 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost.localdomain/127.0.0.1:35536, init= iating session [junit4:junit4] 2> 3363 T3232 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /127.0.0.1:51782 [junit4:junit4] 2> 3363 T3232 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /127.0.0.1:51782 [junit4:junit4] 2> 3364 T3234 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13cf974be7e0004 with negotiated timeout 10000 for client = /127.0.0.1:51782 [junit4:junit4] 2> 3364 T3257 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost.localdomain/127.0.0.1:35536, = sessionid =3D 0x13cf974be7e0004, negotiated timeout =3D 10000 [junit4:junit4] 2> 3364 T3258 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@517fb0a name:ZooKeeperConnectio= n Watcher:127.0.0.1:35536/solr got event WatchedEvent state:SyncConnected t= ype:None path:null path:null type:None [junit4:junit4] 2> 3365 T3230 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 3366 T3230 oascc.ZkStateReader.createClusterStateWatch= ersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 3368 T3230 oasc.ChaosMonkey.monkeyLog monkey: init - e= xpire sessions:true cause connection loss:true [junit4:junit4] 2> 3425 T3230 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 3428 T3230 oejs.AbstractConnector.doStart Started Sele= ctChannelConnector@127.0.0.1:60465 [junit4:junit4] 2> 3428 T3230 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() [junit4:junit4] 2> 3429 T3230 oasc.SolrResourceLoader.locateSolrHome JNDI= not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 3430 T3230 oasc.SolrResourceLoader.locateSolrHome usin= g system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.= x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistribu= tedZkTest-jetty1-1361394846624 [junit4:junit4] 2> 3430 T3230 oasc.CoreContainer$Initializer.initialize l= ooking for solr.xml: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/= build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jet= ty1-1361394846624/solr.xml [junit4:junit4] 2> 3431 T3230 oasc.CoreContainer. New CoreContainer= 1383307932 [junit4:junit4] 2> 3432 T3230 oasc.CoreContainer.load Loading CoreContain= er using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/= build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jet= ty1-1361394846624/' [junit4:junit4] 2> 3432 T3230 oasc.SolrResourceLoader. new SolrReso= urceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux= /solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTe= st-jetty1-1361394846624/' [junit4:junit4] 2> 3458 T3230 oashc.HttpShardHandlerFactory.getParameter = Setting socketTimeout to: 120000 [junit4:junit4] 2> 3459 T3230 oashc.HttpShardHandlerFactory.getParameter = Setting urlScheme to: http:// [junit4:junit4] 2> 3460 T3230 oashc.HttpShardHandlerFactory.getParameter = Setting connTimeout to: 15000 [junit4:junit4] 2> 3460 T3230 oashc.HttpShardHandlerFactory.getParameter = Setting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 3461 T3230 oashc.HttpShardHandlerFactory.getParameter = Setting corePoolSize to: 0 [junit4:junit4] 2> 3461 T3230 oashc.HttpShardHandlerFactory.getParameter = Setting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 3461 T3230 oashc.HttpShardHandlerFactory.getParameter = Setting maxThreadIdleTime to: 5 [junit4:junit4] 2> 3462 T3230 oashc.HttpShardHandlerFactory.getParameter = Setting sizeOfQueue to: -1 [junit4:junit4] 2> 3462 T3230 oashc.HttpShardHandlerFactory.getParameter = Setting fairnessPolicy to: false [junit4:junit4] 2> 3462 T3230 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000&= socketTimeout=3D120000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 3466 T3230 oasc.CoreContainer.load Registering Log Lis= tener [junit4:junit4] 2> 3473 T3230 oasc.CoreContainer.initZooKeeper Zookeeper = client=3D127.0.0.1:35536/solr [junit4:junit4] 2> 3474 T3230 oasc.ZkController.checkChrootPath zkHost in= cludes chroot [junit4:junit4] 2> 3474 T3230 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:35536 sessionTimeout=3D60000 watcher=3Dor= g.apache.solr.common.cloud.ConnectionManager@6215dde [junit4:junit4] 2> 3475 T3268 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost.localdomain/127.0.0.1:35536. W= ill not attempt to authenticate using SASL (access denied ("javax.security.= auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 2> 3475 T3230 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 3476 T3268 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost.localdomain/127.0.0.1:35536, init= iating session [junit4:junit4] 2> 3476 T3232 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /127.0.0.1:51783 [junit4:junit4] 2> 3476 T3232 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /127.0.0.1:51783 [junit4:junit4] 2> 3477 T3234 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13cf974be7e0005 with negotiated timeout 20000 for client = /127.0.0.1:51783 [junit4:junit4] 2> 3477 T3268 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost.localdomain/127.0.0.1:35536, = sessionid =3D 0x13cf974be7e0005, negotiated timeout =3D 20000 [junit4:junit4] 2> 3477 T3269 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@6215dde name:ZooKeeperConnectio= n Watcher:127.0.0.1:35536 got event WatchedEvent state:SyncConnected type:N= one path:null path:null type:None [junit4:junit4] 2> 3477 T3230 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 3478 T3235 oazs.PrepRequestProcessor.pRequest2Txn Proc= essed session termination for sessionid: 0x13cf974be7e0005 [junit4:junit4] 2> 3479 T3232 oazs.NIOServerCnxn.closeSock Closed socket = connection for client /127.0.0.1:51783 which had sessionid 0x13cf974be7e000= 5 [junit4:junit4] 2> 3479 T3269 oaz.ClientCnxn$EventThread.run EventThread = shut down [junit4:junit4] 2> 3479 T3230 oaz.ZooKeeper.close Session: 0x13cf974be7e0= 005 closed [junit4:junit4] 2> 3479 T3230 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&so= cketTimeout=3D120000&connTimeout=3D15000 [junit4:junit4] 2> 3482 T3230 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:35536/solr sessionTimeout=3D30000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@11cb5a53 [junit4:junit4] 2> 3484 T3270 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost.localdomain/127.0.0.1:35536. W= ill not attempt to authenticate using SASL (access denied ("javax.security.= auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 2> 3484 T3230 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 3484 T3270 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost.localdomain/127.0.0.1:35536, init= iating session [junit4:junit4] 2> 3484 T3232 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /127.0.0.1:51784 [junit4:junit4] 2> 3484 T3232 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /127.0.0.1:51784 [junit4:junit4] 2> 3485 T3234 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13cf974be7e0006 with negotiated timeout 20000 for client = /127.0.0.1:51784 [junit4:junit4] 2> 3485 T3270 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost.localdomain/127.0.0.1:35536, = sessionid =3D 0x13cf974be7e0006, negotiated timeout =3D 20000 [junit4:junit4] 2> 3486 T3271 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@11cb5a53 name:ZooKeeperConnecti= on Watcher:127.0.0.1:35536/solr got event WatchedEvent state:SyncConnected = type:None path:null path:null type:None [junit4:junit4] 2> 3486 T3230 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 3487 T3235 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13cf974be7e0006 type:cre= ate cxid:0x1 zxid:0x49 txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 3488 T3235 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13cf974be7e0006 type:cre= ate cxid:0x2 zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 3490 T3230 oascc.ZkStateReader.createClusterStateWatch= ersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 4493 T3230 oasc.ZkController.createEphemeralLiveNode R= egister node as live in ZooKeeper:/live_nodes/127.0.0.1:60465_ [junit4:junit4] 2> 4495 T3235 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13cf974be7e0006 type:del= ete cxid:0x9 zxid:0x4b txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/1= 27.0.0.1:60465_ Error:KeeperErrorCode =3D NoNode for /solr/live_nodes/127.0= .0.1:60465_ [junit4:junit4] 2> 4496 T3230 oascc.SolrZkClient.makePath makePath: /live= _nodes/127.0.0.1:60465_ [junit4:junit4] 2> 4500 T3252 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/= live_nodes, has occurred - updating... (live nodes size: 1) [junit4:junit4] 2> 4500 T3258 oascc.ZkStateReader$3.process Updating live= nodes... (2) [junit4:junit4] 2> 4500 T3271 oascc.ZkStateReader$3.process Updating live= nodes... (2) [junit4:junit4] 2> 4502 T3252 oascc.ZkStateReader$3.process Updating live= nodes... (2) [junit4:junit4] 2> 4509 T3272 oasc.CoreContainer.create Creating SolrCore= 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.= x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistribu= tedZkTest-jetty1-1361394846624/collection1 [junit4:junit4] 2> 4509 T3272 oasc.ZkController.createCollectionZkNode Ch= eck for collection zkNode:collection1 [junit4:junit4] 2> 4510 T3272 oasc.ZkController.createCollectionZkNode Co= llection zkNode exists [junit4:junit4] 2> 4510 T3272 oasc.ZkController.readConfigName Load colle= ction config from:/collections/collection1 [junit4:junit4] 2> 4512 T3272 oasc.SolrResourceLoader. new SolrReso= urceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux= /solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTe= st-jetty1-1361394846624/collection1/' [junit4:junit4] 2> 4513 T3272 oasc.SolrResourceLoader.replaceClassLoader = Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/so= lr-core/test/J1/org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-136139= 4846624/collection1/lib/README' to classloader [junit4:junit4] 2> 4513 T3272 oasc.SolrResourceLoader.replaceClassLoader = Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/so= lr-core/test/J1/org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-136139= 4846624/collection1/lib/classes/' to classloader [junit4:junit4] 2> 4543 T3272 oasc.SolrConfig. Using Lucene MatchVe= rsion: LUCENE_42 [junit4:junit4] 2> 4566 T3272 oasc.SolrConfig. Loaded SolrConfig: s= olrconfig.xml [junit4:junit4] 2> 4567 T3272 oass.IndexSchema.readSchema Reading Solr Sc= hema [junit4:junit4] 2> 4570 T3272 oass.IndexSchema.readSchema Schema name=3Dt= est [junit4:junit4] 2> 4845 T3253 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 4846 T3253 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "collection":"control_collection", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:36253_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:36253", [junit4:junit4] 2> =09 "shard":"shard1", [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"active", [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "core":"collection1"} [junit4:junit4] 2> 4850 T3271 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 4850 T3258 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 4850 T3252 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 4860 T3272 oass.OpenExchangeRatesOrgProvider.init Init= ialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 4864 T3272 oass.IndexSchema.readSchema default search = field in schema is text [junit4:junit4] 2> 4865 T3272 oass.IndexSchema.readSchema unique key fiel= d: id [junit4:junit4] 2> 4878 T3272 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 4882 T3272 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 4886 T3272 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 4888 T3272 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 4889 T3272 oasc.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.UnloadDistributedZkTest-jetty1-1= 361394846624/collection1/, dataDir=3D./org.apache.solr.cloud.UnloadDistribu= tedZkTest-1361394843258/jetty1/ [junit4:junit4] 2> 4890 T3272 oasc.JmxMonitoredMap. JMX monitoring = is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMB= eanServer@66bba6f9 [junit4:junit4] 2> 4890 T3272 oasc.SolrCore.initDirectoryFactory org.apac= he.solr.core.MockDirectoryFactory [junit4:junit4] 2> 4891 T3272 oasc.CachingDirectoryFactory.get return new= directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/= solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-136139484= 3258/jetty1 forceNew:false [junit4:junit4] 2> 4891 T3272 oasc.CachingDirectoryFactory.close Releasin= g directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/sol= r-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-136139484325= 8/jetty1 [junit4:junit4] 2> 4891 T3272 oasc.SolrCore.getNewIndexDir New index dire= ctory detected: old=3Dnull new=3D./org.apache.solr.cloud.UnloadDistributedZ= kTest-1361394843258/jetty1/index/ [junit4:junit4] 2> 4892 T3272 oasc.SolrCore.initIndex WARNING [collection= 1] Solr index directory './org.apache.solr.cloud.UnloadDistributedZkTest-13= 61394843258/jetty1/index' doesn't exist. Creating new index... [junit4:junit4] 2> 4892 T3272 oasc.CachingDirectoryFactory.get return new= directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/= solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-136139484= 3258/jetty1/index forceNew:false [junit4:junit4] 2> 4894 T3272 oasc.SolrDeletionPolicy.onCommit SolrDeleti= onPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@411c6947 lockFactory=3Dorg.apache.lucene.store.NativeFSLoc= kFactory@3583b87b),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_= 1] [junit4:junit4] 2> 4894 T3272 oasc.SolrDeletionPolicy.updateCommits newes= t commit =3D 1[segments_1] [junit4:junit4] 2> 4895 T3272 oasc.CachingDirectoryFactory.close Releasin= g directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/sol= r-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-136139484325= 8/jetty1/index [junit4:junit4] 2> 4896 T3272 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe" [junit4:junit4] 2> 4897 T3272 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "s= tored_sig" [junit4:junit4] 2> 4897 T3272 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= istrib-dup-test-chain-implicit" [junit4:junit4] 2> 4897 T3272 oasc.RequestHandlers.initHandlersFromConfig= created standard: solr.StandardRequestHandler [junit4:junit4] 2> 4898 T3272 oasc.RequestHandlers.initHandlersFromConfig= created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 4898 T3272 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 4898 T3272 oasc.RequestHandlers.initHandlersFromConfig= created /replication: solr.ReplicationHandler [junit4:junit4] 2> 4898 T3272 oasc.RequestHandlers.initHandlersFromConfig= created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 4898 T3272 oasc.RequestHandlers.initHandlersFromConfig= created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 4900 T3272 oashl.XMLLoader.init xsltCacheLifetimeSecon= ds=3D60 [junit4:junit4] 2> 4902 T3272 oasc.CachingDirectoryFactory.close Releasin= g directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/sol= r-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-136139484325= 8/jetty1 [junit4:junit4] 2> 4902 T3272 oass.SolrIndexSearcher. Opening Searc= her@4d4b852b main [junit4:junit4] 2> 4902 T3272 oasu.UpdateHandler.clearLog Clearing tlog f= iles, tlogDir=3D./org.apache.solr.cloud.UnloadDistributedZkTest-13613948432= 58/jetty1/tlog [junit4:junit4] 2> 4903 T3272 oasu.CommitTracker. Hard AutoCommit: = disabled [junit4:junit4] 2> 4903 T3272 oasu.CommitTracker. Soft AutoCommit: = disabled [junit4:junit4] 2> 4905 T3273 oasc.SolrCore.registerSearcher [collection1= ] Registered new searcher Searcher@4d4b852b main{StandardDirectoryReader(se= gments_1:1)} [junit4:junit4] 2> 4906 T3272 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Ddown [junit4:junit4] 2> 4906 T3272 oasc.ZkController.publish numShards not fou= nd on descriptor - reading it from system property [junit4:junit4] 2> 6354 T3253 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 6355 T3253 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D2 message=3D{ [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:60465_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:60465", [junit4:junit4] 2> =09 "shard":null, [junit4:junit4] 2> =09 "numShards":"2", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"down", [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "core":"collection1"} [junit4:junit4] 2> 6355 T3253 oasc.Overseer$ClusterStateUpdater.createCol= lection Create collection collection1 with numShards 2 [junit4:junit4] 2> 6356 T3253 oasc.Overseer$ClusterStateUpdater.updateSta= te Assigning new node to shard shard=3Dshard2 [junit4:junit4] 2> 6362 T3258 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 6362 T3252 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 6362 T3271 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 6907 T3272 oasc.CoreContainer.registerCore registering= core: collection1 [junit4:junit4] 2> 6908 T3272 oasc.ZkController.register Register replica= - core:collection1 address:http://127.0.0.1:60465 collection:collection1 s= hard:shard2 [junit4:junit4] 2> 6909 T3272 oascc.SolrZkClient.makePath makePath: /coll= ections/collection1/leader_elect/shard2/election [junit4:junit4] 2> 6940 T3235 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13cf974be7e0006 type:del= ete cxid:0x46 zxid:0x5b txntype:-1 reqpath:n/a Error Path:/solr/collections= /collection1/leaders Error:KeeperErrorCode =3D NoNode for /solr/collections= /collection1/leaders [junit4:junit4] 2> 6941 T3272 oasc.ShardLeaderElectionContext.runLeaderPr= ocess Running the leader process. [junit4:junit4] 2> 6941 T3235 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13cf974be7e0006 type:cre= ate cxid:0x47 zxid:0x5c txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 6943 T3272 oasc.ShardLeaderElectionContext.waitForRepl= icasToComeUp Enough replicas found to continue. [junit4:junit4] 2> 6944 T3272 oasc.ShardLeaderElectionContext.runLeaderPr= ocess I may be the new leader - try and sync [junit4:junit4] 2> 6944 T3272 oasc.SyncStrategy.sync Sync replicas to htt= p://127.0.0.1:60465/collection1/ [junit4:junit4] 2> 6944 T3272 oasc.SyncStrategy.syncReplicas Sync Success= - now sync replicas to me [junit4:junit4] 2> 6945 T3272 oasc.SyncStrategy.syncToMe http://127.0.0.1= :60465/collection1/ has no replicas [junit4:junit4] 2> 6945 T3272 oasc.ShardLeaderElectionContext.runLeaderPr= ocess I am the new leader: http://127.0.0.1:60465/collection1/ [junit4:junit4] 2> 6945 T3272 oascc.SolrZkClient.makePath makePath: /coll= ections/collection1/leaders/shard2 [junit4:junit4] 2> 6949 T3235 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13cf974be7e0006 type:cre= ate cxid:0x51 zxid:0x60 txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 7868 T3253 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 7877 T3271 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 7877 T3252 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 7877 T3258 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 7905 T3272 oasc.ZkController.register We are http://12= 7.0.0.1:60465/collection1/ and leader is http://127.0.0.1:60465/collection1= / [junit4:junit4] 2> 7905 T3272 oasc.ZkController.register No LogReplay nee= ded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:60465 [junit4:junit4] 2> 7905 T3272 oasc.ZkController.checkRecovery I am the le= ader, no recovery necessary [junit4:junit4] 2> 7906 T3272 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Dactive [junit4:junit4] 2> 7906 T3272 oasc.ZkController.publish numShards not fou= nd on descriptor - reading it from system property [junit4:junit4] 2> 7907 T3272 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 7908 T3230 oass.SolrDispatchFilter.init user.dir=3D/mn= t/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1 [junit4:junit4] 2> 7909 T3230 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() done [junit4:junit4] 2> 7910 T3230 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&fo= llowRedirects=3Dfalse [junit4:junit4] 2> 7958 T3230 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 7960 T3230 oejs.AbstractConnector.doStart Started Sele= ctChannelConnector@127.0.0.1:60062 [junit4:junit4] 2> 7961 T3230 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() [junit4:junit4] 2> 7961 T3230 oasc.SolrResourceLoader.locateSolrHome JNDI= not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 7961 T3230 oasc.SolrResourceLoader.locateSolrHome usin= g system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.= x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistribu= tedZkTest-jetty2-1361394851170 [junit4:junit4] 2> 7961 T3230 oasc.CoreContainer$Initializer.initialize l= ooking for solr.xml: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/= build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jet= ty2-1361394851170/solr.xml [junit4:junit4] 2> 7962 T3230 oasc.CoreContainer. New CoreContainer= 477429167 [junit4:junit4] 2> 7962 T3230 oasc.CoreContainer.load Loading CoreContain= er using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/= build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jet= ty2-1361394851170/' [junit4:junit4] 2> 7962 T3230 oasc.SolrResourceLoader. new SolrReso= urceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux= /solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTe= st-jetty2-1361394851170/' [junit4:junit4] 2> 7976 T3230 oashc.HttpShardHandlerFactory.getParameter = Setting socketTimeout to: 120000 [junit4:junit4] 2> 7976 T3230 oashc.HttpShardHandlerFactory.getParameter = Setting urlScheme to: http:// [junit4:junit4] 2> 7976 T3230 oashc.HttpShardHandlerFactory.getParameter = Setting connTimeout to: 15000 [junit4:junit4] 2> 7977 T3230 oashc.HttpShardHandlerFactory.getParameter = Setting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 7977 T3230 oashc.HttpShardHandlerFactory.getParameter = Setting corePoolSize to: 0 [junit4:junit4] 2> 7977 T3230 oashc.HttpShardHandlerFactory.getParameter = Setting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 7977 T3230 oashc.HttpShardHandlerFactory.getParameter = Setting maxThreadIdleTime to: 5 [junit4:junit4] 2> 7978 T3230 oashc.HttpShardHandlerFactory.getParameter = Setting sizeOfQueue to: -1 [junit4:junit4] 2> 7978 T3230 oashc.HttpShardHandlerFactory.getParameter = Setting fairnessPolicy to: false [junit4:junit4] 2> 7978 T3230 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000&= socketTimeout=3D120000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 7983 T3230 oasc.CoreContainer.load Registering Log Lis= tener [junit4:junit4] 2> 7989 T3230 oasc.CoreContainer.initZooKeeper Zookeeper = client=3D127.0.0.1:35536/solr [junit4:junit4] 2> 7990 T3230 oasc.ZkController.checkChrootPath zkHost in= cludes chroot [junit4:junit4] 2> 7990 T3230 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:35536 sessionTimeout=3D60000 watcher=3Dor= g.apache.solr.common.cloud.ConnectionManager@50aa5c69 [junit4:junit4] 2> 7991 T3283 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost.localdomain/127.0.0.1:35536. W= ill not attempt to authenticate using SASL (access denied ("javax.security.= auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 2> 7991 T3230 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 7992 T3283 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost.localdomain/127.0.0.1:35536, init= iating session [junit4:junit4] 2> 7992 T3232 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /127.0.0.1:51786 [junit4:junit4] 2> 7993 T3232 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /127.0.0.1:51786 [junit4:junit4] 2> 7994 T3234 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13cf974be7e0007 with negotiated timeout 20000 for client = /127.0.0.1:51786 [junit4:junit4] 2> 7994 T3283 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost.localdomain/127.0.0.1:35536, = sessionid =3D 0x13cf974be7e0007, negotiated timeout =3D 20000 [junit4:junit4] 2> 7994 T3284 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@50aa5c69 name:ZooKeeperConnecti= on Watcher:127.0.0.1:35536 got event WatchedEvent state:SyncConnected type:= None path:null path:null type:None [junit4:junit4] 2> 7995 T3230 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 7996 T3235 oazs.PrepRequestProcessor.pRequest2Txn Proc= essed session termination for sessionid: 0x13cf974be7e0007 [junit4:junit4] 2> 7998 T3232 oazs.NIOServerCnxn.closeSock Closed socket = connection for client /127.0.0.1:51786 which had sessionid 0x13cf974be7e000= 7 [junit4:junit4] 2> 7998 T3284 oaz.ClientCnxn$EventThread.run EventThread = shut down [junit4:junit4] 2> 7998 T3230 oaz.ZooKeeper.close Session: 0x13cf974be7e0= 007 closed [junit4:junit4] 2> 7999 T3230 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&so= cketTimeout=3D120000&connTimeout=3D15000 [junit4:junit4] 2> 8004 T3230 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:35536/solr sessionTimeout=3D30000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@34fb6d92 [junit4:junit4] 2> 8006 T3285 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost.localdomain/127.0.0.1:35536. W= ill not attempt to authenticate using SASL (access denied ("javax.security.= auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 2> 8006 T3230 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 8007 T3232 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /127.0.0.1:51787 [junit4:junit4] 2> 8007 T3285 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost.localdomain/127.0.0.1:35536, init= iating session [junit4:junit4] 2> 8008 T3232 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /127.0.0.1:51787 [junit4:junit4] 2> 8008 T3234 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13cf974be7e0008 with negotiated timeout 20000 for client = /127.0.0.1:51787 [junit4:junit4] 2> 8009 T3285 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost.localdomain/127.0.0.1:35536, = sessionid =3D 0x13cf974be7e0008, negotiated timeout =3D 20000 [junit4:junit4] 2> 8009 T3286 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@34fb6d92 name:ZooKeeperConnecti= on Watcher:127.0.0.1:35536/solr got event WatchedEvent state:SyncConnected = type:None path:null path:null type:None [junit4:junit4] 2> 8009 T3230 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 8011 T3235 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13cf974be7e0008 type:cre= ate cxid:0x1 zxid:0x6d txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 8012 T3235 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13cf974be7e0008 type:cre= ate cxid:0x2 zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 8014 T3230 oascc.ZkStateReader.createClusterStateWatch= ersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 9017 T3230 oasc.ZkController.createEphemeralLiveNode R= egister node as live in ZooKeeper:/live_nodes/127.0.0.1:60062_ [junit4:junit4] 2> 9018 T3235 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13cf974be7e0008 type:del= ete cxid:0x9 zxid:0x6f txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/1= 27.0.0.1:60062_ Error:KeeperErrorCode =3D NoNode for /solr/live_nodes/127.0= .0.1:60062_ [junit4:junit4] 2> 9020 T3230 oascc.SolrZkClient.makePath makePath: /live= _nodes/127.0.0.1:60062_ [junit4:junit4] 2> 9021 T3271 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/= live_nodes, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 9021 T3252 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/= live_nodes, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 9021 T3258 oascc.ZkStateReader$3.process Updating live= nodes... (3) [junit4:junit4] 2> 9021 T3286 oascc.ZkStateReader$3.process Updating live= nodes... (3) [junit4:junit4] 2> 9021 T3258 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/= live_nodes, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 9022 T3271 oascc.ZkStateReader$3.process Updating live= nodes... (3) [junit4:junit4] 2> 9022 T3252 oascc.ZkStateReader$3.process Updating live= nodes... (3) [junit4:junit4] 2> 9027 T3287 oasc.CoreContainer.create Creating SolrCore= 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.= x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistribu= tedZkTest-jetty2-1361394851170/collection1 [junit4:junit4] 2> 9028 T3287 oasc.ZkController.createCollectionZkNode Ch= eck for collection zkNode:collection1 [junit4:junit4] 2> 9029 T3287 oasc.ZkController.createCollectionZkNode Co= llection zkNode exists [junit4:junit4] 2> 9029 T3287 oasc.ZkController.readConfigName Load colle= ction config from:/collections/collection1 [junit4:junit4] 2> 9030 T3287 oasc.SolrResourceLoader. new SolrReso= urceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux= /solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTe= st-jetty2-1361394851170/collection1/' [junit4:junit4] 2> 9031 T3287 oasc.SolrResourceLoader.replaceClassLoader = Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/so= lr-core/test/J1/org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-136139= 4851170/collection1/lib/README' to classloader [junit4:junit4] 2> 9031 T3287 oasc.SolrResourceLoader.replaceClassLoader = Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/so= lr-core/test/J1/org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-136139= 4851170/collection1/lib/classes/' to classloader [junit4:junit4] 2> 9054 T3287 oasc.SolrConfig. Using Lucene MatchVe= rsion: LUCENE_42 [junit4:junit4] 2> 9077 T3287 oasc.SolrConfig. Loaded SolrConfig: s= olrconfig.xml [junit4:junit4] 2> 9078 T3287 oass.IndexSchema.readSchema Reading Solr Sc= hema [junit4:junit4] 2> 9081 T3287 oass.IndexSchema.readSchema Schema name=3Dt= est [junit4:junit4] 2> 9333 T3287 oass.OpenExchangeRatesOrgProvider.init Init= ialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 9339 T3287 oass.IndexSchema.readSchema default search = field in schema is text [junit4:junit4] 2> 9340 T3287 oass.IndexSchema.readSchema unique key fiel= d: id [junit4:junit4] 2> 9355 T3287 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 9358 T3287 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 9362 T3287 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 9364 T3287 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 9366 T3287 oasc.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.UnloadDistributedZkTest-jetty2-1= 361394851170/collection1/, dataDir=3D./org.apache.solr.cloud.UnloadDistribu= tedZkTest-1361394843258/jetty2/ [junit4:junit4] 2> 9366 T3287 oasc.JmxMonitoredMap. JMX monitoring = is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMB= eanServer@66bba6f9 [junit4:junit4] 2> 9366 T3287 oasc.SolrCore.initDirectoryFactory org.apac= he.solr.core.MockDirectoryFactory [junit4:junit4] 2> 9367 T3287 oasc.CachingDirectoryFactory.get return new= directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/= solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-136139484= 3258/jetty2 forceNew:false [junit4:junit4] 2> 9367 T3287 oasc.CachingDirectoryFactory.close Releasin= g directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/sol= r-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-136139484325= 8/jetty2 [junit4:junit4] 2> 9368 T3287 oasc.SolrCore.getNewIndexDir New index dire= ctory detected: old=3Dnull new=3D./org.apache.solr.cloud.UnloadDistributedZ= kTest-1361394843258/jetty2/index/ [junit4:junit4] 2> 9368 T3287 oasc.SolrCore.initIndex WARNING [collection= 1] Solr index directory './org.apache.solr.cloud.UnloadDistributedZkTest-13= 61394843258/jetty2/index' doesn't exist. Creating new index... [junit4:junit4] 2> 9369 T3287 oasc.CachingDirectoryFactory.get return new= directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/= solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-136139484= 3258/jetty2/index forceNew:false [junit4:junit4] 2> 9371 T3287 oasc.SolrDeletionPolicy.onCommit SolrDeleti= onPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@13177e8a lockFactory=3Dorg.apache.lucene.store.NativeFSLoc= kFactory@35a847cd),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_= 1] [junit4:junit4] 2> 9371 T3287 oasc.SolrDeletionPolicy.updateCommits newes= t commit =3D 1[segments_1] [junit4:junit4] 2> 9372 T3287 oasc.CachingDirectoryFactory.close Releasin= g directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/sol= r-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-136139484325= 8/jetty2/index [junit4:junit4] 2> 9373 T3287 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe" [junit4:junit4] 2> 9373 T3287 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "s= tored_sig" [junit4:junit4] 2> 9374 T3287 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= istrib-dup-test-chain-implicit" [junit4:junit4] 2> 9374 T3287 oasc.RequestHandlers.initHandlersFromConfig= created standard: solr.StandardRequestHandler [junit4:junit4] 2> 9375 T3287 oasc.RequestHandlers.initHandlersFromConfig= created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 9375 T3287 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 9376 T3287 oasc.RequestHandlers.initHandlersFromConfig= created /replication: solr.ReplicationHandler [junit4:junit4] 2> 9376 T3287 oasc.RequestHandlers.initHandlersFromConfig= created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 9376 T3287 oasc.RequestHandlers.initHandlersFromConfig= created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 9380 T3287 oashl.XMLLoader.init xsltCacheLifetimeSecon= ds=3D60 [junit4:junit4] 2> 9382 T3253 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 9383 T3253 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D2 message=3D{ [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:60465_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:60465", [junit4:junit4] 2> =09 "shard":"shard2", [junit4:junit4] 2> =09 "numShards":"2", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"active", [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "core":"collection1"} [junit4:junit4] 2> 9384 T3287 oasc.CachingDirectoryFactory.close Releasin= g directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/sol= r-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-136139484325= 8/jetty2 [junit4:junit4] 2> 9384 T3287 oass.SolrIndexSearcher. Opening Searc= her@10e6310a main [junit4:junit4] 2> 9384 T3287 oasu.UpdateHandler.clearLog Clearing tlog f= iles, tlogDir=3D./org.apache.solr.cloud.UnloadDistributedZkTest-13613948432= 58/jetty2/tlog [junit4:junit4] 2> 9385 T3287 oasu.CommitTracker. Hard AutoCommit: = disabled [junit4:junit4] 2> 9386 T3287 oasu.CommitTracker. Soft AutoCommit: = disabled [junit4:junit4] 2> 9387 T3271 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 9388 T3258 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 9388 T3286 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 9387 T3252 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 9388 T3288 oasc.SolrCore.registerSearcher [collection1= ] Registered new searcher Searcher@10e6310a main{StandardDirectoryReader(se= gments_1:1)} [junit4:junit4] 2> 9390 T3287 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Ddown [junit4:junit4] 2> 9390 T3287 oasc.ZkController.publish numShards not fou= nd on descriptor - reading it from system property [junit4:junit4] 2> 10891 T3253 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 10892 T3253 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D2 message=3D{ [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:60062_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:60062", [junit4:junit4] 2> =09 "shard":null, [junit4:junit4] 2> =09 "numShards":"2", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"down", [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "core":"collection1"} [junit4:junit4] 2> 10892 T3253 oasc.Overseer$ClusterStateUpdater.updateSt= ate Collection already exists with numShards=3D2 [junit4:junit4] 2> 10892 T3253 oasc.Overseer$ClusterStateUpdater.updateSt= ate Assigning new node to shard shard=3Dshard1 [junit4:junit4] 2> 10895 T3258 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 10895 T3252 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 10895 T3286 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 10895 T3271 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 11392 T3287 oasc.CoreContainer.registerCore registerin= g core: collection1 [junit4:junit4] 2> 11392 T3287 oasc.ZkController.register Register replic= a - core:collection1 address:http://127.0.0.1:60062 collection:collection1 = shard:shard1 [junit4:junit4] 2> 11394 T3287 oascc.SolrZkClient.makePath makePath: /col= lections/collection1/leader_elect/shard1/election [junit4:junit4] 2> 11403 T3235 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13cf974be7e0008 type:de= lete cxid:0x45 zxid:0x7e txntype:-1 reqpath:n/a Error Path:/solr/collection= s/collection1/leaders/shard1 Error:KeeperErrorCode =3D NoNode for /solr/col= lections/collection1/leaders/shard1 [junit4:junit4] 2> 11404 T3287 oasc.ShardLeaderElectionContext.runLeaderP= rocess Running the leader process. [junit4:junit4] 2> 11404 T3235 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13cf974be7e0008 type:cr= eate cxid:0x46 zxid:0x7f txntype:-1 reqpath:n/a Error Path:/solr/overseer E= rror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 11407 T3287 oasc.ShardLeaderElectionContext.waitForRep= licasToComeUp Enough replicas found to continue. [junit4:junit4] 2> 11407 T3287 oasc.ShardLeaderElectionContext.runLeaderP= rocess I may be the new leader - try and sync [junit4:junit4] 2> 11407 T3287 oasc.SyncStrategy.sync Sync replicas to ht= tp://127.0.0.1:60062/collection1/ [junit4:junit4] 2> 11408 T3287 oasc.SyncStrategy.syncReplicas Sync Succes= s - now sync replicas to me [junit4:junit4] 2> 11408 T3287 oasc.SyncStrategy.syncToMe http://127.0.0.= 1:60062/collection1/ has no replicas [junit4:junit4] 2> 11408 T3287 oasc.ShardLeaderElectionContext.runLeaderP= rocess I am the new leader: http://127.0.0.1:60062/collection1/ [junit4:junit4] 2> 11408 T3287 oascc.SolrZkClient.makePath makePath: /col= lections/collection1/leaders/shard1 [junit4:junit4] 2> 11413 T3235 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13cf974be7e0008 type:cr= eate cxid:0x4f zxid:0x82 txntype:-1 reqpath:n/a Error Path:/solr/overseer E= rror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 12401 T3253 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 12411 T3252 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 12411 T3286 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 12411 T3258 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 12411 T3271 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 12418 T3287 oasc.ZkController.register We are http://1= 27.0.0.1:60062/collection1/ and leader is http://127.0.0.1:60062/collection= 1/ [junit4:junit4] 2> 12418 T3287 oasc.ZkController.register No LogReplay ne= eded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:60062 [junit4:junit4] 2> 12418 T3287 oasc.ZkController.checkRecovery I am the l= eader, no recovery necessary [junit4:junit4] 2> 12419 T3287 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Dactive [junit4:junit4] 2> 12419 T3287 oasc.ZkController.publish numShards not fo= und on descriptor - reading it from system property [junit4:junit4] 2> 12421 T3287 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 12422 T3230 oass.SolrDispatchFilter.init user.dir=3D/m= nt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1 [junit4:junit4] 2> 12423 T3230 oass.SolrDispatchFilter.init SolrDispatchF= ilter.init() done [junit4:junit4] 2> 12424 T3230 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&f= ollowRedirects=3Dfalse [junit4:junit4] 2> 12473 T3230 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 12476 T3230 oejs.AbstractConnector.doStart Started Sel= ectChannelConnector@127.0.0.1:46399 [junit4:junit4] 2> 12477 T3230 oass.SolrDispatchFilter.init SolrDispatchF= ilter.init() [junit4:junit4] 2> 12477 T3230 oasc.SolrResourceLoader.locateSolrHome JND= I not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 12478 T3230 oasc.SolrResourceLoader.locateSolrHome usi= ng system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4= .x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistrib= utedZkTest-jetty3-1361394855683 [junit4:junit4] 2> 12478 T3230 oasc.CoreContainer$Initializer.initialize = looking for solr.xml: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr= /build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-je= tty3-1361394855683/solr.xml [junit4:junit4] 2> 12479 T3230 oasc.CoreContainer. New CoreContaine= r 1208254811 [junit4:junit4] 2> 12480 T3230 oasc.CoreContainer.load Loading CoreContai= ner using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr= /build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-je= tty3-1361394855683/' [junit4:junit4] 2> 12480 T3230 oasc.SolrResourceLoader. new SolrRes= ourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linu= x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkT= est-jetty3-1361394855683/' [junit4:junit4] 2> 12504 T3230 oashc.HttpShardHandlerFactory.getParameter= Setting socketTimeout to: 120000 [junit4:junit4] 2> 12504 T3230 oashc.HttpShardHandlerFactory.getParameter= Setting urlScheme to: http:// [junit4:junit4] 2> 12504 T3230 oashc.HttpShardHandlerFactory.getParameter= Setting connTimeout to: 15000 [junit4:junit4] 2> 12505 T3230 oashc.HttpShardHandlerFactory.getParameter= Setting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 12505 T3230 oashc.HttpShardHandlerFactory.getParameter= Setting corePoolSize to: 0 [junit4:junit4] 2> 12505 T3230 oashc.HttpShardHandlerFactory.getParameter= Setting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 12506 T3230 oashc.HttpShardHandlerFactory.getParameter= Setting maxThreadIdleTime to: 5 [junit4:junit4] 2> 12506 T3230 oashc.HttpShardHandlerFactory.getParameter= Setting sizeOfQueue to: -1 [junit4:junit4] 2> 12506 T3230 oashc.HttpShardHandlerFactory.getParameter= Setting fairnessPolicy to: false [junit4:junit4] 2> 12506 T3230 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000= &socketTimeout=3D120000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 12511 T3230 oasc.CoreContainer.load Registering Log Li= stener [junit4:junit4] 2> 12518 T3230 oasc.CoreContainer.initZooKeeper Zookeeper= client=3D127.0.0.1:35536/solr [junit4:junit4] 2> 12519 T3230 oasc.ZkController.checkChrootPath zkHost i= ncludes chroot [junit4:junit4] 2> 12519 T3230 oaz.ZooKeeper. Initiating client con= nection, connectString=3D127.0.0.1:35536 sessionTimeout=3D60000 watcher=3Do= rg.apache.solr.common.cloud.ConnectionManager@43469f85 [junit4:junit4] 2> 12520 T3230 oascc.ConnectionManager.waitForConnected W= aiting for client to connect to ZooKeeper [junit4:junit4] 2> 12520 T3298 oaz.ClientCnxn$SendThread.logStartConnect = Opening socket connection to server localhost.localdomain/127.0.0.1:35536. = Will not attempt to authenticate using SASL (access denied ("javax.security= .auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 2> 12521 T3298 oaz.ClientCnxn$SendThread.primeConnection = Socket connection established to localhost.localdomain/127.0.0.1:35536, ini= tiating session [junit4:junit4] 2> 12521 T3232 oazs.NIOServerCnxnFactory.run Accepted soc= ket connection from /127.0.0.1:51791 [junit4:junit4] 2> 12521 T3232 oazs.ZooKeeperServer.processConnectRequest= Client attempting to establish new session at /127.0.0.1:51791 [junit4:junit4] 2> 12522 T3234 oazs.ZooKeeperServer.finishSessionInit Est= ablished session 0x13cf974be7e0009 with negotiated timeout 20000 for client= /127.0.0.1:51791 [junit4:junit4] 2> 12522 T3298 oaz.ClientCnxn$SendThread.onConnected Sess= ion establishment complete on server localhost.localdomain/127.0.0.1:35536,= sessionid =3D 0x13cf974be7e0009, negotiated timeout =3D 20000 [junit4:junit4] 2> 12522 T3299 oascc.ConnectionManager.process Watcher or= g.apache.solr.common.cloud.ConnectionManager@43469f85 name:ZooKeeperConnect= ion Watcher:127.0.0.1:35536 got event WatchedEvent state:SyncConnected type= :None path:null path:null type:None [junit4:junit4] 2> 12523 T3230 oascc.ConnectionManager.waitForConnected C= lient is connected to ZooKeeper [junit4:junit4] 2> 12524 T3235 oazs.PrepRequestProcessor.pRequest2Txn Pro= cessed session termination for sessionid: 0x13cf974be7e0009 [junit4:junit4] 2> 12524 T3232 oazs.NIOServerCnxn.closeSock Closed socket= connection for client /127.0.0.1:51791 which had sessionid 0x13cf974be7e00= 09 [junit4:junit4] 2> 12524 T3299 oaz.ClientCnxn$EventThread.run EventThread= shut down [junit4:junit4] 2> 12524 T3230 oaz.ZooKeeper.close Session: 0x13cf974be7e= 0009 closed [junit4:junit4] 2> 12524 T3230 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&s= ocketTimeout=3D120000&connTimeout=3D15000 [junit4:junit4] 2> 12526 T3230 oaz.ZooKeeper. Initiating client con= nection, connectString=3D127.0.0.1:35536/solr sessionTimeout=3D30000 watche= r=3Dorg.apache.solr.common.cloud.ConnectionManager@1533d98a [junit4:junit4] 2> 12527 T3300 oaz.ClientCnxn$SendThread.logStartConnect = Opening socket connection to server localhost.localdomain/127.0.0.1:35536. = Will not attempt to authenticate using SASL (access denied ("javax.security= .auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 2> 12527 T3230 oascc.ConnectionManager.waitForConnected W= aiting for client to connect to ZooKeeper [junit4:junit4] 2> 12528 T3300 oaz.ClientCnxn$SendThread.primeConnection = Socket connection established to localhost.localdomain/127.0.0.1:35536, ini= tiating session [junit4:junit4] 2> 12528 T3232 oazs.NIOServerCnxnFactory.run Accepted soc= ket connection from /127.0.0.1:51792 [junit4:junit4] 2> 12528 T3232 oazs.ZooKeeperServer.processConnectRequest= Client attempting to establish new session at /127.0.0.1:51792 [junit4:junit4] 2> 12529 T3234 oazs.ZooKeeperServer.finishSessionInit Est= ablished session 0x13cf974be7e000a with negotiated timeout 20000 for client= /127.0.0.1:51792 [junit4:junit4] 2> 12529 T3300 oaz.ClientCnxn$SendThread.onConnected Sess= ion establishment complete on server localhost.localdomain/127.0.0.1:35536,= sessionid =3D 0x13cf974be7e000a, negotiated timeout =3D 20000 [junit4:junit4] 2> 12529 T3301 oascc.ConnectionManager.process Watcher or= g.apache.solr.common.cloud.ConnectionManager@1533d98a name:ZooKeeperConnect= ion Watcher:127.0.0.1:35536/solr got event WatchedEvent state:SyncConnected= type:None path:null path:null type:None [junit4:junit4] 2> 12529 T3230 oascc.ConnectionManager.waitForConnected C= lient is connected to ZooKeeper [junit4:junit4] 2> 12530 T3235 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13cf974be7e000a type:cr= eate cxid:0x1 zxid:0x8f txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 12530 T3235 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13cf974be7e000a type:cr= eate cxid:0x2 zxid:0x90 txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 12531 T3230 oascc.ZkStateReader.createClusterStateWatc= hersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 13534 T3230 oasc.ZkController.createEphemeralLiveNode = Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46399_ [junit4:junit4] 2> 13535 T3235 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13cf974be7e000a type:de= lete cxid:0x9 zxid:0x91 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/= 127.0.0.1:46399_ Error:KeeperErrorCode =3D NoNode for /solr/live_nodes/127.= 0.0.1:46399_ [junit4:junit4] 2> 13536 T3230 oascc.SolrZkClient.makePath makePath: /liv= e_nodes/127.0.0.1:46399_ [junit4:junit4] 2> 13539 T3258 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 13539 T3286 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 13540 T3271 oascc.ZkStateReader$3.process Updating liv= e nodes... (4) [junit4:junit4] 2> 13540 T3301 oascc.ZkStateReader$3.process Updating liv= e nodes... (4) [junit4:junit4] 2> 13540 T3252 oascc.ZkStateReader$3.process Updating liv= e nodes... (4) [junit4:junit4] 2> 13540 T3271 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 13540 T3252 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 13541 T3258 oascc.ZkStateReader$3.process Updating liv= e nodes... (4) [junit4:junit4] 2> 13541 T3286 oascc.ZkStateReader$3.process Updating liv= e nodes... (4) [junit4:junit4] 2> 13548 T3302 oasc.CoreContainer.create Creating SolrCor= e 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4= .x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistrib= utedZkTest-jetty3-1361394855683/collection1 [junit4:junit4] 2> 13548 T3302 oasc.ZkController.createCollectionZkNode C= heck for collection zkNode:collection1 [junit4:junit4] 2> 13549 T3302 oasc.ZkController.createCollectionZkNode C= ollection zkNode exists [junit4:junit4] 2> 13549 T3302 oasc.ZkController.readConfigName Load coll= ection config from:/collections/collection1 [junit4:junit4] 2> 13551 T3302 oasc.SolrResourceLoader. new SolrRes= ourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linu= x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkT= est-jetty3-1361394855683/collection1/' [junit4:junit4] 2> 13552 T3302 oasc.SolrResourceLoader.replaceClassLoader= Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/s= olr-core/test/J1/org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-13613= 94855683/collection1/lib/README' to classloader [junit4:junit4] 2> 13552 T3302 oasc.SolrResourceLoader.replaceClassLoader= Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/s= olr-core/test/J1/org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-13613= 94855683/collection1/lib/classes/' to classloader [junit4:junit4] 2> 13582 T3302 oasc.SolrConfig. Using Lucene MatchV= ersion: LUCENE_42 [junit4:junit4] 2> 13604 T3302 oasc.SolrConfig. Loaded SolrConfig: = solrconfig.xml [junit4:junit4] 2> 13605 T3302 oass.IndexSchema.readSchema Reading Solr S= chema [junit4:junit4] 2> 13607 T3302 oass.IndexSchema.readSchema Schema name=3D= test [junit4:junit4] 2> 13845 T3302 oass.OpenExchangeRatesOrgProvider.init Ini= tialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 13849 T3302 oass.IndexSchema.readSchema default search= field in schema is text [junit4:junit4] 2> 13850 T3302 oass.IndexSchema.readSchema unique key fie= ld: id [junit4:junit4] 2> 13862 T3302 oass.FileExchangeRateProvider.reload Reloa= ding exchange rates from file currency.xml [junit4:junit4] 2> 13865 T3302 oass.FileExchangeRateProvider.reload Reloa= ding exchange rates from file currency.xml [junit4:junit4] 2> 13867 T3302 oass.OpenExchangeRatesOrgProvider.reload R= eloading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 13869 T3302 oass.OpenExchangeRatesOrgProvider.reload R= eloading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 13870 T3302 oasc.SolrCore. [collection1] Opening= new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/buil= d/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-= 1361394855683/collection1/, dataDir=3D./org.apache.solr.cloud.UnloadDistrib= utedZkTest-1361394843258/jetty3/ [junit4:junit4] 2> 13871 T3302 oasc.JmxMonitoredMap. JMX monitoring= is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxM= BeanServer@66bba6f9 [junit4:junit4] 2> 13871 T3302 oasc.SolrCore.initDirectoryFactory org.apa= che.solr.core.MockDirectoryFactory [junit4:junit4] 2> 13871 T3302 oasc.CachingDirectoryFactory.get return ne= w directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build= /solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-13613948= 43258/jetty3 forceNew:false [junit4:junit4] 2> 13872 T3302 oasc.CachingDirectoryFactory.close Releasi= ng directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/so= lr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-13613948432= 58/jetty3 [junit4:junit4] 2> 13872 T3302 oasc.SolrCore.getNewIndexDir New index dir= ectory detected: old=3Dnull new=3D./org.apache.solr.cloud.UnloadDistributed= ZkTest-1361394843258/jetty3/index/ [junit4:junit4] 2> 13872 T3302 oasc.SolrCore.initIndex WARNING [collectio= n1] Solr index directory './org.apache.solr.cloud.UnloadDistributedZkTest-1= 361394843258/jetty3/index' doesn't exist. Creating new index... [junit4:junit4] 2> 13873 T3302 oasc.CachingDirectoryFactory.get return ne= w directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build= /solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-13613948= 43258/jetty3/index forceNew:false [junit4:junit4] 2> 13874 T3302 oasc.SolrDeletionPolicy.onCommit SolrDelet= ionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@6d86f160 lockFactory=3Dorg.apache.lucene.store.NativeFSLoc= kFactory@3612997),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1= ] [junit4:junit4] 2> 13874 T3302 oasc.SolrDeletionPolicy.updateCommits newe= st commit =3D 1[segments_1] [junit4:junit4] 2> 13874 T3302 oasc.CachingDirectoryFactory.close Releasi= ng directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/so= lr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-13613948432= 58/jetty3/index [junit4:junit4] 2> 13875 T3302 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= dedupe" [junit4:junit4] 2> 13876 T3302 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= stored_sig" [junit4:junit4] 2> 13876 T3302 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= distrib-dup-test-chain-implicit" [junit4:junit4] 2> 13876 T3302 oasc.RequestHandlers.initHandlersFromConfi= g created standard: solr.StandardRequestHandler [junit4:junit4] 2> 13877 T3302 oasc.RequestHandlers.initHandlersFromConfi= g created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 13877 T3302 oasc.RequestHandlers.initHandlersFromConfi= g adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 13877 T3302 oasc.RequestHandlers.initHandlersFromConfi= g created /replication: solr.ReplicationHandler [junit4:junit4] 2> 13877 T3302 oasc.RequestHandlers.initHandlersFromConfi= g created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 13878 T3302 oasc.RequestHandlers.initHandlersFromConfi= g created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 13881 T3302 oashl.XMLLoader.init xsltCacheLifetimeSeco= nds=3D60 [junit4:junit4] 2> 13883 T3302 oasc.CachingDirectoryFactory.close Releasi= ng directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/so= lr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-13613948432= 58/jetty3 [junit4:junit4] 2> 13884 T3302 oass.SolrIndexSearcher. Opening Sear= cher@461a02cc main [junit4:junit4] 2> 13884 T3302 oasu.UpdateHandler.clearLog Clearing tlog = files, tlogDir=3D./org.apache.solr.cloud.UnloadDistributedZkTest-1361394843= 258/jetty3/tlog [junit4:junit4] 2> 13885 T3302 oasu.CommitTracker. Hard AutoCommit:= disabled [junit4:junit4] 2> 13885 T3302 oasu.CommitTracker. Soft AutoCommit:= disabled [junit4:junit4] 2> 13887 T3302 oasc.CachingDirectoryFactory.close Releasi= ng directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/so= lr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-13613948432= 58/jetty3 [junit4:junit4] 2> 13898 T3303 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@461a02cc main{StandardDirectoryReader(s= egments_1:1)} [junit4:junit4] 2> 13899 T3302 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Ddown [junit4:junit4] 2> 13899 T3302 oasc.ZkController.publish numShards not fo= und on descriptor - reading it from system property [junit4:junit4] 2> 13919 T3253 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 13920 T3253 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D2 message=3D{ [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:60062_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:60062", [junit4:junit4] 2> =09 "shard":"shard1", [junit4:junit4] 2> =09 "numShards":"2", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"active", [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "core":"collection1"} [junit4:junit4] 2> 13924 T3253 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D2 message=3D{ [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:46399_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:46399", [junit4:junit4] 2> =09 "shard":null, [junit4:junit4] 2> =09 "numShards":"2", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"down", [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "core":"collection1"} [junit4:junit4] 2> 13925 T3253 oasc.Overseer$ClusterStateUpdater.updateSt= ate Collection already exists with numShards=3D2 [junit4:junit4] 2> 13925 T3253 oasc.Overseer$ClusterStateUpdater.updateSt= ate Assigning new node to shard shard=3Dshard2 [junit4:junit4] 2> 13930 T3271 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 13930 T3286 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 13930 T3252 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 13930 T3301 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 13930 T3258 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 14901 T3302 oasc.CoreContainer.registerCore registerin= g core: collection1 [junit4:junit4] 2> 14901 T3302 oasc.ZkController.register Register replic= a - core:collection1 address:http://127.0.0.1:46399 collection:collection1 = shard:shard2 [junit4:junit4] 2> 15178 T3302 oasc.ZkController.register We are http://1= 27.0.0.1:46399/collection1/ and leader is http://127.0.0.1:60465/collection= 1/ [junit4:junit4] 2> 15178 T3302 oasc.ZkController.register No LogReplay ne= eded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:46399 [junit4:junit4] 2> 15178 T3302 oasc.ZkController.checkRecovery Core needs= to recover:collection1 [junit4:junit4] 2> 15178 T3302 oasu.DefaultSolrCoreState.doRecovery Runni= ng recovery - first canceling any ongoing recovery [junit4:junit4] 2> ASYNC NEW_CORE C179 name=3Dcollection1 org.apache.sol= r.core.SolrCore@6fff3c13 url=3Dhttp://127.0.0.1:46399/collection1 node=3D12= 7.0.0.1:46399_ C179_STATE=3Dcoll:collection1 core:collection1 props:{collec= tion=3Dcollection1, node_name=3D127.0.0.1:46399_, base_url=3Dhttp://127.0.0= .1:46399, shard=3Dnull, roles=3Dnull, state=3Ddown, core=3Dcollection1} [junit4:junit4] 2> 15179 T3304 C179 P46399 oasc.RecoveryStrategy.run Star= ting recovery process. core=3Dcollection1 recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 15180 T3304 C179 P46399 oasc.RecoveryStrategy.doRecove= ry ###### startupVersions=3D[] [junit4:junit4] 2> 15180 T3302 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 15180 T3304 C179 P46399 oasc.ZkController.publish publ= ishing core=3Dcollection1 state=3Drecovering [junit4:junit4] 2> 15181 T3304 C179 P46399 oasc.ZkController.publish numS= hards not found on descriptor - reading it from system property [junit4:junit4] 2> 15182 T3230 oass.SolrDispatchFilter.init user.dir=3D/m= nt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1 [junit4:junit4] 2> 15182 T3230 oass.SolrDispatchFilter.init SolrDispatchF= ilter.init() done [junit4:junit4] 2> 15183 T3304 C179 P46399 oascsi.HttpClientUtil.createCl= ient Creating new http client, config:maxConnections=3D128&maxConnectionsPe= rHost=3D32&followRedirects=3Dfalse [junit4:junit4] 2> 15183 T3230 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&f= ollowRedirects=3Dfalse [junit4:junit4] 2> 15248 T3230 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 15250 T3230 oejs.AbstractConnector.doStart Started Sel= ectChannelConnector@127.0.0.1:51909 [junit4:junit4] 2> 15250 T3230 oass.SolrDispatchFilter.init SolrDispatchF= ilter.init() [junit4:junit4] 2> 15250 T3230 oasc.SolrResourceLoader.locateSolrHome JND= I not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 15251 T3230 oasc.SolrResourceLoader.locateSolrHome usi= ng system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4= .x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistrib= utedZkTest-jetty4-1361394858443 [junit4:junit4] 2> 15251 T3230 oasc.CoreContainer$Initializer.initialize = looking for solr.xml: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr= /build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-je= tty4-1361394858443/solr.xml [junit4:junit4] 2> 15251 T3230 oasc.CoreContainer. New CoreContaine= r 210083313 [junit4:junit4] 2> 15252 T3230 oasc.CoreContainer.load Loading CoreContai= ner using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr= /build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-je= tty4-1361394858443/' [junit4:junit4] 2> 15252 T3230 oasc.SolrResourceLoader. new SolrRes= ourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linu= x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkT= est-jetty4-1361394858443/' [junit4:junit4] 2> 15270 T3230 oashc.HttpShardHandlerFactory.getParameter= Setting socketTimeout to: 120000 [junit4:junit4] 2> 15271 T3230 oashc.HttpShardHandlerFactory.getParameter= Setting urlScheme to: http:// [junit4:junit4] 2> 15271 T3230 oashc.HttpShardHandlerFactory.getParameter= Setting connTimeout to: 15000 [junit4:junit4] 2> 15272 T3230 oashc.HttpShardHandlerFactory.getParameter= Setting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 15272 T3230 oashc.HttpShardHandlerFactory.getParameter= Setting corePoolSize to: 0 [junit4:junit4] 2> 15273 T3230 oashc.HttpShardHandlerFactory.getParameter= Setting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 15273 T3230 oashc.HttpShardHandlerFactory.getParameter= Setting maxThreadIdleTime to: 5 [junit4:junit4] 2> 15273 T3230 oashc.HttpShardHandlerFactory.getParameter= Setting sizeOfQueue to: -1 [junit4:junit4] 2> 15274 T3230 oashc.HttpShardHandlerFactory.getParameter= Setting fairnessPolicy to: false [junit4:junit4] 2> 15274 T3230 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000= &socketTimeout=3D120000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 15282 T3230 oasc.CoreContainer.load Registering Log Li= stener [junit4:junit4] 2> 15293 T3230 oasc.CoreContainer.initZooKeeper Zookeeper= client=3D127.0.0.1:35536/solr [junit4:junit4] 2> 15294 T3230 oasc.ZkController.checkChrootPath zkHost i= ncludes chroot [junit4:junit4] 2> 15295 T3230 oaz.ZooKeeper. Initiating client con= nection, connectString=3D127.0.0.1:35536 sessionTimeout=3D60000 watcher=3Do= rg.apache.solr.common.cloud.ConnectionManager@3b4e5b6d [junit4:junit4] 2> 15295 T3314 oaz.ClientCnxn$SendThread.logStartConnect = Opening socket connection to server localhost.localdomain/127.0.0.1:35536. = Will not attempt to authenticate using SASL (access denied ("javax.security= .auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 2> 15295 T3230 oascc.ConnectionManager.waitForConnected W= aiting for client to connect to ZooKeeper [junit4:junit4] 2> 15296 T3314 oaz.ClientCnxn$SendThread.primeConnection = Socket connection established to localhost.localdomain/127.0.0.1:35536, ini= tiating session [junit4:junit4] 2> 15296 T3232 oazs.NIOServerCnxnFactory.run Accepted soc= ket connection from /127.0.0.1:51798 [junit4:junit4] 2> 15297 T3232 oazs.ZooKeeperServer.processConnectRequest= Client attempting to establish new session at /127.0.0.1:51798 [junit4:junit4] 2> 15297 T3234 oazs.ZooKeeperServer.finishSessionInit Est= ablished session 0x13cf974be7e000b with negotiated timeout 20000 for client= /127.0.0.1:51798 [junit4:junit4] 2> 15297 T3314 oaz.ClientCnxn$SendThread.onConnected Sess= ion establishment complete on server localhost.localdomain/127.0.0.1:35536,= sessionid =3D 0x13cf974be7e000b, negotiated timeout =3D 20000 [junit4:junit4] 2> 15298 T3315 oascc.ConnectionManager.process Watcher or= g.apache.solr.common.cloud.ConnectionManager@3b4e5b6d name:ZooKeeperConnect= ion Watcher:127.0.0.1:35536 got event WatchedEvent state:SyncConnected type= :None path:null path:null type:None [junit4:junit4] 2> 15298 T3230 oascc.ConnectionManager.waitForConnected C= lient is connected to ZooKeeper [junit4:junit4] 2> 15299 T3235 oazs.PrepRequestProcessor.pRequest2Txn Pro= cessed session termination for sessionid: 0x13cf974be7e000b [junit4:junit4] 2> 15299 T3315 oaz.ClientCnxn$EventThread.run EventThread= shut down [junit4:junit4] 2> 15299 T3232 oazs.NIOServerCnxn.closeSock Closed socket= connection for client /127.0.0.1:51798 which had sessionid 0x13cf974be7e00= 0b [junit4:junit4] 2> 15299 T3230 oaz.ZooKeeper.close Session: 0x13cf974be7e= 000b closed [junit4:junit4] 2> 15300 T3230 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&s= ocketTimeout=3D120000&connTimeout=3D15000 [junit4:junit4] 2> 15303 T3230 oaz.ZooKeeper. Initiating client con= nection, connectString=3D127.0.0.1:35536/solr sessionTimeout=3D30000 watche= r=3Dorg.apache.solr.common.cloud.ConnectionManager@100bde32 [junit4:junit4] 2> 15304 T3316 oaz.ClientCnxn$SendThread.logStartConnect = Opening socket connection to server localhost.localdomain/127.0.0.1:35536. = Will not attempt to authenticate using SASL (access denied ("javax.security= .auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 2> 15303 T3230 oascc.ConnectionManager.waitForConnected W= aiting for client to connect to ZooKeeper [junit4:junit4] 2> 15304 T3316 oaz.ClientCnxn$SendThread.primeConnection = Socket connection established to localhost.localdomain/127.0.0.1:35536, ini= tiating session [junit4:junit4] 2> 15304 T3232 oazs.NIOServerCnxnFactory.run Accepted soc= ket connection from /127.0.0.1:51799 [junit4:junit4] 2> 15304 T3232 oazs.ZooKeeperServer.processConnectRequest= Client attempting to establish new session at /127.0.0.1:51799 [junit4:junit4] 2> 15305 T3234 oazs.ZooKeeperServer.finishSessionInit Est= ablished session 0x13cf974be7e000c with negotiated timeout 20000 for client= /127.0.0.1:51799 [junit4:junit4] 2> 15305 T3316 oaz.ClientCnxn$SendThread.onConnected Sess= ion establishment complete on server localhost.localdomain/127.0.0.1:35536,= sessionid =3D 0x13cf974be7e000c, negotiated timeout =3D 20000 [junit4:junit4] 2> 15305 T3317 oascc.ConnectionManager.process Watcher or= g.apache.solr.common.cloud.ConnectionManager@100bde32 name:ZooKeeperConnect= ion Watcher:127.0.0.1:35536/solr got event WatchedEvent state:SyncConnected= type:None path:null path:null type:None [junit4:junit4] 2> 15306 T3230 oascc.ConnectionManager.waitForConnected C= lient is connected to ZooKeeper [junit4:junit4] 2> 15307 T3235 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13cf974be7e000c type:cr= eate cxid:0x1 zxid:0xa1 txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 15308 T3235 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13cf974be7e000c type:cr= eate cxid:0x2 zxid:0xa2 txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 15309 T3230 oascc.ZkStateReader.createClusterStateWatc= hersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 15437 T3253 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 15438 T3253 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D2 message=3D{ [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:46399_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:46399", [junit4:junit4] 2> =09 "shard":"shard2", [junit4:junit4] 2> =09 "numShards":"2", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"recovering", [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "core":"collection1"} [junit4:junit4] 2> 15442 T3252 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 15442 T3271 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 15442 T3258 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 15442 T3301 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 15442 T3286 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 15442 T3317 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 16312 T3230 oasc.ZkController.createEphemeralLiveNode = Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51909_ [junit4:junit4] 2> 16313 T3235 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13cf974be7e000c type:de= lete cxid:0xb zxid:0xa7 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/= 127.0.0.1:51909_ Error:KeeperErrorCode =3D NoNode for /solr/live_nodes/127.= 0.0.1:51909_ [junit4:junit4] 2> 16314 T3230 oascc.SolrZkClient.makePath makePath: /liv= e_nodes/127.0.0.1:51909_ [junit4:junit4] 2> 16317 T3252 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 16317 T3271 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 16317 T3258 oascc.ZkStateReader$3.process Updating liv= e nodes... (5) [junit4:junit4] 2> 16317 T3301 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 16317 T3258 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 16318 T3286 oascc.ZkStateReader$3.process Updating liv= e nodes... (5) [junit4:junit4] 2> 16318 T3317 oascc.ZkStateReader$3.process Updating liv= e nodes... (5) [junit4:junit4] 2> 16318 T3317 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 16318 T3286 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 16320 T3271 oascc.ZkStateReader$3.process Updating liv= e nodes... (5) [junit4:junit4] 2> 16320 T3252 oascc.ZkStateReader$3.process Updating liv= e nodes... (5) [junit4:junit4] 2> 16320 T3301 oascc.ZkStateReader$3.process Updating liv= e nodes... (5) [junit4:junit4] 2> 16326 T3318 oasc.CoreContainer.create Creating SolrCor= e 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4= .x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistrib= utedZkTest-jetty4-1361394858443/collection1 [junit4:junit4] 2> 16326 T3318 oasc.ZkController.createCollectionZkNode C= heck for collection zkNode:collection1 [junit4:junit4] 2> 16327 T3318 oasc.ZkController.createCollectionZkNode C= ollection zkNode exists [junit4:junit4] 2> 16327 T3318 oasc.ZkController.readConfigName Load coll= ection config from:/collections/collection1 [junit4:junit4] 2> 16329 T3318 oasc.SolrResourceLoader. new SolrRes= ourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linu= x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkT= est-jetty4-1361394858443/collection1/' [junit4:junit4] 2> 16330 T3318 oasc.SolrResourceLoader.replaceClassLoader= Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/s= olr-core/test/J1/org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-13613= 94858443/collection1/lib/README' to classloader [junit4:junit4] 2> 16330 T3318 oasc.SolrResourceLoader.replaceClassLoader= Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/s= olr-core/test/J1/org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-13613= 94858443/collection1/lib/classes/' to classloader [junit4:junit4] 2> 16370 T3318 oasc.SolrConfig. Using Lucene MatchV= ersion: LUCENE_42 [junit4:junit4] 2> 16399 T3318 oasc.SolrConfig. Loaded SolrConfig: = solrconfig.xml [junit4:junit4] 2> 16400 T3318 oass.IndexSchema.readSchema Reading Solr S= chema [junit4:junit4] 2> 16403 T3318 oass.IndexSchema.readSchema Schema name=3D= test [junit4:junit4] 2> 16678 T3318 oass.OpenExchangeRatesOrgProvider.init Ini= tialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 16682 T3318 oass.IndexSchema.readSchema default search= field in schema is text [junit4:junit4] 2> 16684 T3318 oass.IndexSchema.readSchema unique key fie= ld: id [junit4:junit4] 2> 16692 T3318 oass.FileExchangeRateProvider.reload Reloa= ding exchange rates from file currency.xml [junit4:junit4] 2> 16694 T3318 oass.FileExchangeRateProvider.reload Reloa= ding exchange rates from file currency.xml [junit4:junit4] 2> 16696 T3318 oass.OpenExchangeRatesOrgProvider.reload R= eloading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 16697 T3318 oass.OpenExchangeRatesOrgProvider.reload R= eloading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 16697 T3318 oasc.SolrCore. [collection1] Opening= new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/buil= d/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-= 1361394858443/collection1/, dataDir=3D./org.apache.solr.cloud.UnloadDistrib= utedZkTest-1361394843258/jetty4/ [junit4:junit4] 2> 16698 T3318 oasc.JmxMonitoredMap. JMX monitoring= is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxM= BeanServer@66bba6f9 [junit4:junit4] 2> 16698 T3318 oasc.SolrCore.initDirectoryFactory org.apa= che.solr.core.MockDirectoryFactory [junit4:junit4] 2> 16698 T3318 oasc.CachingDirectoryFactory.get return ne= w directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build= /solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-13613948= 43258/jetty4 forceNew:false [junit4:junit4] 2> 16699 T3318 oasc.CachingDirectoryFactory.close Releasi= ng directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/so= lr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-13613948432= 58/jetty4 [junit4:junit4] 2> 16699 T3318 oasc.SolrCore.getNewIndexDir New index dir= ectory detected: old=3Dnull new=3D./org.apache.solr.cloud.UnloadDistributed= ZkTest-1361394843258/jetty4/index/ [junit4:junit4] 2> 16699 T3318 oasc.SolrCore.initIndex WARNING [collectio= n1] Solr index directory './org.apache.solr.cloud.UnloadDistributedZkTest-1= 361394843258/jetty4/index' doesn't exist. Creating new index... [junit4:junit4] 2> 16700 T3318 oasc.CachingDirectoryFactory.get return ne= w directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build= /solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-13613948= 43258/jetty4/index forceNew:false [junit4:junit4] 2> 16701 T3318 oasc.SolrDeletionPolicy.onCommit SolrDelet= ionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@76339b3f lockFactory=3Dorg.apache.lucene.store.NativeFSLoc= kFactory@3df7b46c),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_= 1] [junit4:junit4] 2> 16701 T3318 oasc.SolrDeletionPolicy.updateCommits newe= st commit =3D 1[segments_1] [junit4:junit4] 2> 16701 T3318 oasc.CachingDirectoryFactory.close Releasi= ng directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/so= lr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-13613948432= 58/jetty4/index [junit4:junit4] 2> 16702 T3318 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= dedupe" [junit4:junit4] 2> 16703 T3318 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= stored_sig" [junit4:junit4] 2> 16703 T3318 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= distrib-dup-test-chain-implicit" [junit4:junit4] 2> 16703 T3318 oasc.RequestHandlers.initHandlersFromConfi= g created standard: solr.StandardRequestHandler [junit4:junit4] 2> 16704 T3318 oasc.RequestHandlers.initHandlersFromConfi= g created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 16704 T3318 oasc.RequestHandlers.initHandlersFromConfi= g adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 16704 T3318 oasc.RequestHandlers.initHandlersFromConfi= g created /replication: solr.ReplicationHandler [junit4:junit4] 2> 16704 T3318 oasc.RequestHandlers.initHandlersFromConfi= g created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 16705 T3318 oasc.RequestHandlers.initHandlersFromConfi= g created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 16707 T3318 oashl.XMLLoader.init xsltCacheLifetimeSeco= nds=3D60 [junit4:junit4] 2> 16709 T3318 oasc.CachingDirectoryFactory.close Releasi= ng directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/so= lr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-13613948432= 58/jetty4 [junit4:junit4] 2> 16710 T3318 oass.SolrIndexSearcher. Opening Sear= cher@3fe42c1e main [junit4:junit4] 2> 16710 T3318 oasu.UpdateHandler.clearLog Clearing tlog = files, tlogDir=3D./org.apache.solr.cloud.UnloadDistributedZkTest-1361394843= 258/jetty4/tlog [junit4:junit4] 2> 16710 T3318 oasu.CommitTracker. Hard AutoCommit:= disabled [junit4:junit4] 2> 16711 T3318 oasu.CommitTracker. Soft AutoCommit:= disabled [junit4:junit4] 2> 16714 T3319 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@3fe42c1e main{StandardDirectoryReader(s= egments_1:1)} [junit4:junit4] 2> 16716 T3318 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Ddown [junit4:junit4] 2> 16716 T3318 oasc.ZkController.publish numShards not fo= und on descriptor - reading it from system property [junit4:junit4] 2> 16945 T3253 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 16946 T3253 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D2 message=3D{ [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:51909_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:51909", [junit4:junit4] 2> =09 "shard":null, [junit4:junit4] 2> =09 "numShards":"2", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"down", [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "core":"collection1"} [junit4:junit4] 2> 16946 T3253 oasc.Overseer$ClusterStateUpdater.updateSt= ate Collection already exists with numShards=3D2 [junit4:junit4] 2> 16946 T3253 oasc.Overseer$ClusterStateUpdater.updateSt= ate Assigning new node to shard shard=3Dshard1 [junit4:junit4] 2> 17006 T3317 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 17006 T3301 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 17006 T3252 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 17006 T3258 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 17006 T3286 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 17006 T3271 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 17718 T3318 oasc.CoreContainer.registerCore registerin= g core: collection1 [junit4:junit4] 2> 17719 T3318 oasc.ZkController.register Register replic= a - core:collection1 address:http://127.0.0.1:51909 collection:collection1 = shard:shard1 [junit4:junit4] 2> 17723 T3318 oasc.ZkController.register We are http://1= 27.0.0.1:51909/collection1/ and leader is http://127.0.0.1:60062/collection= 1/ [junit4:junit4] 2> 17724 T3318 oasc.ZkController.register No LogReplay ne= eded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:51909 [junit4:junit4] 2> 17724 T3318 oasc.ZkController.checkRecovery Core needs= to recover:collection1 [junit4:junit4] 2> 17724 T3318 oasu.DefaultSolrCoreState.doRecovery Runni= ng recovery - first canceling any ongoing recovery [junit4:junit4] 2> ASYNC NEW_CORE C180 name=3Dcollection1 org.apache.sol= r.core.SolrCore@38810cb3 url=3Dhttp://127.0.0.1:51909/collection1 node=3D12= 7.0.0.1:51909_ C180_STATE=3Dcoll:collection1 core:collection1 props:{collec= tion=3Dcollection1, node_name=3D127.0.0.1:51909_, base_url=3Dhttp://127.0.0= .1:51909, shard=3Dnull, roles=3Dnull, state=3Ddown, core=3Dcollection1} [junit4:junit4] 2> 17725 T3320 C180 P51909 oasc.RecoveryStrategy.run Star= ting recovery process. core=3Dcollection1 recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 17726 T3320 C180 P51909 oasc.RecoveryStrategy.doRecove= ry ###### startupVersions=3D[] [junit4:junit4] 2> 17726 T3318 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 17726 T3320 C180 P51909 oasc.ZkController.publish publ= ishing core=3Dcollection1 state=3Drecovering [junit4:junit4] 2> 17727 T3320 C180 P51909 oasc.ZkController.publish numS= hards not found on descriptor - reading it from system property [junit4:junit4] 2> 17727 T3230 oass.SolrDispatchFilter.init user.dir=3D/m= nt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1 [junit4:junit4] 2> 17728 T3320 C180 P51909 oascsi.HttpClientUtil.createCl= ient Creating new http client, config:maxConnections=3D128&maxConnectionsPe= rHost=3D32&followRedirects=3Dfalse [junit4:junit4] 2> 17728 T3230 oass.SolrDispatchFilter.init SolrDispatchF= ilter.init() done [junit4:junit4] 2> 17729 T3230 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&f= ollowRedirects=3Dfalse [junit4:junit4] 2> 17733 T3230 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 17735 T3230 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&f= ollowRedirects=3Dfalse [junit4:junit4] 2> 17741 T3265 oasc.CoreContainer.create Creating SolrCor= e 'unloadcollection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-= Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadD= istributedZkTest-jetty1-1361394846624/unloadcollection1 [junit4:junit4] 2> 17741 T3265 oasc.ZkController.createCollectionZkNode C= heck for collection zkNode:unloadcollection [junit4:junit4] 2> 17742 T3265 oasc.ZkController.createCollectionZkNode C= reating collection in ZooKeeper:unloadcollection [junit4:junit4] 2> 17743 T3265 oasc.ZkController.getConfName Looking for = collection configName [junit4:junit4] 2> 17744 T3265 oasc.ZkController.getConfName Only one con= fig set found in zk - using it:conf1 [junit4:junit4] 2> 17745 T3265 oascc.SolrZkClient.makePath makePath: /col= lections/unloadcollection [junit4:junit4] 2> 17748 T3265 oasc.ZkController.readConfigName Load coll= ection config from:/collections/unloadcollection [junit4:junit4] 2> 17750 T3265 oasc.SolrResourceLoader. new SolrRes= ourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linu= x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkT= est-jetty1-1361394846624/unloadcollection1/' [junit4:junit4] 2> 17802 T3265 oasc.SolrConfig. Using Lucene MatchV= ersion: LUCENE_42 [junit4:junit4] 2> 17832 T3265 oasc.SolrConfig. Loaded SolrConfig: = solrconfig.xml [junit4:junit4] 2> 17833 T3265 oass.IndexSchema.readSchema Reading Solr S= chema [junit4:junit4] 2> 17836 T3265 oass.IndexSchema.readSchema Schema name=3D= test [junit4:junit4] 2> 18081 T3265 oass.OpenExchangeRatesOrgProvider.init Ini= tialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 18084 T3265 oass.IndexSchema.readSchema default search= field in schema is text [junit4:junit4] 2> 18086 T3265 oass.IndexSchema.readSchema unique key fie= ld: id [junit4:junit4] 2> 18101 T3265 oass.FileExchangeRateProvider.reload Reloa= ding exchange rates from file currency.xml [junit4:junit4] 2> 18104 T3265 oass.FileExchangeRateProvider.reload Reloa= ding exchange rates from file currency.xml [junit4:junit4] 2> 18107 T3265 oass.OpenExchangeRatesOrgProvider.reload R= eloading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 18109 T3265 oass.OpenExchangeRatesOrgProvider.reload R= eloading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 18111 T3265 oasc.SolrCore. [unloadcollection1] O= pening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/sol= r/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-j= etty1-1361394846624/unloadcollection1/, dataDir=3D/mnt/ssd/jenkins/workspac= e/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistr= ibutedZkTest-1361394843259/1361394860994unloadcollection1_1n/ [junit4:junit4] 2> 18111 T3265 oasc.JmxMonitoredMap. JMX monitoring= is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxM= BeanServer@66bba6f9 [junit4:junit4] 2> 18111 T3265 oasc.SolrCore.initDirectoryFactory org.apa= che.solr.core.MockDirectoryFactory [junit4:junit4] 2> 18112 T3265 oasc.CachingDirectoryFactory.get return ne= w directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build= /solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361394843259/1361394= 860994unloadcollection1_1n forceNew:false [junit4:junit4] 2> 18112 T3265 oasc.CachingDirectoryFactory.close Releasi= ng directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/so= lr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361394843259/1361394860= 994unloadcollection1_1n [junit4:junit4] 2> 18113 T3265 oasc.SolrCore.getNewIndexDir New index dir= ectory detected: old=3Dnull new=3D/mnt/ssd/jenkins/workspace/Lucene-Solr-4.= x-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-136= 1394843259/1361394860994unloadcollection1_1n/index/ [junit4:junit4] 2> 18113 T3265 oasc.SolrCore.initIndex WARNING [unloadcol= lection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-= Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-13613= 94843259/1361394860994unloadcollection1_1n/index' doesn't exist. Creating n= ew index... [junit4:junit4] 2> 18114 T3265 oasc.CachingDirectoryFactory.get return ne= w directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build= /solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361394843259/1361394= 860994unloadcollection1_1n/index forceNew:false [junit4:junit4] 2> 18115 T3265 oasc.SolrDeletionPolicy.onCommit SolrDelet= ionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@74fdb4dd lockFactory=3Dorg.apache.lucene.store.NativeFSLoc= kFactory@2df2dab2),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_= 1] [junit4:junit4] 2> 18116 T3265 oasc.SolrDeletionPolicy.updateCommits newe= st commit =3D 1[segments_1] [junit4:junit4] 2> 18116 T3265 oasc.CachingDirectoryFactory.close Releasi= ng directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/so= lr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361394843259/1361394860= 994unloadcollection1_1n/index [junit4:junit4] 2> 18118 T3265 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= dedupe" [junit4:junit4] 2> 18118 T3265 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= stored_sig" [junit4:junit4] 2> 18119 T3265 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= distrib-dup-test-chain-implicit" [junit4:junit4] 2> 18119 T3265 oasc.RequestHandlers.initHandlersFromConfi= g created standard: solr.StandardRequestHandler [junit4:junit4] 2> 18120 T3265 oasc.RequestHandlers.initHandlersFromConfi= g created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 18120 T3265 oasc.RequestHandlers.initHandlersFromConfi= g adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 18121 T3265 oasc.RequestHandlers.initHandlersFromConfi= g created /replication: solr.ReplicationHandler [junit4:junit4] 2> 18121 T3265 oasc.RequestHandlers.initHandlersFromConfi= g created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 18122 T3265 oasc.RequestHandlers.initHandlersFromConfi= g created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 18125 T3265 oashl.XMLLoader.init xsltCacheLifetimeSeco= nds=3D60 [junit4:junit4] 2> 18128 T3265 oasc.CachingDirectoryFactory.close Releasi= ng directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/so= lr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361394843259/1361394860= 994unloadcollection1_1n [junit4:junit4] 2> 18128 T3265 oass.SolrIndexSearcher. Opening Sear= cher@1da9e9e3 main [junit4:junit4] 2> 18129 T3265 oasu.UpdateHandler.clearLog Clearing tlog = files, tlogDir=3D/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/buil= d/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361394843259/136139= 4860994unloadcollection1_1n/tlog [junit4:junit4] 2> 18130 T3265 oasu.CommitTracker. Hard AutoCommit:= disabled [junit4:junit4] 2> 18130 T3265 oasu.CommitTracker. Soft AutoCommit:= disabled [junit4:junit4] 2> 18133 T3265 oasc.CachingDirectoryFactory.close Releasi= ng directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/so= lr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361394843259/1361394860= 994unloadcollection1_1n [junit4:junit4] 2> 18134 T3321 oasc.SolrCore.registerSearcher [unloadcoll= ection1] Registered new searcher Searcher@1da9e9e3 main{StandardDirectoryRe= ader(segments_1:1)} [junit4:junit4] 2> 18136 T3265 oasc.ZkController.publish publishing core= =3Dunloadcollection1 state=3Ddown [junit4:junit4] 2> C179_STATE=3Dcoll:collection1 core:collection1 props:= {collection=3Dcollection1, node_name=3D127.0.0.1:46399_, base_url=3Dhttp://= 127.0.0.1:46399, shard=3Dshard2, roles=3Dnull, state=3Drecovering, core=3Dc= ollection1} [junit4:junit4] 2> 18190 T3304 C179 P46399 oasc.RecoveryStrategy.doRecove= ry Attempting to PeerSync from http://127.0.0.1:60465/collection1/ core=3Dc= ollection1 - recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 18190 T3304 C179 P46399 oasu.PeerSync.sync PeerSync: c= ore=3Dcollection1 url=3Dhttp://127.0.0.1:46399 START replicas=3D[http://127= .0.0.1:60465/collection1/] nUpdates=3D100 [junit4:junit4] 2> 18194 T3304 C179 P46399 oasu.PeerSync.sync WARNING no = frame of reference to tell of we've missed updates [junit4:junit4] 2> 18194 T3304 C179 P46399 oasc.RecoveryStrategy.doRecove= ry PeerSync Recovery was not successful - trying replication. core=3Dcollec= tion1 [junit4:junit4] 2> 18194 T3304 C179 P46399 oasc.RecoveryStrategy.doRecove= ry Starting Replication Recovery. core=3Dcollection1 [junit4:junit4] 2> 18195 T3304 C179 P46399 oasc.RecoveryStrategy.doRecove= ry Begin buffering updates. core=3Dcollection1 [junit4:junit4] 2> 18195 T3304 C179 P46399 oasu.UpdateLog.bufferUpdates S= tarting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog=3Dnull} [junit4:junit4] 2> 18195 T3304 C179 P46399 oasc.RecoveryStrategy.replicat= e Attempting to replicate from http://127.0.0.1:60465/collection1/. core=3D= collection1 [junit4:junit4] 2> 18195 T3304 C179 P46399 oascsi.HttpClientUtil.createCl= ient Creating new http client, config:maxConnections=3D128&maxConnectionsPe= rHost=3D32&followRedirects=3Dfalse [junit4:junit4] 2> ASYNC NEW_CORE C181 name=3Dcollection1 org.apache.sol= r.core.SolrCore@582843f1 url=3Dhttp://127.0.0.1:60465/collection1 node=3D12= 7.0.0.1:60465_ C181_STATE=3Dcoll:collection1 core:collection1 props:{collec= tion=3Dcollection1, node_name=3D127.0.0.1:60465_, base_url=3Dhttp://127.0.0= .1:60465, shard=3Dshard2, roles=3Dnull, state=3Dactive, core=3Dcollection1,= leader=3Dtrue} [junit4:junit4] 2> 18198 T3264 C181 P60465 REQ /get {distrib=3Dfalse&getV= ersions=3D100&wt=3Djavabin&qt=3D/get&version=3D2} status=3D0 QTime=3D1=20 [junit4:junit4] 2> 18199 T3266 C181 P60465 oasu.DirectUpdateHandler2.comm= it start commit{,optimize=3Dfalse,openSearcher=3Dfalse,waitSearcher=3Dtrue,= expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 18200 T3266 C181 P60465 oasc.CachingDirectoryFactory.c= lose Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest= -1361394843258/jetty1 [junit4:junit4] 2> 18201 T3266 C181 P60465 oasc.SolrDeletionPolicy.onInit= SolrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@411c6947 lockFactory=3Dorg.apache.lucene.store.NativeFSLoc= kFactory@3583b87b),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_= 1] [junit4:junit4] 2> 18202 T3266 C181 P60465 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 1[segments_1] [junit4:junit4] 2> 18202 T3266 C181 P60465 oasc.SolrDeletionPolicy.onComm= it SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@411c6947 lockFactory=3Dorg.apache.lucene.store.NativeFSLoc= kFactory@3583b87b),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_= 1] [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@411c6947 lockFactory=3Dorg.apache.lucene.store.NativeFSLoc= kFactory@3583b87b),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_= 2] [junit4:junit4] 2> 18203 T3266 C181 P60465 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 2[segments_2] [junit4:junit4] 2> 18203 T3266 C181 P60465 oasc.CachingDirectoryFactory.c= lose Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest= -1361394843258/jetty1 [junit4:junit4] 2> 18203 T3266 C181 P60465 oass.SolrIndexSearcher. = Opening Searcher@760f2074 realtime [junit4:junit4] 2> 18203 T3266 C181 P60465 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 18204 T3266 C181 P60465 /update {commit_end_point=3Dtr= ue&wt=3Djavabin&softCommit=3Dfalse&commit=3Dtrue&version=3D2&openSearcher= =3Dfalse&waitSearcher=3Dtrue} {commit=3D} 0 5 [junit4:junit4] 2> 18204 T3304 C179 P46399 oash.ReplicationHandler.inform= Commits will be reserved for 10000 [junit4:junit4] 2> 18204 T3304 C179 P46399 oash.SnapPuller. No val= ue set for 'pollInterval'. Timer Task not started. [junit4:junit4] 2> 18208 T3264 C181 P60465 oash.ReplicationHandler.inform= Commits will be reserved for 10000 [junit4:junit4] 2> 18208 T3264 C181 P60465 REQ /replication {command=3Din= dexversion&qt=3D/replication&wt=3Djavabin&version=3D2} status=3D0 QTime=3D3= =20 [junit4:junit4] 2> 18212 T3304 C179 P46399 oash.SnapPuller.fetchLatestInd= ex Master's generation: 2 [junit4:junit4] 2> 18212 T3304 C179 P46399 oash.SnapPuller.fetchLatestInd= ex Slave's generation: 1 [junit4:junit4] 2> 18213 T3304 C179 P46399 oash.SnapPuller.fetchLatestInd= ex Starting replication process [junit4:junit4] 2> 18214 T3266 C181 P60465 oasc.CachingDirectoryFactory.c= lose Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest= -1361394843258/jetty1 [junit4:junit4] 2> 18214 T3266 C181 P60465 oasc.CachingDirectoryFactory.c= lose Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest= -1361394843258/jetty1/index [junit4:junit4] 2> 18215 T3266 C181 P60465 REQ /replication {command=3Dfi= lelist&qt=3D/replication&wt=3Djavabin&version=3D2&generation=3D2} status=3D= 0 QTime=3D1=20 [junit4:junit4] 2> 18215 T3304 C179 P46399 oash.SnapPuller.fetchLatestInd= ex Number of files in latest index in master: 1 [junit4:junit4] 2> 18216 T3304 C179 P46399 oasc.CachingDirectoryFactory.g= et return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linu= x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkT= est-1361394843258/jetty3/index.20130220181421470 forceNew:false [junit4:junit4] 2> 18217 T3304 C179 P46399 oasc.CachingDirectoryFactory.c= lose Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest= -1361394843258/jetty3 [junit4:junit4] 2> 18217 T3304 C179 P46399 oash.SnapPuller.fetchLatestInd= ex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory= @63b7ea69 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@1c23598= d) fullCopy=3Dtrue [junit4:junit4] 2> 18219 T3267 C181 P60465 REQ /replication {file=3Dsegme= nts_2&command=3Dfilecontent&wt=3Dfilestream&qt=3D/replication&checksum=3Dtr= ue&generation=3D2} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 18220 T3304 C179 P46399 oasc.CachingDirectoryFactory.c= lose Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest= -1361394843258/jetty3/index [junit4:junit4] 2> 18220 T3304 C179 P46399 oash.SnapPuller.fetchLatestInd= ex Total time taken for download : 0 secs [junit4:junit4] 2> 18220 T3304 C179 P46399 oash.SnapPuller.modifyIndexPro= ps New index installed. Updating index properties... index=3Dindex.20130220= 181421470 [junit4:junit4] 2> 18221 T3304 C179 P46399 oasc.CachingDirectoryFactory.c= lose Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest= -1361394843258/jetty3 [junit4:junit4] 2> 18221 T3304 C179 P46399 oasc.CachingDirectoryFactory.c= lose Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest= -1361394843258/jetty3 [junit4:junit4] 2> 18221 T3304 C179 P46399 oasc.SolrCore.getNewIndexDir N= ew index directory detected: old=3D./org.apache.solr.cloud.UnloadDistribute= dZkTest-1361394843258/jetty3/index/ new=3D./org.apache.solr.cloud.UnloadDis= tributedZkTest-1361394843258/jetty3/index.20130220181421470 [junit4:junit4] 2> 18222 T3304 C179 P46399 oasc.SolrDeletionPolicy.onInit= SolrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@63b7ea69 lockFactory=3Dorg.apache.lucene.store.NativeFSLoc= kFactory@1c23598d),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_= 2] [junit4:junit4] 2> 18223 T3304 C179 P46399 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 2[segments_2] [junit4:junit4] 2> 18223 T3304 C179 P46399 oasc.CachingDirectoryFactory.c= lose Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest= -1361394843258/jetty3 [junit4:junit4] 2> 18223 T3304 C179 P46399 oasu.DefaultSolrCoreState.newI= ndexWriter Creating new IndexWriter... [junit4:junit4] 2> 18223 T3304 C179 P46399 oasu.DefaultSolrCoreState.newI= ndexWriter Waiting until IndexWriter is unused... core=3Dcollection1 [junit4:junit4] 2> 18224 T3304 C179 P46399 oasu.DefaultSolrCoreState.newI= ndexWriter Rollback old IndexWriter... core=3Dcollection1 [junit4:junit4] 2> 18224 T3304 C179 P46399 oasc.CachingDirectoryFactory.c= lose Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest= -1361394843258/jetty3/index.20130220181421470 [junit4:junit4] 2> 18224 T3304 C179 P46399 oasc.CachingDirectoryFactory.c= lose Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest= -1361394843258/jetty3 [junit4:junit4] 2> 18224 T3304 C179 P46399 oasc.SolrDeletionPolicy.onInit= SolrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@63b7ea69 lockFactory=3Dorg.apache.lucene.store.NativeFSLoc= kFactory@1c23598d),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_= 2] [junit4:junit4] 2> 18225 T3304 C179 P46399 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 2[segments_2] [junit4:junit4] 2> 18225 T3304 C179 P46399 oasu.DefaultSolrCoreState.newI= ndexWriter New IndexWriter is ready to be used. [junit4:junit4] 2> 18225 T3304 C179 P46399 oasc.CachingDirectoryFactory.c= lose Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest= -1361394843258/jetty3 [junit4:junit4] 2> 18225 T3304 C179 P46399 oass.SolrIndexSearcher. = Opening Searcher@71c7f6c1 main [junit4:junit4] 2> 18226 T3303 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@71c7f6c1 main{StandardDirectoryReader(s= egments_2:1:nrt)} [junit4:junit4] 2> 18226 T3303 oasc.CachingDirectoryFactory.close Releasi= ng directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/so= lr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-13613948432= 58/jetty3/index [junit4:junit4] 2> 18226 T3304 C179 P46399 oasu.DirectUpdateHandler2.comm= it start commit{,optimize=3Dfalse,openSearcher=3Dfalse,waitSearcher=3Dfalse= ,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 18227 T3304 C179 P46399 oasc.SolrDeletionPolicy.onComm= it SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@63b7ea69 lockFactory=3Dorg.apache.lucene.store.NativeFSLoc= kFactory@1c23598d),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_= 2] [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@63b7ea69 lockFactory=3Dorg.apache.lucene.store.NativeFSLoc= kFactory@1c23598d),segFN=3Dsegments_3,generation=3D3,filenames=3D[segments_= 3] [junit4:junit4] 2> 18227 T3304 C179 P46399 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 3[segments_3] [junit4:junit4] 2> 18227 T3304 C179 P46399 oasc.CachingDirectoryFactory.c= lose Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest= -1361394843258/jetty3 [junit4:junit4] 2> 18227 T3304 C179 P46399 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 18227 T3304 C179 P46399 oasc.CachingDirectoryFactory.c= lose Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest= -1361394843258/jetty3/index.20130220181421470 [junit4:junit4] 2> 18227 T3304 C179 P46399 oasc.CachingDirectoryFactory.c= lose Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest= -1361394843258/jetty3/index [junit4:junit4] 2> 18227 T3304 C179 P46399 oasc.RecoveryStrategy.replay N= o replay needed. core=3Dcollection1 [junit4:junit4] 2> 18227 T3304 C179 P46399 oasc.RecoveryStrategy.doRecove= ry Replication Recovery was successful - registering as Active. core=3Dcoll= ection1 [junit4:junit4] 2> 18228 T3304 C179 P46399 oasc.ZkController.publish publ= ishing core=3Dcollection1 state=3Dactive [junit4:junit4] 2> 18228 T3304 C179 P46399 oasc.ZkController.publish numS= hards not found on descriptor - reading it from system property [junit4:junit4] 2> 18228 T3304 C179 P46399 oasc.RecoveryStrategy.doRecove= ry Finished recovery process. core=3Dcollection1 [junit4:junit4] 2> 18511 T3253 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 18512 T3253 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D2 message=3D{ [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:51909_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:51909", [junit4:junit4] 2> =09 "shard":"shard1", [junit4:junit4] 2> =09 "numShards":"2", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"recovering", [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "core":"collection1"} [junit4:junit4] 2> 18515 T3253 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "collection":"unloadcollection", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:60465_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:60465", [junit4:junit4] 2> =09 "shard":null, [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"down", [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "core":"unloadcollection1"} [junit4:junit4] 2> 18516 T3253 oasc.Overseer$ClusterStateUpdater.createCo= llection Create collection unloadcollection with numShards 1 [junit4:junit4] 2> 18516 T3253 oasc.Overseer$ClusterStateUpdater.updateSt= ate Assigning new node to shard shard=3Dshard1 [junit4:junit4] 2> 18519 T3253 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D2 message=3D{ [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:46399_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:46399", [junit4:junit4] 2> =09 "shard":"shard2", [junit4:junit4] 2> =09 "numShards":"2", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"active", [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "core":"collection1"} [junit4:junit4] 2> 18522 T3271 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 18522 T3252 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 18523 T3258 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 18522 T3317 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 18522 T3301 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 18522 T3286 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 19138 T3265 oasc.CoreContainer.registerCore registerin= g core: unloadcollection1 [junit4:junit4] 2> 19138 T3265 oasc.ZkController.register Register replic= a - core:unloadcollection1 address:http://127.0.0.1:60465 collection:unload= collection shard:shard1 [junit4:junit4] 2> 19139 T3265 oascc.SolrZkClient.makePath makePath: /col= lections/unloadcollection/leader_elect/shard1/election [junit4:junit4] 2> 19145 T3235 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13cf974be7e0006 type:de= lete cxid:0xa4 zxid:0xc2 txntype:-1 reqpath:n/a Error Path:/solr/collection= s/unloadcollection/leaders Error:KeeperErrorCode =3D NoNode for /solr/colle= ctions/unloadcollection/leaders [junit4:junit4] 2> 19146 T3265 oasc.ShardLeaderElectionContext.runLeaderP= rocess Running the leader process. [junit4:junit4] 2> 19147 T3235 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13cf974be7e0006 type:cr= eate cxid:0xa5 zxid:0xc3 txntype:-1 reqpath:n/a Error Path:/solr/overseer E= rror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 19148 T3265 oasc.ShardLeaderElectionContext.waitForRep= licasToComeUp Enough replicas found to continue. [junit4:junit4] 2> 19149 T3265 oasc.ShardLeaderElectionContext.runLeaderP= rocess I may be the new leader - try and sync [junit4:junit4] 2> 19149 T3265 oasc.SyncStrategy.sync Sync replicas to ht= tp://127.0.0.1:60465/unloadcollection1/ [junit4:junit4] 2> 19149 T3265 oasc.SyncStrategy.syncReplicas Sync Succes= s - now sync replicas to me [junit4:junit4] 2> 19150 T3265 oasc.SyncStrategy.syncToMe http://127.0.0.= 1:60465/unloadcollection1/ has no replicas [junit4:junit4] 2> 19150 T3265 oasc.ShardLeaderElectionContext.runLeaderP= rocess I am the new leader: http://127.0.0.1:60465/unloadcollection1/ [junit4:junit4] 2> 19150 T3265 oascc.SolrZkClient.makePath makePath: /col= lections/unloadcollection/leaders/shard1 [junit4:junit4] 2> 19153 T3235 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13cf974be7e0006 type:cr= eate cxid:0xaf zxid:0xc7 txntype:-1 reqpath:n/a Error Path:/solr/overseer E= rror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 20030 T3253 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 20041 T3271 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 20041 T3252 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 20041 T3286 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 20041 T3317 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 20041 T3301 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 20041 T3258 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 20057 T3265 oasc.ZkController.register We are http://1= 27.0.0.1:60465/unloadcollection1/ and leader is http://127.0.0.1:60465/unlo= adcollection1/ [junit4:junit4] 2> 20057 T3265 oasc.ZkController.register No LogReplay ne= eded for core=3Dunloadcollection1 baseURL=3Dhttp://127.0.0.1:60465 [junit4:junit4] 2> 20057 T3265 oasc.ZkController.checkRecovery I am the l= eader, no recovery necessary [junit4:junit4] 2> 20057 T3265 oasc.ZkController.publish publishing core= =3Dunloadcollection1 state=3Dactive [junit4:junit4] 2> 20059 T3265 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 20059 T3265 oasc.CoreContainer.persistFile Persisting = cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build= /solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1= 361394846624/solr.xml [junit4:junit4] 2> 20066 T3265 oasc.SolrXMLSerializer.persistFile Persist= ing cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/b= uild/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-jett= y1-1361394846624/solr.xml [junit4:junit4] 2> 20068 T3230 oascsi.HttpClientUtil.createClient Creatin= g new http client, config: [junit4:junit4] 2> 20070 T3230 oaz.ZooKeeper. Initiating client con= nection, connectString=3D127.0.0.1:35536/solr sessionTimeout=3D10000 watche= r=3Dorg.apache.solr.common.cloud.ConnectionManager@dfdef7c [junit4:junit4] 2> 20070 T3324 oaz.ClientCnxn$SendThread.logStartConnect = Opening socket connection to server localhost.localdomain/127.0.0.1:35536. = Will not attempt to authenticate using SASL (access denied ("javax.security= .auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 2> 20070 T3230 oascc.ConnectionManager.waitForConnected W= aiting for client to connect to ZooKeeper [junit4:junit4] 2> 20071 T3324 oaz.ClientCnxn$SendThread.primeConnection = Socket connection established to localhost.localdomain/127.0.0.1:35536, ini= tiating session [junit4:junit4] 2> 20071 T3232 oazs.NIOServerCnxnFactory.run Accepted soc= ket connection from /127.0.0.1:51821 [junit4:junit4] 2> 20071 T3232 oazs.ZooKeeperServer.processConnectRequest= Client attempting to establish new session at /127.0.0.1:51821 [junit4:junit4] 2> 20071 T3234 oazs.ZooKeeperServer.finishSessionInit Est= ablished session 0x13cf974be7e000d with negotiated timeout 10000 for client= /127.0.0.1:51821 [junit4:junit4] 2> 20072 T3324 oaz.ClientCnxn$SendThread.onConnected Sess= ion establishment complete on server localhost.localdomain/127.0.0.1:35536,= sessionid =3D 0x13cf974be7e000d, negotiated timeout =3D 10000 [junit4:junit4] 2> 20072 T3325 oascc.ConnectionManager.process Watcher or= g.apache.solr.common.cloud.ConnectionManager@dfdef7c name:ZooKeeperConnecti= on Watcher:127.0.0.1:35536/solr got event WatchedEvent state:SyncConnected = type:None path:null path:null type:None [junit4:junit4] 2> 20072 T3230 oascc.ConnectionManager.waitForConnected C= lient is connected to ZooKeeper [junit4:junit4] 2> 20073 T3230 oascc.ZkStateReader.createClusterStateWatc= hersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 20075 T3230 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 20075 T3230 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&f= ollowRedirects=3Dfalse [junit4:junit4] 2> 20079 T3279 oasc.CoreContainer.create Creating SolrCor= e 'unloadcollection2' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-= Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadD= istributedZkTest-jetty2-1361394851170/unloadcollection2 [junit4:junit4] 2> 20079 T3279 oasc.ZkController.createCollectionZkNode C= heck for collection zkNode:unloadcollection [junit4:junit4] 2> 20080 T3279 oasc.ZkController.createCollectionZkNode C= ollection zkNode exists [junit4:junit4] 2> 20080 T3279 oasc.ZkController.readConfigName Load coll= ection config from:/collections/unloadcollection [junit4:junit4] 2> 20081 T3279 oasc.SolrResourceLoader. new SolrRes= ourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linu= x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkT= est-jetty2-1361394851170/unloadcollection2/' [junit4:junit4] 2> 20104 T3279 oasc.SolrConfig. Using Lucene MatchV= ersion: LUCENE_42 [junit4:junit4] 2> 20136 T3279 oasc.SolrConfig. Loaded SolrConfig: = solrconfig.xml [junit4:junit4] 2> 20137 T3279 oass.IndexSchema.readSchema Reading Solr S= chema [junit4:junit4] 2> 20140 T3279 oass.IndexSchema.readSchema Schema name=3D= test [junit4:junit4] 2> 20400 T3279 oass.OpenExchangeRatesOrgProvider.init Ini= tialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 20404 T3279 oass.IndexSchema.readSchema default search= field in schema is text [junit4:junit4] 2> 20406 T3279 oass.IndexSchema.readSchema unique key fie= ld: id [junit4:junit4] 2> 20415 T3279 oass.FileExchangeRateProvider.reload Reloa= ding exchange rates from file currency.xml [junit4:junit4] 2> 20417 T3279 oass.FileExchangeRateProvider.reload Reloa= ding exchange rates from file currency.xml [junit4:junit4] 2> 20419 T3279 oass.OpenExchangeRatesOrgProvider.reload R= eloading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 20420 T3279 oass.OpenExchangeRatesOrgProvider.reload R= eloading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 20421 T3279 oasc.SolrCore. [unloadcollection2] O= pening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/sol= r/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-j= etty2-1361394851170/unloadcollection2/, dataDir=3D/mnt/ssd/jenkins/workspac= e/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistr= ibutedZkTest-1361394843259/1361394863333unloadcollection1_2n/ [junit4:junit4] 2> 20423 T3279 oasc.JmxMonitoredMap. JMX monitoring= is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxM= BeanServer@66bba6f9 [junit4:junit4] 2> 20423 T3279 oasc.SolrCore.initDirectoryFactory org.apa= che.solr.core.MockDirectoryFactory [junit4:junit4] 2> 20424 T3279 oasc.CachingDirectoryFactory.get return ne= w directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build= /solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361394843259/1361394= 863333unloadcollection1_2n forceNew:false [junit4:junit4] 2> 20424 T3279 oasc.CachingDirectoryFactory.close Releasi= ng directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/so= lr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361394843259/1361394863= 333unloadcollection1_2n [junit4:junit4] 2> 20424 T3279 oasc.SolrCore.getNewIndexDir New index dir= ectory detected: old=3Dnull new=3D/mnt/ssd/jenkins/workspace/Lucene-Solr-4.= x-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-136= 1394843259/1361394863333unloadcollection1_2n/index/ [junit4:junit4] 2> 20424 T3279 oasc.SolrCore.initIndex WARNING [unloadcol= lection2] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-= Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-13613= 94843259/1361394863333unloadcollection1_2n/index' doesn't exist. Creating n= ew index... [junit4:junit4] 2> 20425 T3279 oasc.CachingDirectoryFactory.get return ne= w directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build= /solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361394843259/1361394= 863333unloadcollection1_2n/index forceNew:false [junit4:junit4] 2> 20426 T3279 oasc.SolrDeletionPolicy.onCommit SolrDelet= ionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@70c5f44 lockFactory=3Dorg.apache.lucene.store.NativeFSLock= Factory@54006eda),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1= ] [junit4:junit4] 2> 20426 T3279 oasc.SolrDeletionPolicy.updateCommits newe= st commit =3D 1[segments_1] [junit4:junit4] 2> 20426 T3279 oasc.CachingDirectoryFactory.close Releasi= ng directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/so= lr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361394843259/1361394863= 333unloadcollection1_2n/index [junit4:junit4] 2> 20427 T3279 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= dedupe" [junit4:junit4] 2> 20427 T3279 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= stored_sig" [junit4:junit4] 2> 20428 T3279 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= distrib-dup-test-chain-implicit" [junit4:junit4] 2> 20428 T3279 oasc.RequestHandlers.initHandlersFromConfi= g created standard: solr.StandardRequestHandler [junit4:junit4] 2> 20428 T3279 oasc.RequestHandlers.initHandlersFromConfi= g created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 20429 T3279 oasc.RequestHandlers.initHandlersFromConfi= g adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 20429 T3279 oasc.RequestHandlers.initHandlersFromConfi= g created /replication: solr.ReplicationHandler [junit4:junit4] 2> 20429 T3279 oasc.RequestHandlers.initHandlersFromConfi= g created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 20429 T3279 oasc.RequestHandlers.initHandlersFromConfi= g created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 20432 T3279 oashl.XMLLoader.init xsltCacheLifetimeSeco= nds=3D60 [junit4:junit4] 2> 20435 T3279 oasc.CachingDirectoryFactory.close Releasi= ng directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/so= lr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361394843259/1361394863= 333unloadcollection1_2n [junit4:junit4] 2> 20436 T3279 oass.SolrIndexSearcher. Opening Sear= cher@34a92f73 main [junit4:junit4] 2> 20436 T3279 oasu.UpdateHandler.clearLog Clearing tlog = files, tlogDir=3D/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/buil= d/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361394843259/136139= 4863333unloadcollection1_2n/tlog [junit4:junit4] 2> 20437 T3279 oasu.CommitTracker. Hard AutoCommit:= disabled [junit4:junit4] 2> 20437 T3279 oasu.CommitTracker. Soft AutoCommit:= disabled [junit4:junit4] 2> 20440 T3279 oasc.CachingDirectoryFactory.close Releasi= ng directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/so= lr-core/test/J1/./solrtest-UnloadDistributedZkTest-1361394843259/1361394863= 333unloadcollection1_2n [junit4:junit4] 2> 20440 T3326 oasc.SolrCore.registerSearcher [unloadcoll= ection2] Registered new searcher Searcher@34a92f73 main{StandardDirectoryRe= ader(segments_1:1)} [junit4:junit4] 2> 20441 T3279 oasc.ZkController.publish publishing core= =3Dunloadcollection2 state=3Ddown [junit4:junit4] 2> 20441 T3279 oasc.ZkController.publish numShards not fo= und on descriptor - reading it from system property [junit4:junit4] 2> C180_STATE=3Dcoll:collection1 core:collection1 props:= {collection=3Dcollection1, node_name=3D127.0.0.1:51909_, base_url=3Dhttp://= 127.0.0.1:51909, shard=3Dshard1, roles=3Dnull, state=3Drecovering, core=3Dc= ollection1} [junit4:junit4] 2> 20734 T3320 C180 P51909 oasc.RecoveryStrategy.doRecove= ry Attempting to PeerSync from http://127.0.0.1:60062/collection1/ core=3Dc= ollection1 - recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 20735 T3320 C180 P51909 oasu.PeerSync.sync PeerSync: c= ore=3Dcollection1 url=3Dhttp://127.0.0.1:51909 START replicas=3D[http://127= .0.0.1:60062/collection1/] nUpdates=3D100 [junit4:junit4] 2> 20735 T3320 C180 P51909 oasu.PeerSync.sync WARNING no = frame of reference to tell of we've missed updates [junit4:junit4] 2> 20735 T3320 C180 P51909 oasc.RecoveryStrategy.doRecove= ry PeerSync Recovery was not successful - trying replication. core=3Dcollec= tion1 [junit4:junit4] 2> 20735 T3320 C180 P51909 oasc.RecoveryStrategy.doRecove= ry Starting Replication Recovery. core=3Dcollection1 [junit4:junit4] 2> 20736 T3320 C180 P51909 oasc.RecoveryStrategy.doRecove= ry Begin buffering updates. core=3Dcollection1 [junit4:junit4] 2> 20736 T3320 C180 P51909 oasu.UpdateLog.bufferUpdates S= tarting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog=3Dnull} [junit4:junit4] 2> 20736 T3320 C180 P51909 oasc.RecoveryStrategy.replicat= e Attempting to replicate from http://127.0.0.1:60062/collection1/. core=3D= collection1 [junit4:junit4] 2> 20736 T3320 C180 P51909 oascsi.HttpClientUtil.createCl= ient Creating new http client, config:maxConnections=3D128&maxConnectionsPe= rHost=3D32&followRedirects=3Dfalse [junit4:junit4] 2> ASYNC NEW_CORE C182 name=3Dcollection1 org.apache.sol= r.core.SolrCore@252d3f49 url=3Dhttp://127.0.0.1:60062/collection1 node=3D12= 7.0.0.1:60062_ C182_STATE=3Dcoll:collection1 core:collection1 props:{collec= tion=3Dcollection1, node_name=3D127.0.0.1:60062_, base_url=3Dhttp://127.0.0= .1:60062, shard=3Dshard1, roles=3Dnull, state=3Dactive, core=3Dcollection1,= leader=3Dtrue} [junit4:junit4] 2> 20741 T3281 C182 P60062 REQ /get {distrib=3Dfalse&getV= ersions=3D100&wt=3Djavabin&qt=3D/get&version=3D2} status=3D0 QTime=3D1=20 [junit4:junit4] 2> 20742 T3282 C182 P60062 oasu.DirectUpdateHandler2.comm= it start commit{,optimize=3Dfalse,openSearcher=3Dfalse,waitSearcher=3Dtrue,= expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 20742 T3282 C182 P60062 oasc.CachingDirectoryFactory.c= lose Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest= -1361394843258/jetty2 [junit4:junit4] 2> 20743 T3282 C182 P60062 oasc.SolrDeletionPolicy.onInit= SolrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@13177e8a lockFactory=3Dorg.apache.lucene.store.NativeFSLoc= kFactory@35a847cd),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_= 1] [junit4:junit4] 2> 20744 T3282 C182 P60062 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 1[segments_1] [junit4:junit4] 2> 20744 T3282 C182 P60062 oasc.SolrDeletionPolicy.onComm= it SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@13177e8a lockFactory=3Dorg.apache.lucene.store.NativeFSLoc= kFactory@35a847cd),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_= 1] [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@13177e8a lockFactory=3Dorg.apache.lucene.store.NativeFSLoc= kFactory@35a847cd),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_= 2] [junit4:junit4] 2> 20744 T3282 C182 P60062 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 2[segments_2] [junit4:junit4] 2> 20745 T3282 C182 P60062 oasc.CachingDirectoryFactory.c= lose Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest= -1361394843258/jetty2 [junit4:junit4] 2> 20745 T3282 C182 P60062 oass.SolrIndexSearcher. = Opening Searcher@3a3a40d8 realtime [junit4:junit4] 2> 20745 T3282 C182 P60062 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 20745 T3282 C182 P60062 /update {commit_end_point=3Dtr= ue&wt=3Djavabin&softCommit=3Dfalse&commit=3Dtrue&version=3D2&openSearcher= =3Dfalse&waitSearcher=3Dtrue} {commit=3D} 0 4 [junit4:junit4] 2> 20746 T3320 C180 P51909 oash.ReplicationHandler.inform= Commits will be reserved for 10000 [junit4:junit4] 2> 20746 T3320 C180 P51909 oash.SnapPuller. No val= ue set for 'pollInterval'. Timer Task not started. [junit4:junit4] 2> 20747 T3280 C182 P60062 oash.ReplicationHandler.inform= Commits will be reserved for 10000 [junit4:junit4] 2> 20748 T3280 C182 P60062 REQ /replication {command=3Din= dexversion&qt=3D/replication&wt=3Djavabin&version=3D2} status=3D0 QTime=3D1= =20 [junit4:junit4] 2> 20748 T3320 C180 P51909 oash.SnapPuller.fetchLatestInd= ex Master's generation: 2 [junit4:junit4] 2> 20748 T3320 C180 P51909 oash.SnapPuller.fetchLatestInd= ex Slave's generation: 1 [junit4:junit4] 2> 20749 T3320 C180 P51909 oash.SnapPuller.fetchLatestInd= ex Starting replication process [junit4:junit4] 2> 20750 T3282 C182 P60062 oasc.CachingDirectoryFactory.c= lose Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest= -1361394843258/jetty2 [junit4:junit4] 2> 20750 T3282 C182 P60062 oasc.CachingDirectoryFactory.c= lose Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest= -1361394843258/jetty2/index [junit4:junit4] 2> 20751 T3282 C182 P60062 REQ /replication {command=3Dfi= lelist&qt=3D/replication&wt=3Djavabin&version=3D2&generation=3D2} status=3D= 0 QTime=3D1=20 [junit4:junit4] 2> 20751 T3320 C180 P51909 oash.SnapPuller.fetchLatestInd= ex Number of files in latest index in master: 1 [junit4:junit4] 2> 20752 T3320 C180 P51909 oasc.CachingDirectoryFactory.g= et return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linu= x/solr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkT= est-1361394843258/jetty4/index.20130220181424006 forceNew:false [junit4:junit4] 2> 20752 T3320 C180 P51909 oasc.CachingDirectoryFactory.c= lose Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest= -1361394843258/jetty4 [junit4:junit4] 2> 20753 T3320 C180 P51909 oash.SnapPuller.fetchLatestInd= ex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory= @29fb5480 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@1f453a9= 6) fullCopy=3Dtrue [junit4:junit4] 2> 20755 T3281 C182 P60062 REQ /replication {file=3Dsegme= nts_2&command=3Dfilecontent&wt=3Dfilestream&qt=3D/replication&checksum=3Dtr= ue&generation=3D2} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 20756 T3320 C180 P51909 oasc.CachingDirectoryFactory.c= lose Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest= -1361394843258/jetty4/index [junit4:junit4] 2> 20756 T3320 C180 P51909 oash.SnapPuller.fetchLatestInd= ex Total time taken for download : 0 secs [junit4:junit4] 2> 20757 T3320 C180 P51909 oash.SnapPuller.modifyIndexPro= ps New index installed. Updating index properties... index=3Dindex.20130220= 181424006 [junit4:junit4] 2> 20757 T3320 C180 P51909 oasc.CachingDirectoryFactory.c= lose Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest= -1361394843258/jetty4 [junit4:junit4] 2> 20758 T3320 C180 P51909 oasc.CachingDirectoryFactory.c= lose Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest= -1361394843258/jetty4 [junit4:junit4] 2> 20758 T3320 C180 P51909 oasc.SolrCore.getNewIndexDir N= ew index directory detected: old=3D./org.apache.solr.cloud.UnloadDistribute= dZkTest-1361394843258/jetty4/index/ new=3D./org.apache.solr.cloud.UnloadDis= tributedZkTest-1361394843258/jetty4/index.20130220181424006 [junit4:junit4] 2> 20758 T3320 C180 P51909 oasc.SolrDeletionPolicy.onInit= SolrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@29fb5480 lockFactory=3Dorg.apache.lucene.store.NativeFSLoc= kFactory@1f453a96),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_= 2] [junit4:junit4] 2> 20759 T3320 C180 P51909 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 2[segments_2] [junit4:junit4] 2> 20759 T3320 C180 P51909 oasc.CachingDirectoryFactory.c= lose Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest= -1361394843258/jetty4 [junit4:junit4] 2> 20759 T3320 C180 P51909 oasu.DefaultSolrCoreState.newI= ndexWriter Creating new IndexWriter... [junit4:junit4] 2> 20759 T3320 C180 P51909 oasu.DefaultSolrCoreState.newI= ndexWriter Waiting until IndexWriter is unused... core=3Dcollection1 [junit4:junit4] 2> 20759 T3320 C180 P51909 oasu.DefaultSolrCoreState.newI= ndexWriter Rollback old IndexWriter... core=3Dcollection1 [junit4:junit4] 2> 20760 T3320 C180 P51909 oasc.CachingDirectoryFactory.c= lose Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest= -1361394843258/jetty4/index.20130220181424006 [junit4:junit4] 2> 20760 T3320 C180 P51909 oasc.CachingDirectoryFactory.c= lose Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest= -1361394843258/jetty4 [junit4:junit4] 2> 20760 T3320 C180 P51909 oasc.SolrDeletionPolicy.onInit= SolrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@29fb5480 lockFactory=3Dorg.apache.lucene.store.NativeFSLoc= kFactory@1f453a96),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_= 2] [junit4:junit4] 2> 20761 T3320 C180 P51909 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 2[segments_2] [junit4:junit4] 2> 20761 T3320 C180 P51909 oasu.DefaultSolrCoreState.newI= ndexWriter New IndexWriter is ready to be used. [junit4:junit4] 2> 20761 T3320 C180 P51909 oasc.CachingDirectoryFactory.c= lose Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest= -1361394843258/jetty4 [junit4:junit4] 2> 20761 T3320 C180 P51909 oass.SolrIndexSearcher. = Opening Searcher@34305dce main [junit4:junit4] 2> 20762 T3319 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@34305dce main{StandardDirectoryReader(s= egments_2:1:nrt)} [junit4:junit4] 2> 20762 T3319 oasc.CachingDirectoryFactory.close Releasi= ng directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/so= lr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest-13613948432= 58/jetty4/index [junit4:junit4] 2> 20762 T3320 C180 P51909 oasu.DirectUpdateHandler2.comm= it start commit{,optimize=3Dfalse,openSearcher=3Dfalse,waitSearcher=3Dfalse= ,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 20762 T3320 C180 P51909 oasc.SolrDeletionPolicy.onComm= it SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@29fb5480 lockFactory=3Dorg.apache.lucene.store.NativeFSLoc= kFactory@1f453a96),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_= 2] [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@29fb5480 lockFactory=3Dorg.apache.lucene.store.NativeFSLoc= kFactory@1f453a96),segFN=3Dsegments_3,generation=3D3,filenames=3D[segments_= 3] [junit4:junit4] 2> 20762 T3320 C180 P51909 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 3[segments_3] [junit4:junit4] 2> 20763 T3320 C180 P51909 oasc.CachingDirectoryFactory.c= lose Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest= -1361394843258/jetty4 [junit4:junit4] 2> 20763 T3320 C180 P51909 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 20763 T3320 C180 P51909 oasc.CachingDirectoryFactory.c= lose Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest= -1361394843258/jetty4/index.20130220181424006 [junit4:junit4] 2> 20763 T3320 C180 P51909 oasc.CachingDirectoryFactory.c= lose Releasing directory:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.UnloadDistributedZkTest= -1361394843258/jetty4/index [junit4:junit4] 2> 20763 T3320 C180 P51909 oasc.RecoveryStrategy.replay N= o replay needed. core=3Dcollection1 [junit4:junit4] 2> 20763 T3320 C180 P51909 oasc.RecoveryStrategy.doRecove= ry Replication Recovery was successful - registering as Active. core=3Dcoll= ection1 [junit4:junit4] 2> 20763 T3320 C180 P51909 oasc.ZkController.publish publ= ishing core=3Dcollection1 state=3Dactive [junit4:junit4] 2> 20763 T3320 C180 P51909 oasc.ZkController.publish numS= hards not found on descriptor - reading it from system property [junit4:junit4] 2> 20764 T3320 C180 P51909 oasc.RecoveryStrategy.doRecove= ry Finished recovery process. core=3Dcollection1 [junit4:junit4] 2> 21547 T3253 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 21548 T3253 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "collection":"unloadcollection", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:60465_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:60465", [junit4:junit4] 2> =09 "shard":"shard1", [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"active", [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "core":"unloadcollection1"} [junit4:junit4] 2> 21551 T3253 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D2 message=3D{ [junit4:junit4] 2> =09 "collection":"unloadcollection", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:60062_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:60062", [junit4:junit4] 2> =09 "shard":null, [junit4:junit4] 2> =09 "numShards":"2", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"down", [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "core":"unloadcollection2"} [junit4:junit4] 2> 21551 T3253 oasc.Overseer$ClusterStateUpdater.updateSt= ate Collection already exists with numShards=3D1 [junit4:junit4] 2> 21551 T3253 oasc.Overseer$ClusterStateUpdater.updateSt= ate Assigning new node to shard shard=3Dshard1 [junit4:junit4] 2> 21554 T3253 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D2 message=3D{ [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:51909_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:51909", [junit4:junit4] 2> =09 "shard":"shard1", [junit4:junit4] 2> =09 "numShards":"2", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"active", [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "core":"collection1"} [junit4:junit4] 2> 21558 T3258 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 21558 T3317 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 21558 T3271 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 21558 T3252 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 21558 T3301 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 21558 T3286 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 21558 T3325 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 22443 T3279 oasc.CoreContainer.registerCore registerin= g core: unloadcollection2 [junit4:junit4] 2> 22444 T3279 oasc.ZkController.register Register replic= a - core:unloadcollection2 address:http://127.0.0.1:60062 collection:unload= collection shard:shard1 [junit4:junit4] 2> 22446 T3279 oasc.ZkController.register We are http://1= 27.0.0.1:60062/unloadcollection2/ and leader is http://127.0.0.1:60465/unlo= adcollection1/ [junit4:junit4] 2> 22447 T3279 oasc.ZkController.register No LogReplay ne= eded for core=3Dunloadcollection2 baseURL=3Dhttp://127.0.0.1:60062 [junit4:junit4] 2> 22447 T3279 oasc.ZkController.checkRecovery Core needs= to recover:unloadcollection2 [junit4:junit4] 2> 22447 T3279 oasu.DefaultSolrCoreState.doRecovery Runni= ng recovery - first canceling any ongoing recovery [junit4:junit4] 2> ASYNC NEW_CORE C183 name=3Dunloadcollection2 org.apac= he.solr.core.SolrCore@19c352f8 url=3Dhttp://127.0.0.1:60062/unloadcollectio= n2 node=3D127.0.0.1:60062_ C183_STATE=3Dcoll:unloadcollection core:unloadco= llection2 props:{collection=3Dunloadcollection, node_name=3D127.0.0.1:60062= _, base_url=3Dhttp://127.0.0.1:60062, shard=3Dnull, roles=3Dnull, state=3Dd= own, core=3Dunloadcollection2} [junit4:junit4] 2> 22448 T3329 C183 P60062 oasc.RecoveryStrategy.run Star= ting recovery process. core=3Dunloadcollection2 recoveringAfterStartup=3Dt= rue [junit4:junit4] 2> 22448 T3329 C183 P60062 oasc.RecoveryStrategy.doRecove= ry ###### startupVersions=3D[] [junit4:junit4] 2> 22448 T3329 C183 P60062 oasc.ZkController.publish publ= ishing core=3Dunloadcollection2 state=3Dreco [...truncated too long message...] ZkTest.doTest(UnloadDistributedZkTest.java:73) [junit4:junit4] > =09at org.apache.solr.BaseDistributedSearchTestCase.te= stDistribSearch(BaseDistributedSearchTestCase.java:794) [junit4:junit4] > =09at sun.reflect.NativeMethodAccessorImpl.invoke0(Nat= ive Method) [junit4:junit4] > =09at sun.reflect.NativeMethodAccessorImpl.invoke(Nati= veMethodAccessorImpl.java:57) [junit4:junit4] > =09at sun.reflect.DelegatingMethodAccessorImpl.invoke(= DelegatingMethodAccessorImpl.java:43) [junit4:junit4] > =09at java.lang.reflect.Method.invoke(Method.java:474) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.RandomizedRun= ner.invoke(RandomizedRunner.java:1559) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.RandomizedRun= ner.access$600(RandomizedRunner.java:79) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.RandomizedRun= ner$6.evaluate(RandomizedRunner.java:737) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.RandomizedRun= ner$7.evaluate(RandomizedRunner.java:773) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.RandomizedRun= ner$8.evaluate(RandomizedRunner.java:787) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.rules.SystemP= ropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53) [junit4:junit4] > =09at org.apache.lucene.util.TestRuleSetupTeardownChai= ned$1.evaluate(TestRuleSetupTeardownChained.java:50) [junit4:junit4] > =09at org.apache.lucene.util.TestRuleFieldCacheSanity$= 1.evaluate(TestRuleFieldCacheSanity.java:51) [junit4:junit4] > =09at org.apache.lucene.util.AbstractBeforeAfterRule$1= .evaluate(AbstractBeforeAfterRule.java:46) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.rules.SystemP= ropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55) [junit4:junit4] > =09at org.apache.lucene.util.TestRuleThreadAndTestName= $1.evaluate(TestRuleThreadAndTestName.java:49) [junit4:junit4] > =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFai= lures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70) [junit4:junit4] > =09at org.apache.lucene.util.TestRuleMarkFailure$1.eva= luate(TestRuleMarkFailure.java:48) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.rules.Stateme= ntAdapter.evaluate(StatementAdapter.java:36) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.ThreadLeakCon= trol$StatementRunner.run(ThreadLeakControl.java:358) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.ThreadLeakCon= trol.forkTimeoutingTask(ThreadLeakControl.java:782) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.ThreadLeakCon= trol$3.evaluate(ThreadLeakControl.java:442) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.RandomizedRun= ner.runSingleTest(RandomizedRunner.java:746) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.RandomizedRun= ner$3.evaluate(RandomizedRunner.java:648) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.RandomizedRun= ner$4.evaluate(RandomizedRunner.java:682) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.RandomizedRun= ner$5.evaluate(RandomizedRunner.java:693) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.rules.Stateme= ntAdapter.evaluate(StatementAdapter.java:36) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.rules.SystemP= ropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53) [junit4:junit4] > =09at org.apache.lucene.util.AbstractBeforeAfterRule$1= .evaluate(AbstractBeforeAfterRule.java:46) [junit4:junit4] > =09at org.apache.lucene.util.TestRuleStoreClassName$1.= evaluate(TestRuleStoreClassName.java:42) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.rules.SystemP= ropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.rules.NoShado= wingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule= .java:39) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.rules.NoShado= wingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule= .java:39) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.rules.Stateme= ntAdapter.evaluate(StatementAdapter.java:36) [junit4:junit4] > =09at org.apache.lucene.util.TestRuleAssertionsRequire= d$1.evaluate(TestRuleAssertionsRequired.java:43) [junit4:junit4] > =09at org.apache.lucene.util.TestRuleMarkFailure$1.eva= luate(TestRuleMarkFailure.java:48) [junit4:junit4] > =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFai= lures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70) [junit4:junit4] > =09at org.apache.lucene.util.TestRuleIgnoreTestSuites$= 1.evaluate(TestRuleIgnoreTestSuites.java:55) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.rules.Stateme= ntAdapter.evaluate(StatementAdapter.java:36) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.ThreadLeakCon= trol$StatementRunner.run(ThreadLeakControl.java:358) [junit4:junit4] > =09at java.lang.Thread.run(Thread.java:722) [junit4:junit4] 2> 136254 T3230 oas.SolrTestCaseJ4.deleteCore ###deleteCo= re [junit4:junit4] 2> 136264 T3229 ccr.ThreadLeakControl.checkThreadLeaks WA= RNING Will linger awaiting termination of 3 leaked thread(s). [junit4:junit4] 2> 136745 T3233 oazs.SessionTrackerImpl.run SessionTracke= rImpl exited loop! [junit4:junit4] 2> 137322 T3317 oascc.ZkStateReader$3.process WARNING Zoo= Keeper watch triggered, but Solr cannot talk to ZK [junit4:junit4] 2> 137323 T3317 oascc.ZkStateReader$2.process A cluster s= tate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path= :/live_nodes, has occurred - updating... (live nodes size: 1) [junit4:junit4] 2> 137323 T3317 oascc.ZkStateReader$2.process WARNING Zoo= Keeper watch triggered, but Solr cannot talk to ZK [junit4:junit4] 2> 137323 T3317 oaz.ClientCnxn$EventThread.run EventThrea= d shut down [junit4:junit4] 2> NOTE: test params are: codec=3DAppending, sim=3DRandom= SimilarityProvider(queryNorm=3Dtrue,coord=3Dyes): {}, locale=3Den_AU, timez= one=3DEtc/GMT+3 [junit4:junit4] 2> NOTE: Linux 3.2.0-38-generic amd64/Oracle Corporation = 1.8.0-ea (64-bit)/cpus=3D8,threads=3D1,free=3D373608048,total=3D518979584 [junit4:junit4] 2> NOTE: All tests run in this JVM: [TestReload, DirectUp= dateHandlerTest, SynonymTokenizerTest, RecoveryZkTest, OutputWriterTest, Ba= dIndexSchemaTest, BasicFunctionalityTest, IndexSchemaTest, OverseerCollecti= onProcessorTest, FileUtilsTest, TestDocSet, ZkNodePropsTest, PolyFieldTest,= PrimUtilsTest, CoreContainerCoreInitFailuresTest, TestReplicationHandler, = TestCSVLoader, TestCollationKeyRangeQueries, PeerSyncTest, QueryParsingTest= , HighlighterTest, TestDistributedSearch, TestRemoteStreaming, ConvertedLeg= acyTest, StandardRequestHandlerTest, TestAtomicUpdateErrorCases, DOMUtilTes= t, DocumentBuilderTest, PingRequestHandlerTest, TestFunctionQuery, SyncSlic= eTest, TestQueryUtils, TestFastOutputStream, DisMaxRequestHandlerTest, Time= ZoneUtilsTest, SoftAutoCommitTest, TestSolrDeletionPolicy1, DirectSolrSpell= CheckerTest, TestStressRecovery, TestSort, SliceStateUpdateTest, SpellingQu= eryConverterTest, ZkSolrClientTest, LeaderElectionTest, EchoParamsTest, Fie= ldMutatingUpdateProcessorTest, TestOmitPositions, PrimitiveFieldTypeTest, T= estPluginEnable, TestReversedWildcardFilterFactory, TestTrie, BasicZkTest, = SignatureUpdateProcessorFactoryTest, TestJmxIntegration, StatelessScriptUpd= ateProcessorFactoryTest, TestBM25SimilarityFactory, RequiredFieldsTest, Ove= rseerTest, TestSolrDeletionPolicy2, ClusterStateUpdateTest, UpdateParamsTes= t, DocumentAnalysisRequestHandlerTest, FullSolrCloudDistribCmdsTest, Leader= ElectionIntegrationTest, DistributedSpellCheckComponentTest, TestRealTimeGe= t, TestDistributedGrouping, TestRandomFaceting, TestHashPartitioner, Distri= butedTermsComponentTest, StatsComponentTest, SolrCoreTest, IndexBasedSpellC= heckerTest, TestRangeQuery, SimpleFacetsTest, LukeRequestHandlerTest, TestF= iltering, TestPseudoReturnFields, TermsComponentTest, SolrInfoMBeanTest, Xs= ltUpdateRequestHandlerTest, TestPHPSerializedResponseWriter, FieldAnalysisR= equestHandlerTest, TestSurroundQueryParser, IndexSchemaRuntimeFieldTest, Te= stValueSourceCache, FastVectorHighlighterTest, ReturnFieldsTest, TestArbitr= aryIndexDir, LoggingHandlerTest, SuggesterTest, ShowFileRequestHandlerTest,= SolrCoreCheckLockOnStartupTest, TestWriterPerf, TestBinaryField, SOLR749Te= st, TestMergePolicyConfig, TestQuerySenderListener, SolrIndexConfigTest, Nu= mericFieldsTest, TestSolrCoreProperties, TestPhraseSuggestions, TestPerFiel= dSimilarity, TestDFRSimilarityFactory, TestCodecSupport, TestFastLRUCache, = URLClassifyProcessorTest, TestSystemIdResolver, TestSuggestSpellingConverte= r, RAMDirectoryFactoryTest, ClusterStateTest, ShardRoutingCustomTest, Shard= RoutingTest, SliceStateTest, TestZkChroot, UnloadDistributedZkTest] [junit4:junit4] Completed on J1 in 137.54s, 1 test, 1 failure <<< FAILURES! [...truncated 10 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:447:= The following error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:12= 02: The following error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:86= 5: There were test failures: 255 suites, 1055 tests, 1 failure, 8 ignored (= 3 assumptions) Total time: 37 minutes 50 seconds Build step 'Invoke Ant' marked build as failure Archiving artifacts Recording test results Description set: Java: 64bit/jdk1.8.0-ea-b65 -XX:+UseConcMarkSweepGC Email was triggered for: Failure Sending email for trigger: Failure ------=_Part_12_1981595989.1361394983777 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_12_1981595989.1361394983777--