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 BC533E650 for ; Mon, 17 Dec 2012 22:06:29 +0000 (UTC) Received: (qmail 79788 invoked by uid 500); 17 Dec 2012 22:06:28 -0000 Delivered-To: apmail-lucene-dev-archive@lucene.apache.org Received: (qmail 79696 invoked by uid 500); 17 Dec 2012 22:06:27 -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 79687 invoked by uid 99); 17 Dec 2012 22:06:27 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Mon, 17 Dec 2012 22:06:27 +0000 X-ASF-Spam-Status: No, hits=-2000.0 required=5.0 tests=ALL_TRUSTED,NORMAL_HTTP_TO_IP,WEIRD_PORT X-Spam-Check-By: apache.org Received: from [140.211.11.8] (HELO aegis.apache.org) (140.211.11.8) by apache.org (qpsmtpd/0.29) with ESMTP; Mon, 17 Dec 2012 22:06:19 +0000 Received: from aegis.apache.org (localhost [127.0.0.1]) by aegis.apache.org (Postfix) with ESMTP id E1204C00AE for ; Mon, 17 Dec 2012 22:05:58 +0000 (UTC) Date: Mon, 17 Dec 2012 22:05:37 +0000 (UTC) From: Apache Jenkins Server To: dev@lucene.apache.org Message-ID: <112923672.3769.1355781958905.JavaMail.hudson@aegis> In-Reply-To: <479562769.3564.1355723201210.JavaMail.hudson@aegis> References: <479562769.3564.1355723201210.JavaMail.hudson@aegis> Subject: [JENKINS] Lucene-Solr-Tests-4.x-java7 - Build # 807 - Still Failing MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="----=_Part_3768_823571361.1355781937851" X-Virus-Checked: Checked by ClamAV on apache.org ------=_Part_3768_823571361.1355781937851 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-java7/807/ 1 tests failed. REGRESSION: org.apache.solr.cloud.SyncSliceTest.testDistribSearch Error Message: Stack Trace: java.lang.AssertionError =09at __randomizedtesting.SeedInfo.seed([BF39A2C09A4432F:8A1514347EFB2313]:= 0) =09at org.junit.Assert.fail(Assert.java:92) =09at org.junit.Assert.assertTrue(Assert.java:43) =09at org.junit.Assert.assertNotNull(Assert.java:526) =09at org.junit.Assert.assertNotNull(Assert.java:537) =09at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:211) =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:601) =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 9254 lines...] [junit4:junit4] Suite: org.apache.solr.cloud.SyncSliceTest [junit4:junit4] 2> 0 T2533 oas.BaseDistributedSearchTestCase.initHostCont= ext Setting hostContext system property: /hh_ov/xj [junit4:junit4] 2> 3 T2533 oas.SolrTestCaseJ4.setUp ###Starting testDistr= ibSearch [junit4:junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/worksp= ace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-Syn= cSliceTest-1355781770504 [junit4:junit4] 2> 4 T2533 oasc.ZkTestServer.run STARTING ZK TEST SERVER [junit4:junit4] 2> 5 T2534 oasc.ZkTestServer$ZKServerMain.runFromConfig S= tarting server [junit4:junit4] 2> 7 T2534 oazs.ZooKeeperServer.setTickTime tickTime set = to 1000 [junit4:junit4] 2> 7 T2534 oazs.ZooKeeperServer.setMinSessionTimeout minS= essionTimeout set to -1 [junit4:junit4] 2> 7 T2534 oazs.ZooKeeperServer.setMaxSessionTimeout maxS= essionTimeout set to -1 [junit4:junit4] 2> 8 T2534 oazs.NIOServerCnxnFactory.configure binding to= port 0.0.0.0/0.0.0.0:0 [junit4:junit4] 2> 8 T2534 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to= /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/b= uild/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1355781770504/= zookeeper/server1/data/version-2/snapshot.0 [junit4:junit4] 2> 106 T2533 oasc.ZkTestServer.run start zk server on por= t:32005 [junit4:junit4] 2> 106 T2533 oaz.ZooKeeper. Initiating client conne= ction, connectString=3D127.0.0.1:32005 sessionTimeout=3D10000 watcher=3Dorg= .apache.solr.common.cloud.ConnectionManager@549bd478 [junit4:junit4] 2> 107 T2533 oascc.ConnectionManager.waitForConnected Wai= ting for client to connect to ZooKeeper [junit4:junit4] 2> 107 T2539 oaz.ClientCnxn$SendThread.logStartConnect Op= ening socket connection to server localhost/127.0.0.1:32005. Will not attem= pt to authenticate using SASL (access denied ("javax.security.auth.AuthPerm= ission" "getLoginConfiguration")) [junit4:junit4] 2> 108 T2539 oaz.ClientCnxn$SendThread.primeConnection So= cket connection established to localhost/127.0.0.1:32005, initiating sessio= n [junit4:junit4] 2> 108 T2535 oazs.NIOServerCnxnFactory.run Accepted socke= t connection from /140.211.11.196:32006 [junit4:junit4] 2> 109 T2535 oazs.ZooKeeperServer.processConnectRequest C= lient attempting to establish new session at /140.211.11.196:32006 [junit4:junit4] 2> 109 T2537 oazsp.FileTxnLog.append Creating new log fil= e: log.1 [junit4:junit4] 2> 110 T2537 oazs.ZooKeeperServer.finishSessionInit Estab= lished session 0x13baae40d0d0000 with negotiated timeout 10000 for client /= 140.211.11.196:32006 [junit4:junit4] 2> 111 T2539 oaz.ClientCnxn$SendThread.onConnected Sessio= n establishment complete on server localhost/127.0.0.1:32005, sessionid =3D= 0x13baae40d0d0000, negotiated timeout =3D 10000 [junit4:junit4] 2> 111 T2540 oascc.ConnectionManager.process Watcher org.= apache.solr.common.cloud.ConnectionManager@549bd478 name:ZooKeeperConnectio= n Watcher:127.0.0.1:32005 got event WatchedEvent state:SyncConnected type:N= one path:null path:null type:None [junit4:junit4] 2> 111 T2533 oascc.ConnectionManager.waitForConnected Cli= ent is connected to ZooKeeper [junit4:junit4] 2> 112 T2533 oascc.SolrZkClient.makePath makePath: /solr [junit4:junit4] 2> 114 T2538 oazs.PrepRequestProcessor.pRequest2Txn Proce= ssed session termination for sessionid: 0x13baae40d0d0000 [junit4:junit4] 2> 122 T2540 oaz.ClientCnxn$EventThread.run EventThread s= hut down [junit4:junit4] 2> 122 T2535 oazs.NIOServerCnxn.closeSock Closed socket c= onnection for client /140.211.11.196:32006 which had sessionid 0x13baae40d0= d0000 [junit4:junit4] 2> 122 T2533 oaz.ZooKeeper.close Session: 0x13baae40d0d00= 00 closed [junit4:junit4] 2> 122 T2533 oaz.ZooKeeper. Initiating client conne= ction, connectString=3D127.0.0.1:32005/solr sessionTimeout=3D10000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@59e4a54a [junit4:junit4] 2> 123 T2533 oascc.ConnectionManager.waitForConnected Wai= ting for client to connect to ZooKeeper [junit4:junit4] 2> 123 T2541 oaz.ClientCnxn$SendThread.logStartConnect Op= ening socket connection to server localhost/127.0.0.1:32005. Will not attem= pt to authenticate using SASL (access denied ("javax.security.auth.AuthPerm= ission" "getLoginConfiguration")) [junit4:junit4] 2> 124 T2541 oaz.ClientCnxn$SendThread.primeConnection So= cket connection established to localhost/127.0.0.1:32005, initiating sessio= n [junit4:junit4] 2> 124 T2535 oazs.NIOServerCnxnFactory.run Accepted socke= t connection from /140.211.11.196:32007 [junit4:junit4] 2> 124 T2535 oazs.ZooKeeperServer.processConnectRequest C= lient attempting to establish new session at /140.211.11.196:32007 [junit4:junit4] 2> 125 T2537 oazs.ZooKeeperServer.finishSessionInit Estab= lished session 0x13baae40d0d0001 with negotiated timeout 10000 for client /= 140.211.11.196:32007 [junit4:junit4] 2> 125 T2541 oaz.ClientCnxn$SendThread.onConnected Sessio= n establishment complete on server localhost/127.0.0.1:32005, sessionid =3D= 0x13baae40d0d0001, negotiated timeout =3D 10000 [junit4:junit4] 2> 125 T2542 oascc.ConnectionManager.process Watcher org.= apache.solr.common.cloud.ConnectionManager@59e4a54a name:ZooKeeperConnectio= n Watcher:127.0.0.1:32005/solr got event WatchedEvent state:SyncConnected t= ype:None path:null path:null type:None [junit4:junit4] 2> 126 T2533 oascc.ConnectionManager.waitForConnected Cli= ent is connected to ZooKeeper [junit4:junit4] 2> 126 T2533 oascc.SolrZkClient.makePath makePath: /colle= ctions/collection1 [junit4:junit4] 2> 136 T2533 oascc.SolrZkClient.makePath makePath: /colle= ctions/collection1/shards [junit4:junit4] 2> 138 T2533 oascc.SolrZkClient.makePath makePath: /colle= ctions/control_collection [junit4:junit4] 2> 140 T2533 oascc.SolrZkClient.makePath makePath: /colle= ctions/control_collection/shards [junit4:junit4] 2> 142 T2533 oasc.AbstractZkTestCase.putConfig put /usr/h= ome/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/so= lr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf1/s= olrconfig.xml [junit4:junit4] 2> 143 T2533 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/solrconfig.xml [junit4:junit4] 2> 160 T2533 oasc.AbstractZkTestCase.putConfig put /usr/h= ome/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/so= lr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schem= a.xml [junit4:junit4] 2> 162 T2533 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/schema.xml [junit4:junit4] 2> 266 T2533 oasc.AbstractZkTestCase.putConfig put /usr/h= ome/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/so= lr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/st= opwords.txt [junit4:junit4] 2> 268 T2533 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/stopwords.txt [junit4:junit4] 2> 271 T2533 oasc.AbstractZkTestCase.putConfig put /usr/h= ome/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/so= lr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/pr= otwords.txt [junit4:junit4] 2> 272 T2533 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/protwords.txt [junit4:junit4] 2> 281 T2533 oasc.AbstractZkTestCase.putConfig put /usr/h= ome/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/so= lr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/cur= rency.xml [junit4:junit4] 2> 281 T2533 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/currency.xml [junit4:junit4] 2> 285 T2533 oasc.AbstractZkTestCase.putConfig put /usr/h= ome/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/so= lr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /confi= gs/conf1/open-exchange-rates.json [junit4:junit4] 2> 285 T2533 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/open-exchange-rates.json [junit4:junit4] 2> 295 T2533 oasc.AbstractZkTestCase.putConfig put /usr/h= ome/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/so= lr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /co= nfigs/conf1/mapping-ISOLatin1Accent.txt [junit4:junit4] 2> 296 T2533 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/mapping-ISOLatin1Accent.txt [junit4:junit4] 2> 306 T2533 oasc.AbstractZkTestCase.putConfig put /usr/h= ome/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/so= lr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1= /old_synonyms.txt [junit4:junit4] 2> 307 T2533 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/old_synonyms.txt [junit4:junit4] 2> 311 T2533 oasc.AbstractZkTestCase.putConfig put /usr/h= ome/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/so= lr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/syn= onyms.txt [junit4:junit4] 2> 311 T2533 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/synonyms.txt [junit4:junit4] 2> 315 T2538 oazs.PrepRequestProcessor.pRequest2Txn Proce= ssed session termination for sessionid: 0x13baae40d0d0001 [junit4:junit4] 2> 318 T2542 oaz.ClientCnxn$EventThread.run EventThread s= hut down [junit4:junit4] 2> 318 T2535 oazs.NIOServerCnxn.closeSock Closed socket c= onnection for client /140.211.11.196:32007 which had sessionid 0x13baae40d0= d0001 [junit4:junit4] 2> 318 T2533 oaz.ZooKeeper.close Session: 0x13baae40d0d00= 01 closed [junit4:junit4] 2> 432 T2533 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 437 T2533 oejs.AbstractConnector.doStart Started Socke= tConnector@127.0.0.1:32009 [junit4:junit4] 2> 438 T2533 oasc.SolrResourceLoader.locateSolrHome JNDI = not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 439 T2533 oasc.SolrResourceLoader.locateSolrHome using= system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cl= oud.SyncSliceTest-controljetty-1355781770819 [junit4:junit4] 2> 439 T2533 oasc.SolrResourceLoader. new SolrResou= rceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.c= loud.SyncSliceTest-controljetty-1355781770819/' [junit4:junit4] 2> 468 T2533 oass.SolrDispatchFilter.init SolrDispatchFil= ter.init() [junit4:junit4] 2> 468 T2533 oasc.SolrResourceLoader.locateSolrHome JNDI = not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 469 T2533 oasc.SolrResourceLoader.locateSolrHome using= system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cl= oud.SyncSliceTest-controljetty-1355781770819 [junit4:junit4] 2> 469 T2533 oasc.CoreContainer$Initializer.initialize lo= oking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tes= ts-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSlice= Test-controljetty-1355781770819/solr.xml [junit4:junit4] 2> 470 T2533 oasc.CoreContainer. New CoreContainer = 273795367 [junit4:junit4] 2> 470 T2533 oasc.CoreContainer.load Loading CoreContaine= r using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tes= ts-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSlice= Test-controljetty-1355781770819/' [junit4:junit4] 2> 471 T2533 oasc.SolrResourceLoader. new SolrResou= rceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-So= lr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Syn= cSliceTest-controljetty-1355781770819/' [junit4:junit4] 2> 491 T2533 oashc.HttpShardHandlerFactory.getParameter S= etting socketTimeout to: 30000 [junit4:junit4] 2> 492 T2533 oashc.HttpShardHandlerFactory.getParameter S= etting urlScheme to: http:// [junit4:junit4] 2> 492 T2533 oashc.HttpShardHandlerFactory.getParameter S= etting connTimeout to: 15000 [junit4:junit4] 2> 493 T2533 oashc.HttpShardHandlerFactory.getParameter S= etting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 493 T2533 oashc.HttpShardHandlerFactory.getParameter S= etting corePoolSize to: 0 [junit4:junit4] 2> 493 T2533 oashc.HttpShardHandlerFactory.getParameter S= etting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 494 T2533 oashc.HttpShardHandlerFactory.getParameter S= etting maxThreadIdleTime to: 5 [junit4:junit4] 2> 494 T2533 oashc.HttpShardHandlerFactory.getParameter S= etting sizeOfQueue to: -1 [junit4:junit4] 2> 495 T2533 oashc.HttpShardHandlerFactory.getParameter S= etting fairnessPolicy to: false [junit4:junit4] 2> 495 T2533 oascsi.HttpClientUtil.createClient Creating = new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000&s= ocketTimeout=3D30000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 510 T2533 oasc.CoreContainer.load Registering Log List= ener [junit4:junit4] 2> 525 T2533 oasc.CoreContainer.initZooKeeper Zookeeper c= lient=3D127.0.0.1:32005/solr [junit4:junit4] 2> 526 T2533 oasc.ZkController.checkChrootPath zkHost inc= ludes chroot [junit4:junit4] 2> 526 T2533 oaz.ZooKeeper. Initiating client conne= ction, connectString=3D127.0.0.1:32005 sessionTimeout=3D60000 watcher=3Dorg= .apache.solr.common.cloud.ConnectionManager@5c056be6 [junit4:junit4] 2> 527 T2533 oascc.ConnectionManager.waitForConnected Wai= ting for client to connect to ZooKeeper [junit4:junit4] 2> 527 T2552 oaz.ClientCnxn$SendThread.logStartConnect Op= ening socket connection to server localhost/127.0.0.1:32005. Will not attem= pt to authenticate using SASL (access denied ("javax.security.auth.AuthPerm= ission" "getLoginConfiguration")) [junit4:junit4] 2> 528 T2552 oaz.ClientCnxn$SendThread.primeConnection So= cket connection established to localhost/127.0.0.1:32005, initiating sessio= n [junit4:junit4] 2> 528 T2535 oazs.NIOServerCnxnFactory.run Accepted socke= t connection from /140.211.11.196:32010 [junit4:junit4] 2> 529 T2535 oazs.ZooKeeperServer.processConnectRequest C= lient attempting to establish new session at /140.211.11.196:32010 [junit4:junit4] 2> 574 T2537 oazs.ZooKeeperServer.finishSessionInit Estab= lished session 0x13baae40d0d0002 with negotiated timeout 20000 for client /= 140.211.11.196:32010 [junit4:junit4] 2> 574 T2552 oaz.ClientCnxn$SendThread.onConnected Sessio= n establishment complete on server localhost/127.0.0.1:32005, sessionid =3D= 0x13baae40d0d0002, negotiated timeout =3D 20000 [junit4:junit4] 2> 575 T2553 oascc.ConnectionManager.process Watcher org.= apache.solr.common.cloud.ConnectionManager@5c056be6 name:ZooKeeperConnectio= n Watcher:127.0.0.1:32005 got event WatchedEvent state:SyncConnected type:N= one path:null path:null type:None [junit4:junit4] 2> 575 T2533 oascc.ConnectionManager.waitForConnected Cli= ent is connected to ZooKeeper [junit4:junit4] 2> 576 T2538 oazs.PrepRequestProcessor.pRequest2Txn Proce= ssed session termination for sessionid: 0x13baae40d0d0002 [junit4:junit4] 2> 578 T2553 oaz.ClientCnxn$EventThread.run EventThread s= hut down [junit4:junit4] 2> 578 T2535 oazs.NIOServerCnxn.closeSock Closed socket c= onnection for client /140.211.11.196:32010 which had sessionid 0x13baae40d0= d0002 [junit4:junit4] 2> 578 T2533 oaz.ZooKeeper.close Session: 0x13baae40d0d00= 02 closed [junit4:junit4] 2> 578 T2533 oascsi.HttpClientUtil.createClient Creating = new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&soc= ketTimeout=3D15000&connTimeout=3D30000 [junit4:junit4] 2> 585 T2533 oaz.ZooKeeper. Initiating client conne= ction, connectString=3D127.0.0.1:32005/solr sessionTimeout=3D30000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@22ac0088 [junit4:junit4] 2> 586 T2533 oascc.ConnectionManager.waitForConnected Wai= ting for client to connect to ZooKeeper [junit4:junit4] 2> 586 T2554 oaz.ClientCnxn$SendThread.logStartConnect Op= ening socket connection to server localhost/127.0.0.1:32005. Will not attem= pt to authenticate using SASL (access denied ("javax.security.auth.AuthPerm= ission" "getLoginConfiguration")) [junit4:junit4] 2> 587 T2554 oaz.ClientCnxn$SendThread.primeConnection So= cket connection established to localhost/127.0.0.1:32005, initiating sessio= n [junit4:junit4] 2> 587 T2535 oazs.NIOServerCnxnFactory.run Accepted socke= t connection from /140.211.11.196:32011 [junit4:junit4] 2> 587 T2535 oazs.ZooKeeperServer.processConnectRequest C= lient attempting to establish new session at /140.211.11.196:32011 [junit4:junit4] 2> 602 T2537 oazs.ZooKeeperServer.finishSessionInit Estab= lished session 0x13baae40d0d0003 with negotiated timeout 20000 for client /= 140.211.11.196:32011 [junit4:junit4] 2> 602 T2554 oaz.ClientCnxn$SendThread.onConnected Sessio= n establishment complete on server localhost/127.0.0.1:32005, sessionid =3D= 0x13baae40d0d0003, negotiated timeout =3D 20000 [junit4:junit4] 2> 602 T2555 oascc.ConnectionManager.process Watcher org.= apache.solr.common.cloud.ConnectionManager@22ac0088 name:ZooKeeperConnectio= n Watcher:127.0.0.1:32005/solr got event WatchedEvent state:SyncConnected t= ype:None path:null path:null type:None [junit4:junit4] 2> 603 T2533 oascc.ConnectionManager.waitForConnected Cli= ent is connected to ZooKeeper [junit4:junit4] 2> 639 T2538 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13baae40d0d0003 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> 664 T2533 oascc.SolrZkClient.makePath makePath: /live_= nodes [junit4:junit4] 2> 667 T2533 oasc.ZkController.createEphemeralLiveNode Re= gister node as live in ZooKeeper:/live_nodes/127.0.0.1:32009_hh_ov%2Fxj [junit4:junit4] 2> 667 T2538 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13baae40d0d0003 type:dele= te cxid:0x7 zxid:0x1c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/12= 7.0.0.1:32009_hh_ov%2Fxj Error:KeeperErrorCode =3D NoNode for /solr/live_no= des/127.0.0.1:32009_hh_ov%2Fxj [junit4:junit4] 2> 669 T2533 oascc.SolrZkClient.makePath makePath: /live_= nodes/127.0.0.1:32009_hh_ov%2Fxj [junit4:junit4] 2> 672 T2533 oascc.SolrZkClient.makePath makePath: /overs= eer_elect/election [junit4:junit4] 2> 712 T2538 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13baae40d0d0003 type:dele= te cxid:0x15 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> 713 T2533 oascc.SolrZkClient.makePath makePath: /overs= eer_elect/leader [junit4:junit4] 2> 716 T2533 oasc.Overseer.start Overseer (id=3D888525141= 12077827-127.0.0.1:32009_hh_ov%2Fxj-n_0000000000) starting [junit4:junit4] 2> 716 T2538 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13baae40d0d0003 type:crea= te cxid:0x1a zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 724 T2538 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13baae40d0d0003 type:crea= te cxid:0x1b zxid:0x24 txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 726 T2538 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13baae40d0d0003 type:crea= te cxid:0x1c zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 727 T2538 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13baae40d0d0003 type:crea= te cxid:0x1d zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 743 T2557 oasc.OverseerCollectionProcessor.run Process= current queue of collection messages [junit4:junit4] 2> 744 T2533 oascc.SolrZkClient.makePath makePath: /clust= erstate.json [junit4:junit4] 2> 762 T2533 oascc.ZkStateReader.createClusterStateWatche= rsAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 763 T2556 oasc.Overseer$ClusterStateUpdater.run Starti= ng to work on the main queue [junit4:junit4] 2> 768 T2558 oasc.CoreContainer.create Creating SolrCore = 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cl= oud.SyncSliceTest-controljetty-1355781770819/collection1 [junit4:junit4] 2> 769 T2558 oasc.ZkController.createCollectionZkNode Che= ck for collection zkNode:control_collection [junit4:junit4] 2> 769 T2558 oasc.ZkController.createCollectionZkNode Col= lection zkNode exists [junit4:junit4] 2> 769 T2558 oasc.ZkController.readConfigName Load collec= tion config from:/collections/control_collection [junit4:junit4] 2> 771 T2558 oasc.SolrResourceLoader. new SolrResou= rceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-So= lr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Syn= cSliceTest-controljetty-1355781770819/collection1/' [junit4:junit4] 2> 772 T2558 oasc.SolrResourceLoader.replaceClassLoader A= dding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-j= ava7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-contr= oljetty-1355781770819/collection1/lib/classes/' to classloader [junit4:junit4] 2> 773 T2558 oasc.SolrResourceLoader.replaceClassLoader A= dding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-j= ava7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-contr= oljetty-1355781770819/collection1/lib/README' to classloader [junit4:junit4] 2> 827 T2558 oasc.SolrConfig. Using Lucene MatchVer= sion: LUCENE_41 [junit4:junit4] 2> 902 T2558 oasc.SolrConfig. Loaded SolrConfig: so= lrconfig.xml [junit4:junit4] 2> 1003 T2558 oass.IndexSchema.readSchema Reading Solr Sc= hema [junit4:junit4] 2> 1010 T2558 oass.IndexSchema.readSchema Schema name=3Dt= est [junit4:junit4] 2> 1698 T2558 oass.OpenExchangeRatesOrgProvider.init Init= ialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 1711 T2558 oass.IndexSchema.readSchema default search = field in schema is text [junit4:junit4] 2> 1715 T2558 oass.IndexSchema.readSchema unique key fiel= d: id [junit4:junit4] 2> 1728 T2558 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 1733 T2558 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 1737 T2558 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 1739 T2558 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 1740 T2558 oasc.SolrCore. [collection1] Opening = new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4= .x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest= -controljetty-1355781770819/collection1/, dataDir=3D./org.apache.solr.cloud= .SyncSliceTest-1355781770504/control/data/ [junit4:junit4] 2> 1740 T2558 oasc.JmxMonitoredMap. JMX monitoring = is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMB= eanServer@1afa578a [junit4:junit4] 2> 1741 T2558 oasc.SolrCore.initDirectoryFactory solr.NRT= CachingDirectoryFactory [junit4:junit4] 2> 1742 T2558 oasc.CachingDirectoryFactory.get return new= directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.= x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-= 1355781770504/control/data forceNew:false [junit4:junit4] 2> 1743 T2558 oasc.CachingDirectoryFactory.close Releasin= g directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-j= ava7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-135= 5781770504/control/data [junit4:junit4] 2> 1743 T2558 oasc.SolrCore.getNewIndexDir New index dire= ctory detected: old=3Dnull new=3D./org.apache.solr.cloud.SyncSliceTest-1355= 781770504/control/data/index/ [junit4:junit4] 2> 1744 T2558 oasc.SolrCore.initIndex WARNING [collection= 1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-135578177050= 4/control/data/index' doesn't exist. Creating new index... [junit4:junit4] 2> 1745 T2558 oasc.CachingDirectoryFactory.get return new= directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.= x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-= 1355781770504/control/data/index forceNew:false [junit4:junit4] 2> 1770 T2558 oasc.SolrDeletionPolicy.onCommit SolrDeleti= onPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/o= rg.apache.solr.cloud.SyncSliceTest-1355781770504/control/data/index lockFac= tory=3Dorg.apache.lucene.store.NativeFSLockFactory@331c755c; maxCacheMB=3D4= 8.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_1,generation=3D1,filenames=3D[s= egments_1] [junit4:junit4] 2> 1771 T2558 oasc.SolrDeletionPolicy.updateCommits newes= t commit =3D 1[segments_1] [junit4:junit4] 2> 1772 T2558 oasc.CachingDirectoryFactory.close Releasin= g directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-j= ava7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-135= 5781770504/control/data/index [junit4:junit4] 2> 1772 T2558 oasc.SolrCore.initWriters created xml: solr= .XMLResponseWriter [junit4:junit4] 2> 1774 T2558 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe" [junit4:junit4] 2> 1774 T2558 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe-allfields" [junit4:junit4] 2> 1775 T2558 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "s= tored_sig" [junit4:junit4] 2> 1775 T2558 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "u= niq-fields" [junit4:junit4] 2> 1776 T2558 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= istrib-dup-test-chain-implicit" [junit4:junit4] 2> 1776 T2558 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 1776 T2558 oasc.RequestHandlers.initHandlersFromConfig= created /replication: solr.ReplicationHandler [junit4:junit4] 2> 1777 T2558 oasc.RequestHandlers.initHandlersFromConfig= created standard: solr.StandardRequestHandler [junit4:junit4] 2> 1778 T2558 oasc.RequestHandlers.initHandlersFromConfig= created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 1779 T2558 oasc.RequestHandlers.initHandlersFromConfig= created dismax: solr.SearchHandler [junit4:junit4] 2> 1780 T2558 oasc.RequestHandlers.initHandlersFromConfig= created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler [junit4:junit4] 2> 1780 T2558 oasc.RequestHandlers.initHandlersFromConfig= created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 1781 T2558 oasc.RequestHandlers.initHandlersFromConfig= created defaults: solr.StandardRequestHandler [junit4:junit4] 2> 1782 T2558 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.StandardRequestHandler [junit4:junit4] 2> 1782 T2558 oasc.RequestHandlers.initHandlersFromConfig= created lazy: solr.StandardRequestHandler [junit4:junit4] 2> 1783 T2558 oasc.RequestHandlers.initHandlersFromConfig= created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 1784 T2558 oasc.RequestHandlers.initHandlersFromConfig= created /terms: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 1784 T2558 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 1785 T2558 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchH= andler [junit4:junit4] 2> 1786 T2558 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchH= andler [junit4:junit4] 2> 1787 T2558 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.= SearchHandler [junit4:junit4] 2> 1788 T2558 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 1789 T2558 oasc.RequestHandlers.initHandlersFromConfig= created mltrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 1789 T2558 oasc.RequestHandlers.initHandlersFromConfig= created tvrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 1790 T2558 oasc.RequestHandlers.initHandlersFromConfig= created /mlt: solr.MoreLikeThisHandler [junit4:junit4] 2> 1791 T2558 oasc.RequestHandlers.initHandlersFromConfig= created /debug/dump: solr.DumpRequestHandler [junit4:junit4] 2> 1804 T2558 oashl.XMLLoader.init xsltCacheLifetimeSecon= ds=3D60 [junit4:junit4] 2> 1809 T2558 oasc.SolrCore.initDeprecatedSupport WARNING= solrconfig.xml uses deprecated , Please update your c= onfig to use the ShowFileRequestHandler. [junit4:junit4] 2> 1810 T2558 oasc.SolrCore.initDeprecatedSupport WARNING= adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS= .TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT,= CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT] [junit4:junit4] 2> 1813 T2558 oasc.CachingDirectoryFactory.close Releasin= g directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-j= ava7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-135= 5781770504/control/data [junit4:junit4] 2> 1815 T2558 oass.SolrIndexSearcher. Opening Searc= her@7c87b903 main [junit4:junit4] 2> 1816 T2558 oasu.CommitTracker. Hard AutoCommit: = disabled [junit4:junit4] 2> 1817 T2558 oasu.CommitTracker. Soft AutoCommit: = disabled [junit4:junit4] 2> 1817 T2558 oashc.SpellCheckComponent.inform Initializi= ng spell checkers [junit4:junit4] 2> 1824 T2558 oass.DirectSolrSpellChecker.init init: {nam= e=3Ddirect,classname=3DDirectSolrSpellChecker,field=3Dlowerfilt,minQueryLen= gth=3D3} [junit4:junit4] 2> 1877 T2559 oasc.SolrCore.registerSearcher [collection1= ] Registered new searcher Searcher@7c87b903 main{StandardDirectoryReader(se= gments_1:1)} [junit4:junit4] 2> 1881 T2558 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Ddown [junit4:junit4] 2> 1881 T2558 oasc.ZkController.publish numShards not fou= nd on descriptor - reading it from system property [junit4:junit4] 2> 1882 T2538 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13baae40d0d0003 type:cre= ate cxid:0x56 zxid:0x29 txntype:-1 reqpath:n/a Error Path:/solr/overseer/qu= eue Error:KeeperErrorCode =3D NoNode for /solr/overseer/queue [junit4:junit4] 2> 2271 T2556 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 2272 T2556 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "shard":null, [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"down", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"control_collection", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:32009_hh_ov%2Fxj", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:32009/hh_ov/xj"} [junit4:junit4] 2> 2272 T2556 oasc.Overseer$ClusterStateUpdater.createCol= lection Create collection control_collection with numShards 1 [junit4:junit4] 2> 2272 T2556 oasc.Overseer$ClusterStateUpdater.updateSta= te Assigning new node to shard shard=3Dshard1 [junit4:junit4] 2> 2273 T2538 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13baae40d0d0003 type:cre= ate cxid:0x5e 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> 2287 T2555 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> 2395 T2558 oasc.CoreContainer.registerCore registering= core: collection1 [junit4:junit4] 2> 2395 T2558 oasc.ZkController.register Register shard -= core:collection1 address:http://127.0.0.1:32009/hh_ov/xj shardId:shard1 [junit4:junit4] 2> 2396 T2558 oascc.SolrZkClient.makePath makePath: /coll= ections/control_collection/leader_elect/shard1/election [junit4:junit4] 2> 2411 T2538 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13baae40d0d0003 type:del= ete cxid:0x78 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> 2412 T2558 oasc.ShardLeaderElectionContext.runLeaderPr= ocess Running the leader process. [junit4:junit4] 2> 2413 T2538 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13baae40d0d0003 type:cre= ate cxid:0x79 zxid:0x37 txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 2425 T2558 oasc.ShardLeaderElectionContext.waitForRepl= icasToComeUp Enough replicas found to continue. [junit4:junit4] 2> 2426 T2558 oasc.ShardLeaderElectionContext.runLeaderPr= ocess I may be the new leader - try and sync [junit4:junit4] 2> 2426 T2558 oasc.SyncStrategy.sync Sync replicas to htt= p://127.0.0.1:32009/hh_ov/xj/collection1/ [junit4:junit4] 2> 2426 T2558 oasc.SyncStrategy.syncReplicas Sync Success= - now sync replicas to me [junit4:junit4] 2> 2426 T2558 oasc.SyncStrategy.syncToMe http://127.0.0.1= :32009/hh_ov/xj/collection1/ has no replicas [junit4:junit4] 2> 2426 T2558 oasc.ShardLeaderElectionContext.runLeaderPr= ocess I am the new leader: http://127.0.0.1:32009/hh_ov/xj/collection1/ [junit4:junit4] 2> 2427 T2558 oascc.SolrZkClient.makePath makePath: /coll= ections/control_collection/leaders/shard1 [junit4:junit4] 2> 2436 T2538 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13baae40d0d0003 type:cre= ate cxid:0x83 zxid:0x3b txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 2791 T2556 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 2808 T2555 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> 2846 T2558 oasc.ZkController.register We are http://12= 7.0.0.1:32009/hh_ov/xj/collection1/ and leader is http://127.0.0.1:32009/hh= _ov/xj/collection1/ [junit4:junit4] 2> 2846 T2558 oasc.ZkController.register No LogReplay nee= ded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:32009/hh_ov/xj [junit4:junit4] 2> 2846 T2558 oasc.ZkController.checkRecovery I am the le= ader, no recovery necessary [junit4:junit4] 2> 2847 T2558 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Dactive [junit4:junit4] 2> 2847 T2558 oasc.ZkController.publish numShards not fou= nd on descriptor - reading it from system property [junit4:junit4] 2> 2849 T2558 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 2850 T2533 oass.SolrDispatchFilter.init user.dir=3D/us= r/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build= /solr-core/test/J1 [junit4:junit4] 2> 2851 T2533 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() done [junit4:junit4] 2> 2851 T2533 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&fo= llowRedirects=3Dfalse [junit4:junit4] 2> 2860 T2533 oascsi.HttpClientUtil.createClient Creating= new http client, config: [junit4:junit4] 2> 2867 T2533 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:32005/solr sessionTimeout=3D10000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@1616bfe2 [junit4:junit4] 2> 2867 T2533 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 2868 T2560 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost/127.0.0.1:32005. Will not atte= mpt to authenticate using SASL (access denied ("javax.security.auth.AuthPer= mission" "getLoginConfiguration")) [junit4:junit4] 2> 2868 T2560 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost/127.0.0.1:32005, initiating sessi= on [junit4:junit4] 2> 2869 T2535 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /140.211.11.196:32012 [junit4:junit4] 2> 2869 T2535 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /140.211.11.196:32012 [junit4:junit4] 2> 2870 T2537 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13baae40d0d0004 with negotiated timeout 10000 for client = /140.211.11.196:32012 [junit4:junit4] 2> 2870 T2560 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost/127.0.0.1:32005, sessionid = =3D 0x13baae40d0d0004, negotiated timeout =3D 10000 [junit4:junit4] 2> 2870 T2561 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@1616bfe2 name:ZooKeeperConnecti= on Watcher:127.0.0.1:32005/solr got event WatchedEvent state:SyncConnected = type:None path:null path:null type:None [junit4:junit4] 2> 2871 T2533 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 2872 T2533 oascc.ZkStateReader.createClusterStateWatch= ersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 2873 T2533 oasc.ChaosMonkey.monkeyLog monkey: init - e= xpire sessions:true cause connection loss:true [junit4:junit4] 2> 2983 T2533 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 2985 T2533 oejs.AbstractConnector.doStart Started Sock= etConnector@127.0.0.1:32013 [junit4:junit4] 2> 2986 T2533 oasc.SolrResourceLoader.locateSolrHome JNDI= not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 2987 T2533 oasc.SolrResourceLoader.locateSolrHome usin= g system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.c= loud.SyncSliceTest-jetty1-1355781773373 [junit4:junit4] 2> 2987 T2533 oasc.SolrResourceLoader. new SolrReso= urceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/= Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.= cloud.SyncSliceTest-jetty1-1355781773373/' [junit4:junit4] 2> 3015 T2533 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() [junit4:junit4] 2> 3015 T2533 oasc.SolrResourceLoader.locateSolrHome JNDI= not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 3016 T2533 oasc.SolrResourceLoader.locateSolrHome usin= g system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.c= loud.SyncSliceTest-jetty1-1355781773373 [junit4:junit4] 2> 3016 T2533 oasc.CoreContainer$Initializer.initialize l= ooking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSlic= eTest-jetty1-1355781773373/solr.xml [junit4:junit4] 2> 3017 T2533 oasc.CoreContainer. New CoreContainer= 222631496 [junit4:junit4] 2> 3017 T2533 oasc.CoreContainer.load Loading CoreContain= er using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSlic= eTest-jetty1-1355781773373/' [junit4:junit4] 2> 3018 T2533 oasc.SolrResourceLoader. new SolrReso= urceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-S= olr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Sy= ncSliceTest-jetty1-1355781773373/' [junit4:junit4] 2> 3037 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting socketTimeout to: 30000 [junit4:junit4] 2> 3038 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting urlScheme to: http:// [junit4:junit4] 2> 3039 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting connTimeout to: 15000 [junit4:junit4] 2> 3039 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 3039 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting corePoolSize to: 0 [junit4:junit4] 2> 3040 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 3040 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting maxThreadIdleTime to: 5 [junit4:junit4] 2> 3041 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting sizeOfQueue to: -1 [junit4:junit4] 2> 3041 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting fairnessPolicy to: false [junit4:junit4] 2> 3041 T2533 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000&= socketTimeout=3D30000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 3055 T2533 oasc.CoreContainer.load Registering Log Lis= tener [junit4:junit4] 2> 3069 T2533 oasc.CoreContainer.initZooKeeper Zookeeper = client=3D127.0.0.1:32005/solr [junit4:junit4] 2> 3070 T2533 oasc.ZkController.checkChrootPath zkHost in= cludes chroot [junit4:junit4] 2> 3070 T2533 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:32005 sessionTimeout=3D60000 watcher=3Dor= g.apache.solr.common.cloud.ConnectionManager@5b38e98a [junit4:junit4] 2> 3071 T2533 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 3072 T2571 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost/127.0.0.1:32005. Will not atte= mpt to authenticate using SASL (access denied ("javax.security.auth.AuthPer= mission" "getLoginConfiguration")) [junit4:junit4] 2> 3072 T2571 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost/127.0.0.1:32005, initiating sessi= on [junit4:junit4] 2> 3072 T2535 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /140.211.11.196:32014 [junit4:junit4] 2> 3073 T2535 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /140.211.11.196:32014 [junit4:junit4] 2> 3075 T2537 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13baae40d0d0005 with negotiated timeout 20000 for client = /140.211.11.196:32014 [junit4:junit4] 2> 3075 T2571 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost/127.0.0.1:32005, sessionid = =3D 0x13baae40d0d0005, negotiated timeout =3D 20000 [junit4:junit4] 2> 3075 T2572 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@5b38e98a name:ZooKeeperConnecti= on Watcher:127.0.0.1:32005 got event WatchedEvent state:SyncConnected type:= None path:null path:null type:None [junit4:junit4] 2> 3076 T2533 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 3077 T2538 oazs.PrepRequestProcessor.pRequest2Txn Proc= essed session termination for sessionid: 0x13baae40d0d0005 [junit4:junit4] 2> 3088 T2572 oaz.ClientCnxn$EventThread.run EventThread = shut down [junit4:junit4] 2> 3088 T2535 oazs.NIOServerCnxn.closeSock Closed socket = connection for client /140.211.11.196:32014 which had sessionid 0x13baae40d= 0d0005 [junit4:junit4] 2> 3088 T2533 oaz.ZooKeeper.close Session: 0x13baae40d0d0= 005 closed [junit4:junit4] 2> 3089 T2533 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&so= cketTimeout=3D15000&connTimeout=3D30000 [junit4:junit4] 2> 3095 T2533 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:32005/solr sessionTimeout=3D30000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@6b70339c [junit4:junit4] 2> 3096 T2533 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 3096 T2573 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost/127.0.0.1:32005. Will not atte= mpt to authenticate using SASL (access denied ("javax.security.auth.AuthPer= mission" "getLoginConfiguration")) [junit4:junit4] 2> 3097 T2573 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost/127.0.0.1:32005, initiating sessi= on [junit4:junit4] 2> 3097 T2535 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /140.211.11.196:32015 [junit4:junit4] 2> 3098 T2535 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /140.211.11.196:32015 [junit4:junit4] 2> 3099 T2537 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13baae40d0d0006 with negotiated timeout 20000 for client = /140.211.11.196:32015 [junit4:junit4] 2> 3099 T2573 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost/127.0.0.1:32005, sessionid = =3D 0x13baae40d0d0006, negotiated timeout =3D 20000 [junit4:junit4] 2> 3099 T2574 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@6b70339c name:ZooKeeperConnecti= on Watcher:127.0.0.1:32005/solr got event WatchedEvent state:SyncConnected = type:None path:null path:null type:None [junit4:junit4] 2> 3099 T2533 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 3100 T2538 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13baae40d0d0006 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> 3101 T2538 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13baae40d0d0006 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> 3111 T2533 oasc.ZkController.createEphemeralLiveNode R= egister node as live in ZooKeeper:/live_nodes/127.0.0.1:32013_hh_ov%2Fxj [junit4:junit4] 2> 3111 T2538 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13baae40d0d0006 type:del= ete cxid:0x4 zxid:0x4b txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/1= 27.0.0.1:32013_hh_ov%2Fxj Error:KeeperErrorCode =3D NoNode for /solr/live_n= odes/127.0.0.1:32013_hh_ov%2Fxj [junit4:junit4] 2> 3112 T2533 oascc.SolrZkClient.makePath makePath: /live= _nodes/127.0.0.1:32013_hh_ov%2Fxj [junit4:junit4] 2> 3115 T2555 oascc.ZkStateReader$3.process Updating live= nodes... (2) [junit4:junit4] 2> 3115 T2561 oascc.ZkStateReader$3.process Updating live= nodes... (2) [junit4:junit4] 2> 3116 T2555 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> 3119 T2533 oascc.ZkStateReader.createClusterStateWatch= ersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 3125 T2575 oasc.CoreContainer.create Creating SolrCore= 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.c= loud.SyncSliceTest-jetty1-1355781773373/collection1 [junit4:junit4] 2> 3125 T2575 oasc.ZkController.createCollectionZkNode Ch= eck for collection zkNode:collection1 [junit4:junit4] 2> 3126 T2575 oasc.ZkController.createCollectionZkNode Co= llection zkNode exists [junit4:junit4] 2> 3126 T2575 oasc.ZkController.readConfigName Load colle= ction config from:/collections/collection1 [junit4:junit4] 2> 3127 T2575 oasc.SolrResourceLoader. new SolrReso= urceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-S= olr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Sy= ncSliceTest-jetty1-1355781773373/collection1/' [junit4:junit4] 2> 3129 T2575 oasc.SolrResourceLoader.replaceClassLoader = Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-= java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jett= y1-1355781773373/collection1/lib/README' to classloader [junit4:junit4] 2> 3129 T2575 oasc.SolrResourceLoader.replaceClassLoader = Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-= java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jett= y1-1355781773373/collection1/lib/classes/' to classloader [junit4:junit4] 2> 3182 T2575 oasc.SolrConfig. Using Lucene MatchVe= rsion: LUCENE_41 [junit4:junit4] 2> 3254 T2575 oasc.SolrConfig. Loaded SolrConfig: s= olrconfig.xml [junit4:junit4] 2> 3321 T2556 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 3322 T2556 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "shard":"shard1", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"active", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"control_collection", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:32009_hh_ov%2Fxj", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:32009/hh_ov/xj"} [junit4:junit4] 2> 3335 T2555 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> 3335 T2561 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> 3355 T2575 oass.IndexSchema.readSchema Reading Solr Sc= hema [junit4:junit4] 2> 3355 T2574 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> 3362 T2575 oass.IndexSchema.readSchema Schema name=3Dt= est [junit4:junit4] 2> 3996 T2575 oass.OpenExchangeRatesOrgProvider.init Init= ialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 4008 T2575 oass.IndexSchema.readSchema default search = field in schema is text [junit4:junit4] 2> 4012 T2575 oass.IndexSchema.readSchema unique key fiel= d: id [junit4:junit4] 2> 4025 T2575 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 4030 T2575 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 4035 T2575 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 4036 T2575 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 4037 T2575 oasc.SolrCore. [collection1] Opening = new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4= .x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest= -jetty1-1355781773373/collection1/, dataDir=3D./org.apache.solr.cloud.SyncS= liceTest-1355781770504/jetty1/ [junit4:junit4] 2> 4038 T2575 oasc.JmxMonitoredMap. JMX monitoring = is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMB= eanServer@1afa578a [junit4:junit4] 2> 4038 T2575 oasc.SolrCore.initDirectoryFactory solr.NRT= CachingDirectoryFactory [junit4:junit4] 2> 4039 T2575 oasc.CachingDirectoryFactory.get return new= directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.= x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-= 1355781770504/jetty1 forceNew:false [junit4:junit4] 2> 4040 T2575 oasc.CachingDirectoryFactory.close Releasin= g directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-j= ava7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-135= 5781770504/jetty1 [junit4:junit4] 2> 4040 T2575 oasc.SolrCore.getNewIndexDir New index dire= ctory detected: old=3Dnull new=3D./org.apache.solr.cloud.SyncSliceTest-1355= 781770504/jetty1/index/ [junit4:junit4] 2> 4041 T2575 oasc.SolrCore.initIndex WARNING [collection= 1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-135578177050= 4/jetty1/index' doesn't exist. Creating new index... [junit4:junit4] 2> 4042 T2575 oasc.CachingDirectoryFactory.get return new= directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.= x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-= 1355781770504/jetty1/index forceNew:false [junit4:junit4] 2> 4064 T2575 oasc.SolrDeletionPolicy.onCommit SolrDeleti= onPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/o= rg.apache.solr.cloud.SyncSliceTest-1355781770504/jetty1/index lockFactory= =3Dorg.apache.lucene.store.NativeFSLockFactory@59130c74; maxCacheMB=3D48.0 = maxMergeSizeMB=3D4.0)),segFN=3Dsegments_1,generation=3D1,filenames=3D[segme= nts_1] [junit4:junit4] 2> 4065 T2575 oasc.SolrDeletionPolicy.updateCommits newes= t commit =3D 1[segments_1] [junit4:junit4] 2> 4065 T2575 oasc.CachingDirectoryFactory.close Releasin= g directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-j= ava7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-135= 5781770504/jetty1/index [junit4:junit4] 2> 4066 T2575 oasc.SolrCore.initWriters created xml: solr= .XMLResponseWriter [junit4:junit4] 2> 4068 T2575 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe" [junit4:junit4] 2> 4068 T2575 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe-allfields" [junit4:junit4] 2> 4068 T2575 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "s= tored_sig" [junit4:junit4] 2> 4069 T2575 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "u= niq-fields" [junit4:junit4] 2> 4070 T2575 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= istrib-dup-test-chain-implicit" [junit4:junit4] 2> 4070 T2575 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 4070 T2575 oasc.RequestHandlers.initHandlersFromConfig= created /replication: solr.ReplicationHandler [junit4:junit4] 2> 4071 T2575 oasc.RequestHandlers.initHandlersFromConfig= created standard: solr.StandardRequestHandler [junit4:junit4] 2> 4072 T2575 oasc.RequestHandlers.initHandlersFromConfig= created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 4073 T2575 oasc.RequestHandlers.initHandlersFromConfig= created dismax: solr.SearchHandler [junit4:junit4] 2> 4074 T2575 oasc.RequestHandlers.initHandlersFromConfig= created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler [junit4:junit4] 2> 4075 T2575 oasc.RequestHandlers.initHandlersFromConfig= created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 4076 T2575 oasc.RequestHandlers.initHandlersFromConfig= created defaults: solr.StandardRequestHandler [junit4:junit4] 2> 4076 T2575 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.StandardRequestHandler [junit4:junit4] 2> 4076 T2575 oasc.RequestHandlers.initHandlersFromConfig= created lazy: solr.StandardRequestHandler [junit4:junit4] 2> 4077 T2575 oasc.RequestHandlers.initHandlersFromConfig= created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 4078 T2575 oasc.RequestHandlers.initHandlersFromConfig= created /terms: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 4079 T2575 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 4080 T2575 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchH= andler [junit4:junit4] 2> 4081 T2575 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchH= andler [junit4:junit4] 2> 4082 T2575 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.= SearchHandler [junit4:junit4] 2> 4083 T2575 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 4084 T2575 oasc.RequestHandlers.initHandlersFromConfig= created mltrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 4084 T2575 oasc.RequestHandlers.initHandlersFromConfig= created tvrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 4085 T2575 oasc.RequestHandlers.initHandlersFromConfig= created /mlt: solr.MoreLikeThisHandler [junit4:junit4] 2> 4086 T2575 oasc.RequestHandlers.initHandlersFromConfig= created /debug/dump: solr.DumpRequestHandler [junit4:junit4] 2> 4099 T2575 oashl.XMLLoader.init xsltCacheLifetimeSecon= ds=3D60 [junit4:junit4] 2> 4104 T2575 oasc.SolrCore.initDeprecatedSupport WARNING= solrconfig.xml uses deprecated , Please update your c= onfig to use the ShowFileRequestHandler. [junit4:junit4] 2> 4105 T2575 oasc.SolrCore.initDeprecatedSupport WARNING= adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS= .TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT,= CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT] [junit4:junit4] 2> 4108 T2575 oasc.CachingDirectoryFactory.close Releasin= g directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-j= ava7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-135= 5781770504/jetty1 [junit4:junit4] 2> 4110 T2575 oass.SolrIndexSearcher. Opening Searc= her@6db1bcee main [junit4:junit4] 2> 4111 T2575 oasu.CommitTracker. Hard AutoCommit: = disabled [junit4:junit4] 2> 4111 T2575 oasu.CommitTracker. Soft AutoCommit: = disabled [junit4:junit4] 2> 4112 T2575 oashc.SpellCheckComponent.inform Initializi= ng spell checkers [junit4:junit4] 2> 4119 T2575 oass.DirectSolrSpellChecker.init init: {nam= e=3Ddirect,classname=3DDirectSolrSpellChecker,field=3Dlowerfilt,minQueryLen= gth=3D3} [junit4:junit4] 2> 4192 T2576 oasc.SolrCore.registerSearcher [collection1= ] Registered new searcher Searcher@6db1bcee main{StandardDirectoryReader(se= gments_1:1)} [junit4:junit4] 2> 4197 T2575 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Ddown [junit4:junit4] 2> 4197 T2575 oasc.ZkController.publish numShards not fou= nd on descriptor - reading it from system property [junit4:junit4] 2> 4360 T2556 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 4361 T2556 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "shard":null, [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"down", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:32013_hh_ov%2Fxj", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:32013/hh_ov/xj"} [junit4:junit4] 2> 4361 T2556 oasc.Overseer$ClusterStateUpdater.createCol= lection Create collection collection1 with numShards 1 [junit4:junit4] 2> 4361 T2556 oasc.Overseer$ClusterStateUpdater.updateSta= te Assigning new node to shard shard=3Dshard1 [junit4:junit4] 2> 4374 T2574 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> 4374 T2561 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> 4374 T2555 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> 4700 T2575 oasc.CoreContainer.registerCore registering= core: collection1 [junit4:junit4] 2> 4700 T2575 oasc.ZkController.register Register shard -= core:collection1 address:http://127.0.0.1:32013/hh_ov/xj shardId:shard1 [junit4:junit4] 2> 4701 T2575 oascc.SolrZkClient.makePath makePath: /coll= ections/collection1/leader_elect/shard1/election [junit4:junit4] 2> 4717 T2538 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13baae40d0d0006 type:del= ete cxid:0x45 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> 4717 T2575 oasc.ShardLeaderElectionContext.runLeaderPr= ocess Running the leader process. [junit4:junit4] 2> 4718 T2538 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13baae40d0d0006 type:cre= ate cxid:0x46 zxid:0x5c txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 4729 T2575 oasc.ShardLeaderElectionContext.waitForRepl= icasToComeUp Enough replicas found to continue. [junit4:junit4] 2> 4729 T2575 oasc.ShardLeaderElectionContext.runLeaderPr= ocess I may be the new leader - try and sync [junit4:junit4] 2> 4730 T2575 oasc.SyncStrategy.sync Sync replicas to htt= p://127.0.0.1:32013/hh_ov/xj/collection1/ [junit4:junit4] 2> 4730 T2575 oasc.SyncStrategy.syncReplicas Sync Success= - now sync replicas to me [junit4:junit4] 2> 4730 T2575 oasc.SyncStrategy.syncToMe http://127.0.0.1= :32013/hh_ov/xj/collection1/ has no replicas [junit4:junit4] 2> 4730 T2575 oasc.ShardLeaderElectionContext.runLeaderPr= ocess I am the new leader: http://127.0.0.1:32013/hh_ov/xj/collection1/ [junit4:junit4] 2> 4731 T2575 oascc.SolrZkClient.makePath makePath: /coll= ections/collection1/leaders/shard1 [junit4:junit4] 2> 4734 T2538 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13baae40d0d0006 type:cre= ate cxid:0x50 zxid:0x60 txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 4878 T2556 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 4893 T2574 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> 4893 T2555 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> 4893 T2561 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> 4941 T2575 oasc.ZkController.register We are http://12= 7.0.0.1:32013/hh_ov/xj/collection1/ and leader is http://127.0.0.1:32013/hh= _ov/xj/collection1/ [junit4:junit4] 2> 4941 T2575 oasc.ZkController.register No LogReplay nee= ded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:32013/hh_ov/xj [junit4:junit4] 2> 4941 T2575 oasc.ZkController.checkRecovery I am the le= ader, no recovery necessary [junit4:junit4] 2> 4942 T2575 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Dactive [junit4:junit4] 2> 4942 T2575 oasc.ZkController.publish numShards not fou= nd on descriptor - reading it from system property [junit4:junit4] 2> 4944 T2575 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 4945 T2533 oass.SolrDispatchFilter.init user.dir=3D/us= r/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build= /solr-core/test/J1 [junit4:junit4] 2> 4946 T2533 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() done [junit4:junit4] 2> 4946 T2533 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&fo= llowRedirects=3Dfalse [junit4:junit4] 2> 5065 T2533 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 5068 T2533 oejs.AbstractConnector.doStart Started Sock= etConnector@127.0.0.1:32019 [junit4:junit4] 2> 5068 T2533 oasc.SolrResourceLoader.locateSolrHome JNDI= not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 5069 T2533 oasc.SolrResourceLoader.locateSolrHome usin= g system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.c= loud.SyncSliceTest-jetty2-1355781775456 [junit4:junit4] 2> 5069 T2533 oasc.SolrResourceLoader. new SolrReso= urceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/= Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.= cloud.SyncSliceTest-jetty2-1355781775456/' [junit4:junit4] 2> 5097 T2533 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() [junit4:junit4] 2> 5098 T2533 oasc.SolrResourceLoader.locateSolrHome JNDI= not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 5098 T2533 oasc.SolrResourceLoader.locateSolrHome usin= g system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.c= loud.SyncSliceTest-jetty2-1355781775456 [junit4:junit4] 2> 5099 T2533 oasc.CoreContainer$Initializer.initialize l= ooking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSlic= eTest-jetty2-1355781775456/solr.xml [junit4:junit4] 2> 5099 T2533 oasc.CoreContainer. New CoreContainer= 483790259 [junit4:junit4] 2> 5100 T2533 oasc.CoreContainer.load Loading CoreContain= er using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSlic= eTest-jetty2-1355781775456/' [junit4:junit4] 2> 5100 T2533 oasc.SolrResourceLoader. new SolrReso= urceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-S= olr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Sy= ncSliceTest-jetty2-1355781775456/' [junit4:junit4] 2> 5120 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting socketTimeout to: 30000 [junit4:junit4] 2> 5121 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting urlScheme to: http:// [junit4:junit4] 2> 5121 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting connTimeout to: 15000 [junit4:junit4] 2> 5122 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 5122 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting corePoolSize to: 0 [junit4:junit4] 2> 5123 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 5123 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting maxThreadIdleTime to: 5 [junit4:junit4] 2> 5123 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting sizeOfQueue to: -1 [junit4:junit4] 2> 5124 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting fairnessPolicy to: false [junit4:junit4] 2> 5124 T2533 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000&= socketTimeout=3D30000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 5138 T2533 oasc.CoreContainer.load Registering Log Lis= tener [junit4:junit4] 2> 5152 T2533 oasc.CoreContainer.initZooKeeper Zookeeper = client=3D127.0.0.1:32005/solr [junit4:junit4] 2> 5152 T2533 oasc.ZkController.checkChrootPath zkHost in= cludes chroot [junit4:junit4] 2> 5153 T2533 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:32005 sessionTimeout=3D60000 watcher=3Dor= g.apache.solr.common.cloud.ConnectionManager@401e2ff6 [junit4:junit4] 2> 5154 T2533 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 5154 T2586 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost/127.0.0.1:32005. Will not atte= mpt to authenticate using SASL (access denied ("javax.security.auth.AuthPer= mission" "getLoginConfiguration")) [junit4:junit4] 2> 5155 T2586 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost/127.0.0.1:32005, initiating sessi= on [junit4:junit4] 2> 5155 T2535 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /140.211.11.196:32020 [junit4:junit4] 2> 5156 T2535 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /140.211.11.196:32020 [junit4:junit4] 2> 5158 T2537 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13baae40d0d0007 with negotiated timeout 20000 for client = /140.211.11.196:32020 [junit4:junit4] 2> 5158 T2586 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost/127.0.0.1:32005, sessionid = =3D 0x13baae40d0d0007, negotiated timeout =3D 20000 [junit4:junit4] 2> 5158 T2587 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@401e2ff6 name:ZooKeeperConnecti= on Watcher:127.0.0.1:32005 got event WatchedEvent state:SyncConnected type:= None path:null path:null type:None [junit4:junit4] 2> 5158 T2533 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 5159 T2538 oazs.PrepRequestProcessor.pRequest2Txn Proc= essed session termination for sessionid: 0x13baae40d0d0007 [junit4:junit4] 2> 5172 T2587 oaz.ClientCnxn$EventThread.run EventThread = shut down [junit4:junit4] 2> 5172 T2535 oazs.NIOServerCnxn.closeSock Closed socket = connection for client /140.211.11.196:32020 which had sessionid 0x13baae40d= 0d0007 [junit4:junit4] 2> 5172 T2533 oaz.ZooKeeper.close Session: 0x13baae40d0d0= 007 closed [junit4:junit4] 2> 5173 T2533 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&so= cketTimeout=3D15000&connTimeout=3D30000 [junit4:junit4] 2> 5179 T2533 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:32005/solr sessionTimeout=3D30000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@115a7e6a [junit4:junit4] 2> 5180 T2533 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 5181 T2588 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost/127.0.0.1:32005. Will not atte= mpt to authenticate using SASL (access denied ("javax.security.auth.AuthPer= mission" "getLoginConfiguration")) [junit4:junit4] 2> 5181 T2588 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost/127.0.0.1:32005, initiating sessi= on [junit4:junit4] 2> 5181 T2535 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /140.211.11.196:32021 [junit4:junit4] 2> 5182 T2535 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /140.211.11.196:32021 [junit4:junit4] 2> 5183 T2537 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13baae40d0d0008 with negotiated timeout 20000 for client = /140.211.11.196:32021 [junit4:junit4] 2> 5183 T2588 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost/127.0.0.1:32005, sessionid = =3D 0x13baae40d0d0008, negotiated timeout =3D 20000 [junit4:junit4] 2> 5184 T2589 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@115a7e6a name:ZooKeeperConnecti= on Watcher:127.0.0.1:32005/solr got event WatchedEvent state:SyncConnected = type:None path:null path:null type:None [junit4:junit4] 2> 5184 T2533 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 5185 T2538 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13baae40d0d0008 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> 5186 T2538 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13baae40d0d0008 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> 5187 T2533 oasc.ZkController.createEphemeralLiveNode R= egister node as live in ZooKeeper:/live_nodes/127.0.0.1:32019_hh_ov%2Fxj [junit4:junit4] 2> 5188 T2538 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13baae40d0d0008 type:del= ete cxid:0x4 zxid:0x6f txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/1= 27.0.0.1:32019_hh_ov%2Fxj Error:KeeperErrorCode =3D NoNode for /solr/live_n= odes/127.0.0.1:32019_hh_ov%2Fxj [junit4:junit4] 2> 5197 T2533 oascc.SolrZkClient.makePath makePath: /live= _nodes/127.0.0.1:32019_hh_ov%2Fxj [junit4:junit4] 2> 5200 T2574 oascc.ZkStateReader$3.process Updating live= nodes... (3) [junit4:junit4] 2> 5200 T2555 oascc.ZkStateReader$3.process Updating live= nodes... (3) [junit4:junit4] 2> 5200 T2561 oascc.ZkStateReader$3.process Updating live= nodes... (3) [junit4:junit4] 2> 5200 T2574 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> 5200 T2561 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> 5200 T2555 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> 5203 T2533 oascc.ZkStateReader.createClusterStateWatch= ersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 5209 T2590 oasc.CoreContainer.create Creating SolrCore= 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.c= loud.SyncSliceTest-jetty2-1355781775456/collection1 [junit4:junit4] 2> 5209 T2590 oasc.ZkController.createCollectionZkNode Ch= eck for collection zkNode:collection1 [junit4:junit4] 2> 5210 T2590 oasc.ZkController.createCollectionZkNode Co= llection zkNode exists [junit4:junit4] 2> 5210 T2590 oasc.ZkController.readConfigName Load colle= ction config from:/collections/collection1 [junit4:junit4] 2> 5211 T2590 oasc.SolrResourceLoader. new SolrReso= urceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-S= olr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Sy= ncSliceTest-jetty2-1355781775456/collection1/' [junit4:junit4] 2> 5212 T2590 oasc.SolrResourceLoader.replaceClassLoader = Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-= java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jett= y2-1355781775456/collection1/lib/classes/' to classloader [junit4:junit4] 2> 5213 T2590 oasc.SolrResourceLoader.replaceClassLoader = Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-= java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jett= y2-1355781775456/collection1/lib/README' to classloader [junit4:junit4] 2> 5266 T2590 oasc.SolrConfig. Using Lucene MatchVe= rsion: LUCENE_41 [junit4:junit4] 2> 5344 T2590 oasc.SolrConfig. Loaded SolrConfig: s= olrconfig.xml [junit4:junit4] 2> 5398 T2556 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 5399 T2556 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "shard":"shard1", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"active", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:32013_hh_ov%2Fxj", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:32013/hh_ov/xj"} [junit4:junit4] 2> 5406 T2555 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> 5406 T2561 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> 5406 T2574 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> 5445 T2589 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> 5445 T2590 oass.IndexSchema.readSchema Reading Solr Sc= hema [junit4:junit4] 2> 5452 T2590 oass.IndexSchema.readSchema Schema name=3Dt= est [junit4:junit4] 2> 6104 T2590 oass.OpenExchangeRatesOrgProvider.init Init= ialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 6117 T2590 oass.IndexSchema.readSchema default search = field in schema is text [junit4:junit4] 2> 6121 T2590 oass.IndexSchema.readSchema unique key fiel= d: id [junit4:junit4] 2> 6134 T2590 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 6138 T2590 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 6143 T2590 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 6144 T2590 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 6145 T2590 oasc.SolrCore. [collection1] Opening = new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4= .x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest= -jetty2-1355781775456/collection1/, dataDir=3D./org.apache.solr.cloud.SyncS= liceTest-1355781770504/jetty2/ [junit4:junit4] 2> 6146 T2590 oasc.JmxMonitoredMap. JMX monitoring = is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMB= eanServer@1afa578a [junit4:junit4] 2> 6146 T2590 oasc.SolrCore.initDirectoryFactory solr.NRT= CachingDirectoryFactory [junit4:junit4] 2> 6147 T2590 oasc.CachingDirectoryFactory.get return new= directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.= x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-= 1355781770504/jetty2 forceNew:false [junit4:junit4] 2> 6148 T2590 oasc.CachingDirectoryFactory.close Releasin= g directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-j= ava7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-135= 5781770504/jetty2 [junit4:junit4] 2> 6148 T2590 oasc.SolrCore.getNewIndexDir New index dire= ctory detected: old=3Dnull new=3D./org.apache.solr.cloud.SyncSliceTest-1355= 781770504/jetty2/index/ [junit4:junit4] 2> 6149 T2590 oasc.SolrCore.initIndex WARNING [collection= 1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-135578177050= 4/jetty2/index' doesn't exist. Creating new index... [junit4:junit4] 2> 6150 T2590 oasc.CachingDirectoryFactory.get return new= directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.= x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-= 1355781770504/jetty2/index forceNew:false [junit4:junit4] 2> 6160 T2590 oasc.SolrDeletionPolicy.onCommit SolrDeleti= onPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/o= rg.apache.solr.cloud.SyncSliceTest-1355781770504/jetty2/index lockFactory= =3Dorg.apache.lucene.store.NativeFSLockFactory@40375d54; maxCacheMB=3D48.0 = maxMergeSizeMB=3D4.0)),segFN=3Dsegments_1,generation=3D1,filenames=3D[segme= nts_1] [junit4:junit4] 2> 6160 T2590 oasc.SolrDeletionPolicy.updateCommits newes= t commit =3D 1[segments_1] [junit4:junit4] 2> 6161 T2590 oasc.CachingDirectoryFactory.close Releasin= g directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-j= ava7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-135= 5781770504/jetty2/index [junit4:junit4] 2> 6161 T2590 oasc.SolrCore.initWriters created xml: solr= .XMLResponseWriter [junit4:junit4] 2> 6163 T2590 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe" [junit4:junit4] 2> 6163 T2590 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe-allfields" [junit4:junit4] 2> 6164 T2590 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "s= tored_sig" [junit4:junit4] 2> 6164 T2590 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "u= niq-fields" [junit4:junit4] 2> 6165 T2590 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= istrib-dup-test-chain-implicit" [junit4:junit4] 2> 6165 T2590 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 6165 T2590 oasc.RequestHandlers.initHandlersFromConfig= created /replication: solr.ReplicationHandler [junit4:junit4] 2> 6166 T2590 oasc.RequestHandlers.initHandlersFromConfig= created standard: solr.StandardRequestHandler [junit4:junit4] 2> 6167 T2590 oasc.RequestHandlers.initHandlersFromConfig= created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 6168 T2590 oasc.RequestHandlers.initHandlersFromConfig= created dismax: solr.SearchHandler [junit4:junit4] 2> 6169 T2590 oasc.RequestHandlers.initHandlersFromConfig= created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler [junit4:junit4] 2> 6169 T2590 oasc.RequestHandlers.initHandlersFromConfig= created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 6170 T2590 oasc.RequestHandlers.initHandlersFromConfig= created defaults: solr.StandardRequestHandler [junit4:junit4] 2> 6171 T2590 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.StandardRequestHandler [junit4:junit4] 2> 6171 T2590 oasc.RequestHandlers.initHandlersFromConfig= created lazy: solr.StandardRequestHandler [junit4:junit4] 2> 6172 T2590 oasc.RequestHandlers.initHandlersFromConfig= created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 6173 T2590 oasc.RequestHandlers.initHandlersFromConfig= created /terms: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 6173 T2590 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 6174 T2590 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchH= andler [junit4:junit4] 2> 6175 T2590 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchH= andler [junit4:junit4] 2> 6176 T2590 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.= SearchHandler [junit4:junit4] 2> 6177 T2590 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 6178 T2590 oasc.RequestHandlers.initHandlersFromConfig= created mltrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 6179 T2590 oasc.RequestHandlers.initHandlersFromConfig= created tvrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 6179 T2590 oasc.RequestHandlers.initHandlersFromConfig= created /mlt: solr.MoreLikeThisHandler [junit4:junit4] 2> 6180 T2590 oasc.RequestHandlers.initHandlersFromConfig= created /debug/dump: solr.DumpRequestHandler [junit4:junit4] 2> 6192 T2590 oashl.XMLLoader.init xsltCacheLifetimeSecon= ds=3D60 [junit4:junit4] 2> 6197 T2590 oasc.SolrCore.initDeprecatedSupport WARNING= solrconfig.xml uses deprecated , Please update your c= onfig to use the ShowFileRequestHandler. [junit4:junit4] 2> 6198 T2590 oasc.SolrCore.initDeprecatedSupport WARNING= adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS= .TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT,= CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT] [junit4:junit4] 2> 6200 T2590 oasc.CachingDirectoryFactory.close Releasin= g directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-j= ava7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-135= 5781770504/jetty2 [junit4:junit4] 2> 6202 T2590 oass.SolrIndexSearcher. Opening Searc= her@30b72e44 main [junit4:junit4] 2> 6203 T2590 oasu.CommitTracker. Hard AutoCommit: = disabled [junit4:junit4] 2> 6203 T2590 oasu.CommitTracker. Soft AutoCommit: = disabled [junit4:junit4] 2> 6204 T2590 oashc.SpellCheckComponent.inform Initializi= ng spell checkers [junit4:junit4] 2> 6211 T2590 oass.DirectSolrSpellChecker.init init: {nam= e=3Ddirect,classname=3DDirectSolrSpellChecker,field=3Dlowerfilt,minQueryLen= gth=3D3} [junit4:junit4] 2> 6264 T2591 oasc.SolrCore.registerSearcher [collection1= ] Registered new searcher Searcher@30b72e44 main{StandardDirectoryReader(se= gments_1:1)} [junit4:junit4] 2> 6268 T2590 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Ddown [junit4:junit4] 2> 6268 T2590 oasc.ZkController.publish numShards not fou= nd on descriptor - reading it from system property [junit4:junit4] 2> 6451 T2556 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 6452 T2556 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "shard":null, [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"down", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:32019_hh_ov%2Fxj", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:32019/hh_ov/xj"} [junit4:junit4] 2> 6452 T2556 oasc.Overseer$ClusterStateUpdater.updateSta= te Collection already exists with numShards=3D1 [junit4:junit4] 2> 6452 T2556 oasc.Overseer$ClusterStateUpdater.updateSta= te Assigning new node to shard shard=3Dshard1 [junit4:junit4] 2> 6468 T2589 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> 6468 T2574 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> 6468 T2555 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> 6468 T2561 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> 6771 T2590 oasc.CoreContainer.registerCore registering= core: collection1 [junit4:junit4] 2> 6771 T2590 oasc.ZkController.register Register shard -= core:collection1 address:http://127.0.0.1:32019/hh_ov/xj shardId:shard1 [junit4:junit4] 2> 6774 T2590 oasc.ZkController.register We are http://12= 7.0.0.1:32019/hh_ov/xj/collection1/ and leader is http://127.0.0.1:32013/hh= _ov/xj/collection1/ [junit4:junit4] 2> 6774 T2590 oasc.ZkController.register No LogReplay nee= ded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:32019/hh_ov/xj [junit4:junit4] 2> 6774 T2590 oasc.ZkController.checkRecovery Core needs = to recover:collection1 [junit4:junit4] 2> 6775 T2590 oasu.DefaultSolrCoreState.doRecovery Runnin= g recovery - first canceling any ongoing recovery [junit4:junit4] 2> ASYNC NEW_CORE C158 name=3Dcollection1 org.apache.sol= r.core.SolrCore@2c3c0497 url=3Dhttp://127.0.0.1:32019/hh_ov/xj/collection1 = node=3D127.0.0.1:32019_hh_ov%2Fxj [junit4:junit4] 2> 6775 T2592 C158 P32019 oasc.RecoveryStrategy.run Start= ing recovery process. core=3Dcollection1 recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 6775 T2590 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 6776 T2592 C158 P32019 oasc.RecoveryStrategy.doRecover= y ###### startupVersions=3D[] [junit4:junit4] 2> 6777 T2592 C158 P32019 oasc.ZkController.publish publi= shing core=3Dcollection1 state=3Drecovering [junit4:junit4] 2> 6777 T2592 C158 P32019 oasc.ZkController.publish numSh= ards not found on descriptor - reading it from system property [junit4:junit4] 2> 6777 T2533 oass.SolrDispatchFilter.init user.dir=3D/us= r/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build= /solr-core/test/J1 [junit4:junit4] 2> 6778 T2533 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() done [junit4:junit4] 2> 6778 T2533 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&fo= llowRedirects=3Dfalse [junit4:junit4] 2> 6782 T2592 C158 P32019 oasc.RecoveryStrategy.doRecover= y Attempting to PeerSync from http://127.0.0.1:32013/hh_ov/xj/collection1/ = core=3Dcollection1 - recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 6783 T2592 C158 P32019 oasu.PeerSync.sync PeerSync: co= re=3Dcollection1 url=3Dhttp://127.0.0.1:32019/hh_ov/xj START replicas=3D[ht= tp://127.0.0.1:32013/hh_ov/xj/collection1/] nUpdates=3D100 [junit4:junit4] 2> 6783 T2592 C158 P32019 oasu.PeerSync.sync WARNING no f= rame of reference to tell of we've missed updates [junit4:junit4] 2> 6783 T2592 C158 P32019 oasc.RecoveryStrategy.doRecover= y PeerSync Recovery was not successful - trying replication. core=3Dcollect= ion1 [junit4:junit4] 2> 6784 T2592 C158 P32019 oasc.RecoveryStrategy.doRecover= y Starting Replication Recovery. core=3Dcollection1 [junit4:junit4] 2> 6784 T2592 C158 P32019 oascsi.HttpClientUtil.createCli= ent Creating new http client, config:maxConnections=3D128&maxConnectionsPer= Host=3D32&followRedirects=3Dfalse [junit4:junit4] 2> ASYNC NEW_CORE C159 name=3Dcollection1 org.apache.sol= r.core.SolrCore@64ef42b1 url=3Dhttp://127.0.0.1:32013/hh_ov/xj/collection1 = node=3D127.0.0.1:32013_hh_ov%2Fxj [junit4:junit4] 2> 6799 T2564 C159 P32013 REQ /get {distrib=3Dfalse&qt=3D= /get&wt=3Djavabin&version=3D2&getVersions=3D100} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 6900 T2533 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 6903 T2533 oejs.AbstractConnector.doStart Started Sock= etConnector@127.0.0.1:32024 [junit4:junit4] 2> 6904 T2533 oasc.SolrResourceLoader.locateSolrHome JNDI= not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 6904 T2533 oasc.SolrResourceLoader.locateSolrHome usin= g system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.c= loud.SyncSliceTest-jetty3-1355781777289 [junit4:junit4] 2> 6905 T2533 oasc.SolrResourceLoader. new SolrReso= urceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/= Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.= cloud.SyncSliceTest-jetty3-1355781777289/' [junit4:junit4] 2> 6932 T2533 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() [junit4:junit4] 2> 6933 T2533 oasc.SolrResourceLoader.locateSolrHome JNDI= not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 6933 T2533 oasc.SolrResourceLoader.locateSolrHome usin= g system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.c= loud.SyncSliceTest-jetty3-1355781777289 [junit4:junit4] 2> 6934 T2533 oasc.CoreContainer$Initializer.initialize l= ooking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSlic= eTest-jetty3-1355781777289/solr.xml [junit4:junit4] 2> 6934 T2533 oasc.CoreContainer. New CoreContainer= 490078543 [junit4:junit4] 2> 6935 T2533 oasc.CoreContainer.load Loading CoreContain= er using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSlic= eTest-jetty3-1355781777289/' [junit4:junit4] 2> 6935 T2533 oasc.SolrResourceLoader. new SolrReso= urceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-S= olr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Sy= ncSliceTest-jetty3-1355781777289/' [junit4:junit4] 2> 6955 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting socketTimeout to: 30000 [junit4:junit4] 2> 6956 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting urlScheme to: http:// [junit4:junit4] 2> 6956 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting connTimeout to: 15000 [junit4:junit4] 2> 6957 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 6957 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting corePoolSize to: 0 [junit4:junit4] 2> 6958 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 6958 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting maxThreadIdleTime to: 5 [junit4:junit4] 2> 6958 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting sizeOfQueue to: -1 [junit4:junit4] 2> 6959 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting fairnessPolicy to: false [junit4:junit4] 2> 6959 T2533 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000&= socketTimeout=3D30000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 6972 T2556 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 6973 T2556 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "shard":"shard1", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"recovering", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:32019_hh_ov%2Fxj", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:32019/hh_ov/xj"} [junit4:junit4] 2> 6973 T2533 oasc.CoreContainer.load Registering Log Lis= tener [junit4:junit4] 2> 6987 T2533 oasc.CoreContainer.initZooKeeper Zookeeper = client=3D127.0.0.1:32005/solr [junit4:junit4] 2> 6988 T2533 oasc.ZkController.checkChrootPath zkHost in= cludes chroot [junit4:junit4] 2> 6989 T2533 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:32005 sessionTimeout=3D60000 watcher=3Dor= g.apache.solr.common.cloud.ConnectionManager@70e8b66a [junit4:junit4] 2> 6989 T2533 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 6990 T2603 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost/127.0.0.1:32005. Will not atte= mpt to authenticate using SASL (access denied ("javax.security.auth.AuthPer= mission" "getLoginConfiguration")) [junit4:junit4] 2> 6990 T2603 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost/127.0.0.1:32005, initiating sessi= on [junit4:junit4] 2> 6991 T2535 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /140.211.11.196:32025 [junit4:junit4] 2> 6991 T2535 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /140.211.11.196:32025 [junit4:junit4] 2> 6992 T2555 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> 6992 T2574 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> 6992 T2589 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> 6992 T2561 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> 6999 T2537 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13baae40d0d0009 with negotiated timeout 20000 for client = /140.211.11.196:32025 [junit4:junit4] 2> 6999 T2603 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost/127.0.0.1:32005, sessionid = =3D 0x13baae40d0d0009, negotiated timeout =3D 20000 [junit4:junit4] 2> 7000 T2604 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@70e8b66a name:ZooKeeperConnecti= on Watcher:127.0.0.1:32005 got event WatchedEvent state:SyncConnected type:= None path:null path:null type:None [junit4:junit4] 2> 7000 T2533 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 7002 T2538 oazs.PrepRequestProcessor.pRequest2Txn Proc= essed session termination for sessionid: 0x13baae40d0d0009 [junit4:junit4] 2> 7002 T2535 oazs.NIOServerCnxn.closeSock Closed socket = connection for client /140.211.11.196:32025 which had sessionid 0x13baae40d= 0d0009 [junit4:junit4] 2> 7002 T2604 oaz.ClientCnxn$EventThread.run EventThread = shut down [junit4:junit4] 2> 7002 T2533 oaz.ZooKeeper.close Session: 0x13baae40d0d0= 009 closed [junit4:junit4] 2> 7003 T2533 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&so= cketTimeout=3D15000&connTimeout=3D30000 [junit4:junit4] 2> 7013 T2533 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:32005/solr sessionTimeout=3D30000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@24498d6e [junit4:junit4] 2> 7014 T2533 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 7014 T2605 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost/127.0.0.1:32005. Will not atte= mpt to authenticate using SASL (access denied ("javax.security.auth.AuthPer= mission" "getLoginConfiguration")) [junit4:junit4] 2> 7015 T2605 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost/127.0.0.1:32005, initiating sessi= on [junit4:junit4] 2> 7015 T2535 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /140.211.11.196:32026 [junit4:junit4] 2> 7015 T2535 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /140.211.11.196:32026 [junit4:junit4] 2> 7016 T2537 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13baae40d0d000a with negotiated timeout 20000 for client = /140.211.11.196:32026 [junit4:junit4] 2> 7016 T2605 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost/127.0.0.1:32005, sessionid = =3D 0x13baae40d0d000a, negotiated timeout =3D 20000 [junit4:junit4] 2> 7017 T2606 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@24498d6e name:ZooKeeperConnecti= on Watcher:127.0.0.1:32005/solr got event WatchedEvent state:SyncConnected = type:None path:null path:null type:None [junit4:junit4] 2> 7017 T2533 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 7018 T2538 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13baae40d0d000a type:cre= ate cxid:0x1 zxid:0x84 txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 7019 T2538 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13baae40d0d000a type:cre= ate cxid:0x2 zxid:0x85 txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 7027 T2533 oasc.ZkController.createEphemeralLiveNode R= egister node as live in ZooKeeper:/live_nodes/127.0.0.1:32024_hh_ov%2Fxj [junit4:junit4] 2> 7028 T2538 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13baae40d0d000a type:del= ete cxid:0x4 zxid:0x86 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/1= 27.0.0.1:32024_hh_ov%2Fxj Error:KeeperErrorCode =3D NoNode for /solr/live_n= odes/127.0.0.1:32024_hh_ov%2Fxj [junit4:junit4] 2> 7029 T2533 oascc.SolrZkClient.makePath makePath: /live= _nodes/127.0.0.1:32024_hh_ov%2Fxj [junit4:junit4] 2> 7032 T2561 oascc.ZkStateReader$3.process Updating live= nodes... (4) [junit4:junit4] 2> 7032 T2555 oascc.ZkStateReader$3.process Updating live= nodes... (4) [junit4:junit4] 2> 7032 T2574 oascc.ZkStateReader$3.process Updating live= nodes... (4) [junit4:junit4] 2> 7032 T2589 oascc.ZkStateReader$3.process Updating live= nodes... (4) [junit4:junit4] 2> 7032 T2555 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/= live_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 7032 T2561 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/= live_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 7032 T2589 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/= live_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 7032 T2574 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/= live_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 7040 T2533 oascc.ZkStateReader.createClusterStateWatch= ersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 7047 T2607 oasc.CoreContainer.create Creating SolrCore= 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.c= loud.SyncSliceTest-jetty3-1355781777289/collection1 [junit4:junit4] 2> 7047 T2607 oasc.ZkController.createCollectionZkNode Ch= eck for collection zkNode:collection1 [junit4:junit4] 2> 7048 T2607 oasc.ZkController.createCollectionZkNode Co= llection zkNode exists [junit4:junit4] 2> 7048 T2607 oasc.ZkController.readConfigName Load colle= ction config from:/collections/collection1 [junit4:junit4] 2> 7050 T2607 oasc.SolrResourceLoader. new SolrReso= urceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-S= olr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Sy= ncSliceTest-jetty3-1355781777289/collection1/' [junit4:junit4] 2> 7051 T2607 oasc.SolrResourceLoader.replaceClassLoader = Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-= java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jett= y3-1355781777289/collection1/lib/classes/' to classloader [junit4:junit4] 2> 7051 T2607 oasc.SolrResourceLoader.replaceClassLoader = Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-= java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jett= y3-1355781777289/collection1/lib/README' to classloader [junit4:junit4] 2> 7100 T2607 oasc.SolrConfig. Using Lucene MatchVe= rsion: LUCENE_41 [junit4:junit4] 2> 7168 T2607 oasc.SolrConfig. Loaded SolrConfig: s= olrconfig.xml [junit4:junit4] 2> 7269 T2607 oass.IndexSchema.readSchema Reading Solr Sc= hema [junit4:junit4] 2> 7275 T2607 oass.IndexSchema.readSchema Schema name=3Dt= est [junit4:junit4] 2> 7890 T2607 oass.OpenExchangeRatesOrgProvider.init Init= ialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 7902 T2607 oass.IndexSchema.readSchema default search = field in schema is text [junit4:junit4] 2> 7906 T2607 oass.IndexSchema.readSchema unique key fiel= d: id [junit4:junit4] 2> 7919 T2607 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 7924 T2607 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 7928 T2607 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 7930 T2607 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 7931 T2607 oasc.SolrCore. [collection1] Opening = new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4= .x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest= -jetty3-1355781777289/collection1/, dataDir=3D./org.apache.solr.cloud.SyncS= liceTest-1355781770504/jetty3/ [junit4:junit4] 2> 7931 T2607 oasc.JmxMonitoredMap. JMX monitoring = is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMB= eanServer@1afa578a [junit4:junit4] 2> 7932 T2607 oasc.SolrCore.initDirectoryFactory solr.NRT= CachingDirectoryFactory [junit4:junit4] 2> 7933 T2607 oasc.CachingDirectoryFactory.get return new= directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.= x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-= 1355781770504/jetty3 forceNew:false [junit4:junit4] 2> 7933 T2607 oasc.CachingDirectoryFactory.close Releasin= g directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-j= ava7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-135= 5781770504/jetty3 [junit4:junit4] 2> 7934 T2607 oasc.SolrCore.getNewIndexDir New index dire= ctory detected: old=3Dnull new=3D./org.apache.solr.cloud.SyncSliceTest-1355= 781770504/jetty3/index/ [junit4:junit4] 2> 7934 T2607 oasc.SolrCore.initIndex WARNING [collection= 1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-135578177050= 4/jetty3/index' doesn't exist. Creating new index... [junit4:junit4] 2> 7935 T2607 oasc.CachingDirectoryFactory.get return new= directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.= x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-= 1355781770504/jetty3/index forceNew:false [junit4:junit4] 2> 7969 T2607 oasc.SolrDeletionPolicy.onCommit SolrDeleti= onPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/o= rg.apache.solr.cloud.SyncSliceTest-1355781770504/jetty3/index lockFactory= =3Dorg.apache.lucene.store.NativeFSLockFactory@5c2ed547; maxCacheMB=3D48.0 = maxMergeSizeMB=3D4.0)),segFN=3Dsegments_1,generation=3D1,filenames=3D[segme= nts_1] [junit4:junit4] 2> 7970 T2607 oasc.SolrDeletionPolicy.updateCommits newes= t commit =3D 1[segments_1] [junit4:junit4] 2> 7971 T2607 oasc.CachingDirectoryFactory.close Releasin= g directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-j= ava7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-135= 5781770504/jetty3/index [junit4:junit4] 2> 7971 T2607 oasc.SolrCore.initWriters created xml: solr= .XMLResponseWriter [junit4:junit4] 2> 7973 T2607 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe" [junit4:junit4] 2> 7973 T2607 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe-allfields" [junit4:junit4] 2> 7974 T2607 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "s= tored_sig" [junit4:junit4] 2> 7974 T2607 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "u= niq-fields" [junit4:junit4] 2> 7975 T2607 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= istrib-dup-test-chain-implicit" [junit4:junit4] 2> 7975 T2607 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 7976 T2607 oasc.RequestHandlers.initHandlersFromConfig= created /replication: solr.ReplicationHandler [junit4:junit4] 2> 7977 T2607 oasc.RequestHandlers.initHandlersFromConfig= created standard: solr.StandardRequestHandler [junit4:junit4] 2> 7978 T2607 oasc.RequestHandlers.initHandlersFromConfig= created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 8000 T2607 oasc.RequestHandlers.initHandlersFromConfig= created dismax: solr.SearchHandler [junit4:junit4] 2> 8001 T2607 oasc.RequestHandlers.initHandlersFromConfig= created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler [junit4:junit4] 2> 8001 T2607 oasc.RequestHandlers.initHandlersFromConfig= created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 8002 T2607 oasc.RequestHandlers.initHandlersFromConfig= created defaults: solr.StandardRequestHandler [junit4:junit4] 2> 8003 T2607 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.StandardRequestHandler [junit4:junit4] 2> 8003 T2607 oasc.RequestHandlers.initHandlersFromConfig= created lazy: solr.StandardRequestHandler [junit4:junit4] 2> 8004 T2607 oasc.RequestHandlers.initHandlersFromConfig= created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 8005 T2607 oasc.RequestHandlers.initHandlersFromConfig= created /terms: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 8006 T2607 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 8007 T2607 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchH= andler [junit4:junit4] 2> 8008 T2607 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchH= andler [junit4:junit4] 2> 8008 T2607 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.= SearchHandler [junit4:junit4] 2> 8009 T2607 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 8010 T2607 oasc.RequestHandlers.initHandlersFromConfig= created mltrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 8011 T2607 oasc.RequestHandlers.initHandlersFromConfig= created tvrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 8012 T2607 oasc.RequestHandlers.initHandlersFromConfig= created /mlt: solr.MoreLikeThisHandler [junit4:junit4] 2> 8013 T2607 oasc.RequestHandlers.initHandlersFromConfig= created /debug/dump: solr.DumpRequestHandler [junit4:junit4] 2> 8026 T2607 oashl.XMLLoader.init xsltCacheLifetimeSecon= ds=3D60 [junit4:junit4] 2> 8031 T2607 oasc.SolrCore.initDeprecatedSupport WARNING= solrconfig.xml uses deprecated , Please update your c= onfig to use the ShowFileRequestHandler. [junit4:junit4] 2> 8032 T2607 oasc.SolrCore.initDeprecatedSupport WARNING= adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS= .TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT,= CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT] [junit4:junit4] 2> 8035 T2607 oasc.CachingDirectoryFactory.close Releasin= g directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-j= ava7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-135= 5781770504/jetty3 [junit4:junit4] 2> 8037 T2607 oass.SolrIndexSearcher. Opening Searc= her@4eaad417 main [junit4:junit4] 2> 8038 T2607 oasu.CommitTracker. Hard AutoCommit: = disabled [junit4:junit4] 2> 8038 T2607 oasu.CommitTracker. Soft AutoCommit: = disabled [junit4:junit4] 2> 8039 T2607 oashc.SpellCheckComponent.inform Initializi= ng spell checkers [junit4:junit4] 2> 8046 T2607 oass.DirectSolrSpellChecker.init init: {nam= e=3Ddirect,classname=3DDirectSolrSpellChecker,field=3Dlowerfilt,minQueryLen= gth=3D3} [junit4:junit4] 2> 8112 T2608 oasc.SolrCore.registerSearcher [collection1= ] Registered new searcher Searcher@4eaad417 main{StandardDirectoryReader(se= gments_1:1)} [junit4:junit4] 2> 8116 T2607 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Ddown [junit4:junit4] 2> 8116 T2607 oasc.ZkController.publish numShards not fou= nd on descriptor - reading it from system property [junit4:junit4] 2> 8507 T2556 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 8508 T2556 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "shard":null, [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"down", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:32024_hh_ov%2Fxj", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:32024/hh_ov/xj"} [junit4:junit4] 2> 8509 T2556 oasc.Overseer$ClusterStateUpdater.updateSta= te Collection already exists with numShards=3D1 [junit4:junit4] 2> 8509 T2556 oasc.Overseer$ClusterStateUpdater.updateSta= te Assigning new node to shard shard=3Dshard1 [junit4:junit4] 2> 8525 T2574 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 8525 T2589 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 8525 T2606 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 8525 T2561 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 8525 T2555 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 8619 T2607 oasc.CoreContainer.registerCore registering= core: collection1 [junit4:junit4] 2> 8619 T2607 oasc.ZkController.register Register shard -= core:collection1 address:http://127.0.0.1:32024/hh_ov/xj shardId:shard1 [junit4:junit4] 2> 8622 T2607 oasc.ZkController.register We are http://12= 7.0.0.1:32024/hh_ov/xj/collection1/ and leader is http://127.0.0.1:32013/hh= _ov/xj/collection1/ [junit4:junit4] 2> 8622 T2607 oasc.ZkController.register No LogReplay nee= ded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:32024/hh_ov/xj [junit4:junit4] 2> 8623 T2607 oasc.ZkController.checkRecovery Core needs = to recover:collection1 [junit4:junit4] 2> 8623 T2607 oasu.DefaultSolrCoreState.doRecovery Runnin= g recovery - first canceling any ongoing recovery [junit4:junit4] 2> ASYNC NEW_CORE C160 name=3Dcollection1 org.apache.sol= r.core.SolrCore@3b11331 url=3Dhttp://127.0.0.1:32024/hh_ov/xj/collection1 n= ode=3D127.0.0.1:32024_hh_ov%2Fxj [junit4:junit4] 2> 8623 T2609 C160 P32024 oasc.RecoveryStrategy.run Start= ing recovery process. core=3Dcollection1 recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 8624 T2607 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 8624 T2609 C160 P32024 oasc.RecoveryStrategy.doRecover= y ###### startupVersions=3D[] [junit4:junit4] 2> 8624 T2609 C160 P32024 oasc.ZkController.publish publi= shing core=3Dcollection1 state=3Drecovering [junit4:junit4] 2> 8625 T2609 C160 P32024 oasc.ZkController.publish numSh= ards not found on descriptor - reading it from system property [junit4:junit4] 2> 8625 T2533 oass.SolrDispatchFilter.init user.dir=3D/us= r/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build= /solr-core/test/J1 [junit4:junit4] 2> 8626 T2533 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() done [junit4:junit4] 2> 8626 T2609 C160 P32024 oasc.RecoveryStrategy.doRecover= y Attempting to PeerSync from http://127.0.0.1:32013/hh_ov/xj/collection1/ = core=3Dcollection1 - recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 8627 T2609 C160 P32024 oasu.PeerSync.sync PeerSync: co= re=3Dcollection1 url=3Dhttp://127.0.0.1:32024/hh_ov/xj START replicas=3D[ht= tp://127.0.0.1:32013/hh_ov/xj/collection1/] nUpdates=3D100 [junit4:junit4] 2> 8627 T2533 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&fo= llowRedirects=3Dfalse [junit4:junit4] 2> 8627 T2609 C160 P32024 oasu.PeerSync.sync WARNING no f= rame of reference to tell of we've missed updates [junit4:junit4] 2> 8627 T2609 C160 P32024 oasc.RecoveryStrategy.doRecover= y PeerSync Recovery was not successful - trying replication. core=3Dcollect= ion1 [junit4:junit4] 2> 8628 T2609 C160 P32024 oasc.RecoveryStrategy.doRecover= y Starting Replication Recovery. core=3Dcollection1 [junit4:junit4] 2> 8628 T2609 C160 P32024 oascsi.HttpClientUtil.createCli= ent Creating new http client, config:maxConnections=3D128&maxConnectionsPer= Host=3D32&followRedirects=3Dfalse [junit4:junit4] 2> 8629 T2564 C159 P32013 REQ /get {distrib=3Dfalse&qt=3D= /get&wt=3Djavabin&version=3D2&getVersions=3D100} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 8810 T2533 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 8813 T2533 oejs.AbstractConnector.doStart Started Sock= etConnector@127.0.0.1:32029 [junit4:junit4] 2> 8814 T2533 oasc.SolrResourceLoader.locateSolrHome JNDI= not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 8815 T2533 oasc.SolrResourceLoader.locateSolrHome usin= g system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.c= loud.SyncSliceTest-jetty4-1355781779145 [junit4:junit4] 2> 8816 T2533 oasc.SolrResourceLoader. new SolrReso= urceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/= Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.= cloud.SyncSliceTest-jetty4-1355781779145/' [junit4:junit4] 2> 8857 T2533 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() [junit4:junit4] 2> 8858 T2533 oasc.SolrResourceLoader.locateSolrHome JNDI= not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 8859 T2533 oasc.SolrResourceLoader.locateSolrHome usin= g system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.c= loud.SyncSliceTest-jetty4-1355781779145 [junit4:junit4] 2> 8859 T2533 oasc.CoreContainer$Initializer.initialize l= ooking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSlic= eTest-jetty4-1355781779145/solr.xml [junit4:junit4] 2> 8860 T2533 oasc.CoreContainer. New CoreContainer= 2095860063 [junit4:junit4] 2> 8860 T2533 oasc.CoreContainer.load Loading CoreContain= er using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSlic= eTest-jetty4-1355781779145/' [junit4:junit4] 2> 8861 T2533 oasc.SolrResourceLoader. new SolrReso= urceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-S= olr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Sy= ncSliceTest-jetty4-1355781779145/' [junit4:junit4] 2> 8891 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting socketTimeout to: 30000 [junit4:junit4] 2> 8892 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting urlScheme to: http:// [junit4:junit4] 2> 8893 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting connTimeout to: 15000 [junit4:junit4] 2> 8894 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 8894 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting corePoolSize to: 0 [junit4:junit4] 2> 8895 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 8895 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting maxThreadIdleTime to: 5 [junit4:junit4] 2> 8896 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting sizeOfQueue to: -1 [junit4:junit4] 2> 8897 T2533 oashc.HttpShardHandlerFactory.getParameter = Setting fairnessPolicy to: false [junit4:junit4] 2> 8897 T2533 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000&= socketTimeout=3D30000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 8919 T2533 oasc.CoreContainer.load Registering Log Lis= tener [junit4:junit4] 2> 8940 T2533 oasc.CoreContainer.initZooKeeper Zookeeper = client=3D127.0.0.1:32005/solr [junit4:junit4] 2> 8941 T2533 oasc.ZkController.checkChrootPath zkHost in= cludes chroot [junit4:junit4] 2> 8941 T2533 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:32005 sessionTimeout=3D60000 watcher=3Dor= g.apache.solr.common.cloud.ConnectionManager@4cc2f00 [junit4:junit4] 2> 8942 T2533 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 8943 T2620 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost/127.0.0.1:32005. Will not atte= mpt to authenticate using SASL (access denied ("javax.security.auth.AuthPer= mission" "getLoginConfiguration")) [junit4:junit4] 2> 8944 T2620 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost/127.0.0.1:32005, initiating sessi= on [junit4:junit4] 2> 8944 T2535 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /140.211.11.196:32030 [junit4:junit4] 2> 8944 T2535 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /140.211.11.196:32030 [junit4:junit4] 2> 8946 T2537 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13baae40d0d000b with negotiated timeout 20000 for client = /140.211.11.196:32030 [junit4:junit4] 2> 8946 T2620 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost/127.0.0.1:32005, sessionid = =3D 0x13baae40d0d000b, negotiated timeout =3D 20000 [junit4:junit4] 2> 8947 T2621 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@4cc2f00 name:ZooKeeperConnectio= n Watcher:127.0.0.1:32005 got event WatchedEvent state:SyncConnected type:N= one path:null path:null type:None [junit4:junit4] 2> 8947 T2533 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 8948 T2538 oazs.PrepRequestProcessor.pRequest2Txn Proc= essed session termination for sessionid: 0x13baae40d0d000b [junit4:junit4] 2> 8966 T2621 oaz.ClientCnxn$EventThread.run EventThread = shut down [junit4:junit4] 2> 8966 T2535 oazs.NIOServerCnxn.closeSock Closed socket = connection for client /140.211.11.196:32030 which had sessionid 0x13baae40d= 0d000b [junit4:junit4] 2> 8966 T2533 oaz.ZooKeeper.close Session: 0x13baae40d0d0= 00b closed [junit4:junit4] 2> 8966 T2533 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&so= cketTimeout=3D15000&connTimeout=3D30000 [junit4:junit4] 2> 8978 T2533 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:32005/solr sessionTimeout=3D30000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@42a21c77 [junit4:junit4] 2> 8980 T2533 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 8980 T2622 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost/127.0.0.1:32005. Will not atte= mpt to authenticate using SASL (access denied ("javax.security.auth.AuthPer= mission" "getLoginConfiguration")) [junit4:junit4] 2> 8981 T2622 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost/127.0.0.1:32005, initiating sessi= on [junit4:junit4] 2> 8981 T2535 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /140.211.11.196:32032 [junit4:junit4] 2> 8981 T2535 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /140.211.11.196:32032 [junit4:junit4] 2> 8983 T2537 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13baae40d0d000c with negotiated timeout 20000 for client = /140.211.11.196:32032 [junit4:junit4] 2> 8983 T2622 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost/127.0.0.1:32005, sessionid = =3D 0x13baae40d0d000c, negotiated timeout =3D 20000 [junit4:junit4] 2> 8983 T2623 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@42a21c77 name:ZooKeeperConnecti= on Watcher:127.0.0.1:32005/solr got event WatchedEvent state:SyncConnected = type:None path:null path:null type:None [junit4:junit4] 2> 8984 T2533 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 8984 T2538 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13baae40d0d000c type:cre= ate cxid:0x1 zxid:0x93 txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 8986 T2538 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13baae40d0d000c type:cre= ate cxid:0x2 zxid:0x94 txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 8987 T2533 oasc.ZkController.createEphemeralLiveNode R= egister node as live in ZooKeeper:/live_nodes/127.0.0.1:32029_hh_ov%2Fxj [junit4:junit4] 2> 8988 T2538 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13baae40d0d000c type:del= ete cxid:0x4 zxid:0x95 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/1= 27.0.0.1:32029_hh_ov%2Fxj Error:KeeperErrorCode =3D NoNode for /solr/live_n= odes/127.0.0.1:32029_hh_ov%2Fxj [junit4:junit4] 2> 8990 T2533 oascc.SolrZkClient.makePath makePath: /live= _nodes/127.0.0.1:32029_hh_ov%2Fxj [junit4:junit4] 2> 8998 T2606 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/= live_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 8998 T2561 oascc.ZkStateReader$3.process Updating live= nodes... (5) [junit4:junit4] 2> 8998 T2574 oascc.ZkStateReader$3.process Updating live= nodes... (5) [junit4:junit4] 2> 8998 T2555 oascc.ZkStateReader$3.process Updating live= nodes... (5) [junit4:junit4] 2> 8998 T2589 oascc.ZkStateReader$3.process Updating live= nodes... (5) [junit4:junit4] 2> 8999 T2574 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/= live_nodes, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 8998 T2561 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/= live_nodes, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 8999 T2589 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/= live_nodes, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 8999 T2555 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/= live_nodes, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 9000 T2606 oascc.ZkStateReader$3.process Updating live= nodes... (5) [junit4:junit4] 2> 9002 T2533 oascc.ZkStateReader.createClusterStateWatch= ersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 9010 T2624 oasc.CoreContainer.create Creating SolrCore= 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.c= loud.SyncSliceTest-jetty4-1355781779145/collection1 [junit4:junit4] 2> 9010 T2624 oasc.ZkController.createCollectionZkNode Ch= eck for collection zkNode:collection1 [junit4:junit4] 2> 9011 T2624 oasc.ZkController.createCollectionZkNode Co= llection zkNode exists [junit4:junit4] 2> 9011 T2624 oasc.ZkController.readConfigName Load colle= ction config from:/collections/collection1 [junit4:junit4] 2> 9013 T2624 oasc.SolrResourceLoader. new SolrReso= urceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-S= olr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Sy= ncSliceTest-jetty4-1355781779145/collection1/' [junit4:junit4] 2> 9014 T2624 oasc.SolrResourceLoader.replaceClassLoader = Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-= java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jett= y4-1355781779145/collection1/lib/README' to classloader [junit4:junit4] 2> 9015 T2624 oasc.SolrResourceLoader.replaceClassLoader = Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-= java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jett= y4-1355781779145/collection1/lib/classes/' to classloader [junit4:junit4] 2> 9030 T2556 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 9031 T2556 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "shard":"shard1", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"recovering", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:32024_hh_ov%2Fxj", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:32024/hh_ov/xj"} [junit4:junit4] 2> 9044 T2574 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 9044 T2606 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 9044 T2561 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 9044 T2555 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 9044 T2623 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 9044 T2589 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 9070 T2624 oasc.SolrConfig. Using Lucene MatchVe= rsion: LUCENE_41 [junit4:junit4] 2> 9142 T2624 oasc.SolrConfig. Loaded SolrConfig: s= olrconfig.xml [junit4:junit4] 2> 9243 T2624 oass.IndexSchema.readSchema Reading Solr Sc= hema [junit4:junit4] 2> 9250 T2624 oass.IndexSchema.readSchema Schema name=3Dt= est [junit4:junit4] 2> C158_STATE=3Dcoll:collection1 core:collection1 props:= {shard=3Dshard1, roles=3Dnull, state=3Drecovering, core=3Dcollection1, coll= ection=3Dcollection1, node_name=3D127.0.0.1:32019_hh_ov%2Fxj, base_url=3Dht= tp://127.0.0.1:32019/hh_ov/xj} [junit4:junit4] 2> 9802 T2592 C158 P32019 oasc.RecoveryStrategy.doRecover= y Begin buffering updates. core=3Dcollection1 [junit4:junit4] 2> 9802 T2592 C158 P32019 oasu.UpdateLog.bufferUpdates St= arting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog=3Dnull} [junit4:junit4] 2> 9802 T2592 C158 P32019 oasc.RecoveryStrategy.replicate= Attempting to replicate from http://127.0.0.1:32013/hh_ov/xj/collection1/.= core=3Dcollection1 [junit4:junit4] 2> 9802 T2592 C158 P32019 oascsi.HttpClientUtil.createCli= ent Creating new http client, config:maxConnections=3D128&maxConnectionsPer= Host=3D32&followRedirects=3Dfalse [junit4:junit4] 2> 9810 T2567 C159 P32013 oasu.DirectUpdateHandler2.commi= t start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dfals= e,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 9813 T2567 C159 P32013 oasc.CachingDirectoryFactory.cl= ose Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr= -Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncS= liceTest-1355781770504/jetty1 [junit4:junit4] 2> 9819 T2567 C159 P32013 oasc.SolrDeletionPolicy.onInit = SolrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/o= rg.apache.solr.cloud.SyncSliceTest-1355781770504/jetty1/index lockFactory= =3Dorg.apache.lucene.store.NativeFSLockFactory@59130c74; maxCacheMB=3D48.0 = maxMergeSizeMB=3D4.0)),segFN=3Dsegments_1,generation=3D1,filenames=3D[segme= nts_1] [junit4:junit4] 2> 9821 T2567 C159 P32013 oasc.SolrDeletionPolicy.updateC= ommits newest commit =3D 1[segments_1] [junit4:junit4] 2> 9852 T2567 C159 P32013 oasc.SolrDeletionPolicy.onCommi= t SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/o= rg.apache.solr.cloud.SyncSliceTest-1355781770504/jetty1/index lockFactory= =3Dorg.apache.lucene.store.NativeFSLockFactory@59130c74; maxCacheMB=3D48.0 = maxMergeSizeMB=3D4.0)),segFN=3Dsegments_1,generation=3D1,filenames=3D[segme= nts_1] [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/o= rg.apache.solr.cloud.SyncSliceTest-1355781770504/jetty1/index lockFactory= =3Dorg.apache.lucene.store.NativeFSLockFactory@59130c74; maxCacheMB=3D48.0 = maxMergeSizeMB=3D4.0)),segFN=3Dsegments_2,generation=3D2,filenames=3D[segme= nts_2] [junit4:junit4] 2> 9853 T2567 C159 P32013 oasc.SolrDeletionPolicy.updateC= ommits newest commit =3D 2[segments_2] [junit4:junit4] 2> 9855 T2567 C159 P32013 oasc.CachingDirectoryFactory.cl= ose Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr= -Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncS= liceTest-1355781770504/jetty1 [junit4:junit4] 2> 9856 T2567 C159 P32013 oass.SolrIndexSearcher. O= pening Searcher@76dedcad realtime [junit4:junit4] 2> 9857 T2567 C159 P32013 oasu.DirectUpdateHandler2.commi= t end_commit_flush [junit4:junit4] 2> 9857 T2567 C159 P32013 /update {waitSearcher=3Dtrue&op= enSearcher=3Dfalse&commit=3Dtrue&commit_end_point=3Dtrue&wt=3Djavabin&softC= ommit=3Dfalse&version=3D2} {commit=3D} 0 47 [junit4:junit4] 2> 9859 T2592 C158 P32019 oash.ReplicationHandler.inform = Commits will be reserved for 10000 [junit4:junit4] 2> 9859 T2592 C158 P32019 oash.SnapPuller. No valu= e set for 'pollInterval'. Timer Task not started. [junit4:junit4] 2> 9862 T2568 C159 P32013 oash.ReplicationHandler.inform = Commits will be reserved for 10000 [junit4:junit4] 2> 9863 T2568 C159 P32013 REQ /replication {command=3Dind= exversion&wt=3Djavabin&qt=3D/replication&version=3D2} status=3D0 QTime=3D3= =20 [junit4:junit4] 2> 9864 T2592 C158 P32019 oash.SnapPuller.fetchLatestInde= x Master's generation: 2 [junit4:junit4] 2> 9864 T2592 C158 P32019 oash.SnapPuller.fetchLatestInde= x Slave's generation: 1 [junit4:junit4] 2> 9864 T2592 C158 P32019 oash.SnapPuller.fetchLatestInde= x Starting replication process [junit4:junit4] 2> 9866 T2568 C159 P32013 oasc.CachingDirectoryFactory.cl= ose Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr= -Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncS= liceTest-1355781770504/jetty1 [junit4:junit4] 2> 9867 T2568 C159 P32013 oasc.CachingDirectoryFactory.cl= ose Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr= -Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncS= liceTest-1355781770504/jetty1/index [junit4:junit4] 2> 9868 T2568 C159 P32013 REQ /replication {command=3Dfil= elist&generation=3D2&wt=3Djavabin&qt=3D/replication&version=3D2} status=3D0= QTime=3D2=20 [junit4:junit4] 2> 9868 T2592 C158 P32019 oash.SnapPuller.fetchLatestInde= x Number of files in latest index in master: 1 [junit4:junit4] 2> 9869 T2592 C158 P32019 oasc.CachingDirectoryFactory.ge= t return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-S= olr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Sy= ncSliceTest-1355781770504/jetty2/index.20121217160300369 forceNew:false [junit4:junit4] 2> 9870 T2592 C158 P32019 oasc.CachingDirectoryFactory.cl= ose Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr= -Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncS= liceTest-1355781770504/jetty2 [junit4:junit4] 2> 9871 T2592 C158 P32019 oash.SnapPuller.fetchLatestInde= x Starting download to RateLimitedDirectoryWrapper(NRTCachingDirectory(org.= apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/= Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cl= oud.SyncSliceTest-1355781770504/jetty2/index.20121217160300369 lockFactory= =3Dorg.apache.lucene.store.NativeFSLockFactory@360ad7ac; maxCacheMB=3D48.0 = maxMergeSizeMB=3D4.0)) fullCopy=3Dtrue [junit4:junit4] 2> 9874 T2568 C159 P32013 REQ /replication {file=3Dsegmen= ts_2&command=3Dfilecontent&checksum=3Dtrue&generation=3D2&qt=3D/replication= &wt=3Dfilestream} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 9876 T2592 C158 P32019 oasc.CachingDirectoryFactory.cl= ose Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr= -Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncS= liceTest-1355781770504/jetty2/index [junit4:junit4] 2> 9876 T2592 C158 P32019 oash.SnapPuller.fetchLatestInde= x Total time taken for download : 0 secs [junit4:junit4] 2> 9876 T2592 C158 P32019 oash.SnapPuller.modifyIndexProp= s New index installed. Updating index properties... index=3Dindex.201212171= 60300369 [junit4:junit4] 2> 9878 T2592 C158 P32019 oasc.CachingDirectoryFactory.cl= ose Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr= -Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncS= liceTest-1355781770504/jetty2 [junit4:junit4] 2> 9878 T2592 C158 P32019 oasc.CachingDirectoryFactory.cl= ose Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr= -Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncS= liceTest-1355781770504/jetty2 [junit4:junit4] 2> 9878 T2592 C158 P32019 oasc.SolrCore.getNewIndexDir Ne= w index directory detected: old=3D./org.apache.solr.cloud.SyncSliceTest-135= 5781770504/jetty2/index/ new=3D./org.apache.solr.cloud.SyncSliceTest-135578= 1770504/jetty2/index.20121217160300369 [junit4:junit4] 2> 9881 T2592 C158 P32019 oasc.SolrDeletionPolicy.onInit = SolrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/o= rg.apache.solr.cloud.SyncSliceTest-1355781770504/jetty2/index.2012121716030= 0369 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@360ad7ac; ma= xCacheMB=3D48.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_2,generation=3D2,fi= lenames=3D[segments_2] [junit4:junit4] 2> 9883 T2592 C158 P32019 oasc.SolrDeletionPolicy.updateC= ommits newest commit =3D 2[segments_2] [junit4:junit4] 2> 9884 T2592 C158 P32019 oasc.CachingDirectoryFactory.cl= ose Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr= -Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncS= liceTest-1355781770504/jetty2 [junit4:junit4] 2> 9884 T2592 C158 P32019 oasu.DefaultSolrCoreState.newIn= dexWriter Creating new IndexWriter... [junit4:junit4] 2> 9884 T2592 C158 P32019 oasu.DefaultSolrCoreState.newIn= dexWriter Waiting until IndexWriter is unused... core=3Dcollection1 [junit4:junit4] 2> 9884 T2592 C158 P32019 oasu.DefaultSolrCoreState.newIn= dexWriter Rollback old IndexWriter... core=3Dcollection1 [junit4:junit4] 2> 9905 T2592 C158 P32019 oasc.CachingDirectoryFactory.cl= ose Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr= -Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncS= liceTest-1355781770504/jetty2/index.20121217160300369 [junit4:junit4] 2> 9906 T2592 C158 P32019 oasc.CachingDirectoryFactory.cl= ose Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr= -Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncS= liceTest-1355781770504/jetty2 [junit4:junit4] 2> 9909 T2592 C158 P32019 oasc.SolrDeletionPolicy.onInit = SolrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/o= rg.apache.solr.cloud.SyncSliceTest-1355781770504/jetty2/index.2012121716030= 0369 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@360ad7ac; ma= xCacheMB=3D48.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_2,generation=3D2,fi= lenames=3D[segments_2] [junit4:junit4] 2> 9909 T2592 C158 P32019 oasc.SolrDeletionPolicy.updateC= ommits newest commit =3D 2[segments_2] [junit4:junit4] 2> 9909 T2592 C158 P32019 oasu.DefaultSolrCoreState.newIn= dexWriter New IndexWriter is ready to be used. [junit4:junit4] 2> 9909 T2592 C158 P32019 oasc.CachingDirectoryFactory.cl= ose Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr= -Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncS= liceTest-1355781770504/jetty2 [junit4:junit4] 2> 9910 T2592 C158 P32019 oass.SolrIndexSearcher. O= pening Searcher@5dae3bf7 main [junit4:junit4] 2> 9912 T2591 oasc.SolrCore.registerSearcher [collection1= ] Registered new searcher Searcher@5dae3bf7 main{StandardDirectoryReader(se= gments_2:1:nrt)} [junit4:junit4] 2> 9912 T2591 oasc.CachingDirectoryFactory.close Releasin= g directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-j= ava7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-135= 5781770504/jetty2/index [junit4:junit4] 2> 9913 T2592 C158 P32019 oasu.DirectUpdateHandler2.commi= t start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dfals= e,waitSearcher=3Dfalse,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 9916 T2592 C158 P32019 oasc.SolrDeletionPolicy.onCommi= t SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/o= rg.apache.solr.cloud.SyncSliceTest-1355781770504/jetty2/index.2012121716030= 0369 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@360ad7ac; ma= xCacheMB=3D48.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_2,generation=3D2,fi= lenames=3D[segments_2] [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/o= rg.apache.solr.cloud.SyncSliceTest-1355781770504/jetty2/index.2012121716030= 0369 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@360ad7ac; ma= xCacheMB=3D48.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_3,generation=3D3,fi= lenames=3D[segments_3] [junit4:junit4] 2> 9916 T2592 C158 P32019 oasc.SolrDeletionPolicy.updateC= ommits newest commit =3D 3[segments_3] [junit4:junit4] 2> 9917 T2592 C158 P32019 oasc.CachingDirectoryFactory.cl= ose Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr= -Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncS= liceTest-1355781770504/jetty2 [junit4:junit4] 2> 9918 T2592 C158 P32019 oasu.DirectUpdateHandler2.commi= t end_commit_flush [junit4:junit4] 2> 9918 T2592 C158 P32019 oasc.CachingDirectoryFactory.cl= ose Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr= -Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncS= liceTest-1355781770504/jetty2/index.20121217160300369 [junit4:junit4] 2> 9918 T2592 C158 P32019 oasc.CachingDirectoryFactory.cl= ose Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr= -Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncS= liceTest-1355781770504/jetty2/index [junit4:junit4] 2> 9918 T2592 C158 P32019 oasc.RecoveryStrategy.replay No= replay needed. core=3Dcollection1 [junit4:junit4] 2> 9918 T2592 C158 P32019 oasc.RecoveryStrategy.doRecover= y Replication Recovery was successful - registering as Active. core=3Dcolle= ction1 [junit4:junit4] 2> 9918 T2592 C158 P32019 oasc.ZkController.publish publi= shing core=3Dcollection1 state=3Dactive [junit4:junit4] 2> 9919 T2592 C158 P32019 oasc.ZkController.publish numSh= ards not found on descriptor - reading it from system property [junit4:junit4] 2> 9920 T2592 C158 P32019 oasc.RecoveryStrategy.doRecover= y Finished recovery process. core=3Dcollection1 [junit4:junit4] 2> 9923 T2624 oass.OpenExchangeRatesOrgProvider.init Init= ialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 9935 T2624 oass.IndexSchema.readSchema default search = field in schema is text [junit4:junit4] 2> 9939 T2624 oass.IndexSchema.readSchema unique key fiel= d: id [junit4:junit4] 2> 9952 T2624 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 9968 T2624 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 9973 T2624 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 9974 T2624 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 9975 T2624 oasc.SolrCore. [collection1] Opening = new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4= .x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest= -jetty4-1355781779145/collection1/, dataDir=3D./org.apache.solr.cloud.SyncS= liceTest-1355781770504/jetty4/ [junit4:junit4] 2> 9975 T2624 oasc.JmxMonitoredMap. JMX monitoring = is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMB= eanServer@1afa578a [junit4:junit4] 2> 9976 T2624 oasc.SolrCore.initDirectoryFactory solr.NRT= CachingDirectoryFactory [junit4:junit4] 2> 9977 T2624 oasc.CachingDirectoryFactory.get return new= directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.= x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-= 1355781770504/jetty4 forceNew:false [junit4:junit4] 2> 9978 T2624 oasc.CachingDirectoryFactory.close Releasin= g directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-j= ava7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-135= 5781770504/jetty4 [junit4:junit4] 2> 9978 T2624 oasc.SolrCore.getNewIndexDir New index dire= ctory detected: old=3Dnull new=3D./org.apache.solr.cloud.SyncSliceTest-1355= 781770504/jetty4/index/ [junit4:junit4] 2> 9979 T2624 oasc.SolrCore.initIndex WARNING [collection= 1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-135578177050= 4/jetty4/index' doesn't exist. Creating new index... [junit4:junit4] 2> 9979 T2624 oasc.CachingDirectoryFactory.get return new= directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.= x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-= 1355781770504/jetty4/index forceNew:false [junit4:junit4] 2> 9985 T2624 oasc.SolrDeletionPolicy.onCommit SolrDeleti= onPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/o= rg.apache.solr.cloud.SyncSliceTest-1355781770504/jetty4/index lockFactory= =3Dorg.apache.lucene.store.NativeFSLockFactory@5b3490e0; maxCacheMB=3D48.0 = maxMergeSizeMB=3D4.0)),segFN=3Dsegments_1,generation=3D1,filenames=3D[segme= nts_1] [junit4:junit4] 2> 9986 T2624 oasc.SolrDeletionPolicy.updateCommits newes= t commit =3D 1[segments_1] [junit4:junit4] 2> 9987 T2624 oasc.CachingDirectoryFactory.close Releasin= g directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-j= ava7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-135= 5781770504/jetty4/index [junit4:junit4] 2> 9987 T2624 oasc.SolrCore.initWriters created xml: solr= .XMLResponseWriter [junit4:junit4] 2> 9989 T2624 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe" [junit4:junit4] 2> 9989 T2624 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe-allfields" [junit4:junit4] 2> 9990 T2624 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "s= tored_sig" [junit4:junit4] 2> 9990 T2624 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "u= niq-fields" [junit4:junit4] 2> 9991 T2624 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= istrib-dup-test-chain-implicit" [junit4:junit4] 2> 9991 T2624 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 9992 T2624 oasc.RequestHandlers.initHandlersFromConfig= created /replication: solr.ReplicationHandler [junit4:junit4] 2> 9993 T2624 oasc.RequestHandlers.initHandlersFromConfig= created standard: solr.StandardRequestHandler [junit4:junit4] 2> 9994 T2624 oasc.RequestHandlers.initHandlersFromConfig= created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 9995 T2624 oasc.RequestHandlers.initHandlersFromConfig= created dismax: solr.SearchHandler [junit4:junit4] 2> 9996 T2624 oasc.RequestHandlers.initHandlersFromConfig= created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler [junit4:junit4] 2> 9996 T2624 oasc.RequestHandlers.initHandlersFromConfig= created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 9997 T2624 oasc.RequestHandlers.initHandlersFromConfig= created defaults: solr.StandardRequestHandler [junit4:junit4] 2> 9997 T2624 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.StandardRequestHandler [junit4:junit4] 2> 9998 T2624 oasc.RequestHandlers.initHandlersFromConfig= created lazy: solr.StandardRequestHandler [junit4:junit4] 2> 9999 T2624 oasc.RequestHandlers.initHandlersFromConfig= created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 9999 T2624 oasc.RequestHandlers.initHandlersFromConfig= created /terms: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 10000 T2624 oasc.RequestHandlers.initHandlersFromConfi= g created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 10001 T2624 oasc.RequestHandlers.initHandlersFromConfi= g created spellCheckCompRH_Direct: org.apache.solr.handler.component.Search= Handler [junit4:junit4] 2> 10002 T2624 oasc.RequestHandlers.initHandlersFromConfi= g created spellCheckWithWordbreak: org.apache.solr.handler.component.Search= Handler [junit4:junit4] 2> 10003 T2624 oasc.RequestHandlers.initHandlersFromConfi= g created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component= .SearchHandler [junit4:junit4] 2> 10004 T2624 oasc.RequestHandlers.initHandlersFromConfi= g created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandle= r [junit4:junit4] 2> 10005 T2624 oasc.RequestHandlers.initHandlersFromConfi= g created mltrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 10006 T2624 oasc.RequestHandlers.initHandlersFromConfi= g created tvrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 10007 T2624 oasc.RequestHandlers.initHandlersFromConfi= g created /mlt: solr.MoreLikeThisHandler [junit4:junit4] 2> 10008 T2624 oasc.RequestHandlers.initHandlersFromConfi= g created /debug/dump: solr.DumpRequestHandler [junit4:junit4] 2> 10021 T2624 oashl.XMLLoader.init xsltCacheLifetimeSeco= nds=3D60 [junit4:junit4] 2> 10026 T2624 oasc.SolrCore.initDeprecatedSupport WARNIN= G solrconfig.xml uses deprecated , Please update your = config to use the ShowFileRequestHandler. [junit4:junit4] 2> 10027 T2624 oasc.SolrCore.initDeprecatedSupport WARNIN= G adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYM= S.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT= , CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT] [junit4:junit4] 2> 10030 T2624 oasc.CachingDirectoryFactory.close Releasi= ng directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-= java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-13= 55781770504/jetty4 [junit4:junit4] 2> 10032 T2624 oass.SolrIndexSearcher. Opening Sear= cher@40bcad31 main [junit4:junit4] 2> 10033 T2624 oasu.CommitTracker. Hard AutoCommit:= disabled [junit4:junit4] 2> 10033 T2624 oasu.CommitTracker. Soft AutoCommit:= disabled [junit4:junit4] 2> 10034 T2624 oashc.SpellCheckComponent.inform Initializ= ing spell checkers [junit4:junit4] 2> 10040 T2624 oass.DirectSolrSpellChecker.init init: {na= me=3Ddirect,classname=3DDirectSolrSpellChecker,field=3Dlowerfilt,minQueryLe= ngth=3D3} [junit4:junit4] 2> 10052 T2556 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 10053 T2556 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "shard":"shard1", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"active", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:32019_hh_ov%2Fxj", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:32019/hh_ov/xj"} [junit4:junit4] 2> 10078 T2606 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> 10078 T2589 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> 10078 T2561 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> 10078 T2623 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> 10078 T2574 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> 10078 T2555 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> 10102 T2626 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@40bcad31 main{StandardDirectoryReader(s= egments_1:1)} [junit4:junit4] 2> 10107 T2624 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Ddown [junit4:junit4] 2> 10107 T2624 oasc.ZkController.publish numShards not fo= und on descriptor - reading it from system property [junit4:junit4] 2> 10582 T2556 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 10583 T2556 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "shard":null, [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"down", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:32029_hh_ov%2Fxj", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:32029/hh_ov/xj"} [junit4:junit4] 2> 10584 T2556 oasc.Overseer$ClusterStateUpdater.updateSt= ate Collection already exists with numShards=3D1 [junit4:junit4] 2> 10584 T2556 oasc.Overseer$ClusterStateUpdater.updateSt= ate Assigning new node to shard shard=3Dshard1 [junit4:junit4] 2> 10631 T2561 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> 10631 T2555 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> 10631 T2574 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> 10631 T2606 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> 10631 T2589 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> 10632 T2623 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> 11110 T2624 oasc.CoreContainer.registerCore registerin= g core: collection1 [junit4:junit4] 2> 11110 T2624 oasc.ZkController.register Register shard = - core:collection1 address:http://127.0.0.1:32029/hh_ov/xj shardId:shard1 [junit4:junit4] 2> 11114 T2624 oasc.ZkController.register We are http://1= 27.0.0.1:32029/hh_ov/xj/collection1/ and leader is http://127.0.0.1:32013/h= h_ov/xj/collection1/ [junit4:junit4] 2> 11114 T2624 oasc.ZkController.register No LogReplay ne= eded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:32029/hh_ov/xj [junit4:junit4] 2> 11114 T2624 oasc.ZkController.checkRecovery Core needs= to recover:collection1 [junit4:junit4] 2> 11114 T2624 oasu.DefaultSolrCoreState.doRecovery Runni= ng recovery - first canceling any ongoing recovery [junit4:junit4] 2> ASYNC NEW_CORE C161 name=3Dcollection1 org.apache.sol= r.core.SolrCore@6787f74a url=3Dhttp://127.0.0.1:32029/hh_ov/xj/collection1 = node=3D127.0.0.1:32029_hh_ov%2Fxj [junit4:junit4] 2> 11115 T2627 C161 P32029 oasc.RecoveryStrategy.run Star= ting recovery process. core=3Dcollection1 recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 11115 T2624 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 11116 T2627 C161 P32029 oasc.RecoveryStrategy.doRecove= ry ###### startupVersions=3D[] [junit4:junit4] 2> 11116 T2627 C161 P32029 oasc.ZkController.publish publ= ishing core=3Dcollection1 state=3Drecovering [junit4:junit4] 2> 11116 T2627 C161 P32029 oasc.ZkController.publish numS= hards not found on descriptor - reading it from system property [junit4:junit4] 2> 11116 T2533 oass.SolrDispatchFilter.init user.dir=3D/u= sr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/buil= d/solr-core/test/J1 [junit4:junit4] 2> 11118 T2627 C161 P32029 oasc.RecoveryStrategy.doRecove= ry Attempting to PeerSync from http://127.0.0.1:32013/hh_ov/xj/collection1/= core=3Dcollection1 - recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 11117 T2533 oass.SolrDispatchFilter.init SolrDispatchF= ilter.init() done [junit4:junit4] 2> 11118 T2627 C161 P32029 oasu.PeerSync.sync PeerSync: c= ore=3Dcollection1 url=3Dhttp://127.0.0.1:32029/hh_ov/xj START replicas=3D[h= ttp://127.0.0.1:32013/hh_ov/xj/collection1/] nUpdates=3D100 [junit4:junit4] 2> 11118 T2533 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&f= ollowRedirects=3Dfalse [junit4:junit4] 2> 11119 T2627 C161 P32029 oasu.PeerSync.sync WARNING no = frame of reference to tell of we've missed updates [junit4:junit4] 2> 11119 T2627 C161 P32029 oasc.RecoveryStrategy.doRecove= ry PeerSync Recovery was not successful - trying replication. core=3Dcollec= tion1 [junit4:junit4] 2> 11119 T2627 C161 P32029 oasc.RecoveryStrategy.doRecove= ry Starting Replication Recovery. core=3Dcollection1 [junit4:junit4] 2> 11119 T2627 C161 P32029 oascsi.HttpClientUtil.createCl= ient Creating new http client, config:maxConnections=3D128&maxConnectionsPe= rHost=3D32&followRedirects=3Dfalse [junit4:junit4] 2> 11121 T2564 C159 P32013 REQ /get {distrib=3Dfalse&qt= =3D/get&wt=3Djavabin&version=3D2&getVersions=3D100} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 11136 T2533 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 11137 T2533 oasc.AbstractFullDistribZkTestBase.waitFor= ThingsToLevelOut Wait for recoveries to finish - wait 15 for each attempt [junit4:junit4] 2> 11138 T2533 oasc.AbstractDistribZkTestBase.waitForReco= veriesToFinish Wait for recoveries to finish - collection: collection1 fail= OnTimeout:true timeout (sec):15 [junit4:junit4] 2> 11138 T2533 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 11164 T2556 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 11232 T2556 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "shard":"shard1", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"recovering", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:32029_hh_ov%2Fxj", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:32029/hh_ov/xj"} [junit4:junit4] 2> 11255 T2561 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> 11255 T2589 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> 11255 T2574 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> 11255 T2555 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> 11255 T2606 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> 11255 T2623 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> C160_STATE=3Dcoll:collection1 core:collection1 props:= {shard=3Dshard1, roles=3Dnull, state=3Drecovering, core=3Dcollection1, coll= ection=3Dcollection1, node_name=3D127.0.0.1:32024_hh_ov%2Fxj, base_url=3Dht= tp://127.0.0.1:32024/hh_ov/xj} [junit4:junit4] 2> 11648 T2609 C160 P32024 oasc.RecoveryStrategy.doRecove= ry Begin buffering updates. core=3Dcollection1 [junit4:junit4] 2> 11648 T2609 C160 P32024 oasu.UpdateLog.bufferUpdates S= tarting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog=3Dnull} [junit4:junit4] 2> 11648 T2609 C160 P32024 oasc.RecoveryStrategy.replicat= e Attempting to replicate from http://127.0.0.1:32013/hh_ov/xj/collection1/= . core=3Dcollection1 [junit4:junit4] 2> 11649 T2609 C160 P32024 oascsi.HttpClientUtil.createCl= ient Creating new http client, config:maxConnections=3D128&maxConnectionsPe= rHost=3D32&followRedirects=3Dfalse [junit4:junit4] 2> 11658 T2570 C159 P32013 oasu.DirectUpdateHandler2.comm= it start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dfal= se,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 11663 T2570 C159 P32013 oasc.SolrDeletionPolicy.onComm= it SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/o= rg.apache.solr.cloud.SyncSliceTest-1355781770504/jetty1/index lockFactory= =3Dorg.apache.lucene.store.NativeFSLockFactory@59130c74; maxCacheMB=3D48.0 = maxMergeSizeMB=3D4.0)),segFN=3Dsegments_2,generation=3D2,filenames=3D[segme= nts_2] [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/o= rg.apache.solr.cloud.SyncSliceTest-1355781770504/jetty1/index lockFactory= =3Dorg.apache.lucene.store.NativeFSLockFactory@59130c74; maxCacheMB=3D48.0 = maxMergeSizeMB=3D4.0)),segFN=3Dsegments_3,generation=3D3,filenames=3D[segme= nts_3] [junit4:junit4] 2> 11664 T2570 C159 P32013 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 3[segments_3] [junit4:junit4] 2> 11664 T2570 C159 P32013 oasc.CachingDirectoryFactory.c= lose Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Sync= SliceTest-1355781770504/jetty1 [junit4:junit4] 2> 11665 T2570 C159 P32013 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 11665 T2570 C159 P32013 /update {waitSearcher=3Dtrue&o= penSearcher=3Dfalse&commit=3Dtrue&commit_end_point=3Dtrue&wt=3Djavabin&soft= Commit=3Dfalse&version=3D2} {commit=3D} 0 7 [junit4:junit4] 2> 11666 T2609 C160 P32024 oash.ReplicationHandler.inform= Commits will be reserved for 10000 [junit4:junit4] 2> 11667 T2609 C160 P32024 oash.SnapPuller. No val= ue set for 'pollInterval'. Timer Task not started. [junit4:junit4] 2> 11669 T2568 C159 P32013 REQ /replication {command=3Din= dexversion&wt=3Djavabin&qt=3D/replication&version=3D2} status=3D0 QTime=3D0= =20 [junit4:junit4] 2> 11670 T2609 C160 P32024 oash.SnapPuller.fetchLatestInd= ex Master's generation: 3 [junit4:junit4] 2> 11670 T2609 C160 P32024 oash.SnapPuller.fetchLatestInd= ex Slave's generation: 1 [junit4:junit4] 2> 11671 T2609 C160 P32024 oash.SnapPuller.fetchLatestInd= ex Starting replication process [junit4:junit4] 2> 11673 T2568 C159 P32013 oasc.CachingDirectoryFactory.c= lose Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Sync= SliceTest-1355781770504/jetty1 [junit4:junit4] 2> 11674 T2568 C159 P32013 oasc.CachingDirectoryFactory.c= lose Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Sync= SliceTest-1355781770504/jetty1/index [junit4:junit4] 2> 11674 T2568 C159 P32013 REQ /replication {command=3Dfi= lelist&generation=3D3&wt=3Djavabin&qt=3D/replication&version=3D2} status=3D= 0 QTime=3D1=20 [junit4:junit4] 2> 11675 T2609 C160 P32024 oash.SnapPuller.fetchLatestInd= ex Number of files in latest index in master: 1 [junit4:junit4] 2> 11676 T2609 C160 P32024 oasc.CachingDirectoryFactory.g= et return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-= Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.S= yncSliceTest-1355781770504/jetty3/index.20121217160302176 forceNew:false [junit4:junit4] 2> 11677 T2609 C160 P32024 oasc.CachingDirectoryFactory.c= lose Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Sync= SliceTest-1355781770504/jetty3 [junit4:junit4] 2> 11677 T2609 C160 P32024 oash.SnapPuller.fetchLatestInd= ex Starting download to RateLimitedDirectoryWrapper(NRTCachingDirectory(org= .apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace= /Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.c= loud.SyncSliceTest-1355781770504/jetty3/index.20121217160302176 lockFactory= =3Dorg.apache.lucene.store.NativeFSLockFactory@1665e0f5; maxCacheMB=3D48.0 = maxMergeSizeMB=3D4.0)) fullCopy=3Dtrue [junit4:junit4] 2> 11681 T2568 C159 P32013 REQ /replication {file=3Dsegme= nts_3&command=3Dfilecontent&checksum=3Dtrue&generation=3D3&qt=3D/replicatio= n&wt=3Dfilestream} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 11683 T2609 C160 P32024 oasc.CachingDirectoryFactory.c= lose Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Sync= SliceTest-1355781770504/jetty3/index [junit4:junit4] 2> 11683 T2609 C160 P32024 oash.SnapPuller.fetchLatestInd= ex Total time taken for download : 0 secs [junit4:junit4] 2> 11684 T2609 C160 P32024 oash.SnapPuller.modifyIndexPro= ps New index installed. Updating index properties... index=3Dindex.20121217= 160302176 [junit4:junit4] 2> 11685 T2609 C160 P32024 oasc.CachingDirectoryFactory.c= lose Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Sync= SliceTest-1355781770504/jetty3 [junit4:junit4] 2> 11685 T2609 C160 P32024 oasc.CachingDirectoryFactory.c= lose Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Sync= SliceTest-1355781770504/jetty3 [junit4:junit4] 2> 11686 T2609 C160 P32024 oasc.SolrCore.getNewIndexDir N= ew index directory detected: old=3D./org.apache.solr.cloud.SyncSliceTest-13= 55781770504/jetty3/index/ new=3D./org.apache.solr.cloud.SyncSliceTest-13557= 81770504/jetty3/index.20121217160302176 [junit4:junit4] 2> 11689 T2609 C160 P32024 oasc.SolrDeletionPolicy.onInit= SolrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/o= rg.apache.solr.cloud.SyncSliceTest-1355781770504/jetty3/index.2012121716030= 2176 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@1665e0f5; ma= xCacheMB=3D48.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_3,generation=3D3,fi= lenames=3D[segments_3] [junit4:junit4] 2> 11690 T2609 C160 P32024 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 3[segments_3] [junit4:junit4] 2> 11691 T2609 C160 P32024 oasc.CachingDirectoryFactory.c= lose Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Sync= SliceTest-1355781770504/jetty3 [junit4:junit4] 2> 11691 T2609 C160 P32024 oasu.DefaultSolrCoreState.newI= ndexWriter Creating new IndexWriter... [junit4:junit4] 2> 11692 T2609 C160 P32024 oasu.DefaultSolrCoreState.newI= ndexWriter Waiting until IndexWriter is unused... core=3Dcollection1 [junit4:junit4] 2> 11692 T2609 C160 P32024 oasu.DefaultSolrCoreState.newI= ndexWriter Rollback old IndexWriter... core=3Dcollection1 [junit4:junit4] 2> 11693 T2609 C160 P32024 oasc.CachingDirectoryFactory.c= lose Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Sync= SliceTest-1355781770504/jetty3/index.20121217160302176 [junit4:junit4] 2> 11693 T2609 C160 P32024 oasc.CachingDirectoryFactory.c= lose Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Sync= SliceTest-1355781770504/jetty3 [junit4:junit4] 2> 11697 T2609 C160 P32024 oasc.SolrDeletionPolicy.onInit= SolrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/o= rg.apache.solr.cloud.SyncSliceTest-1355781770504/jetty3/index.2012121716030= 2176 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@1665e0f5; ma= xCacheMB=3D48.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_3,generation=3D3,fi= lenames=3D[segments_3] [junit4:junit4] 2> 11697 T2609 C160 P32024 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 3[segments_3] [junit4:junit4] 2> 11697 T2609 C160 P32024 oasu.DefaultSolrCoreState.newI= ndexWriter New IndexWriter is ready to be used. [junit4:junit4] 2> 11698 T2609 C160 P32024 oasc.CachingDirectoryFactory.c= lose Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Sync= SliceTest-1355781770504/jetty3 [junit4:junit4] 2> 11698 T2609 C160 P32024 oass.SolrIndexSearcher. = Opening Searcher@cc13c52 main [junit4:junit4] 2> 11700 T2608 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@cc13c52 main{StandardDirectoryReader(se= gments_3:1:nrt)} [junit4:junit4] 2> 11700 T2608 oasc.CachingDirectoryFactory.close Releasi= ng directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-= java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-13= 55781770504/jetty3/index [junit4:junit4] 2> 11700 T2609 C160 P32024 oasu.DirectUpdateHandler2.comm= it start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dfal= se,waitSearcher=3Dfalse,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 11704 T2609 C160 P32024 oasc.SolrDeletionPolicy.onComm= it SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/o= rg.apache.solr.cloud.SyncSliceTest-1355781770504/jetty3/index.2012121716030= 2176 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@1665e0f5; ma= xCacheMB=3D48.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_3,generation=3D3,fi= lenames=3D[segments_3] [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/o= rg.apache.solr.cloud.SyncSliceTest-1355781770504/jetty3/index.2012121716030= 2176 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@1665e0f5; ma= xCacheMB=3D48.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_4,generation=3D4,fi= lenames=3D[segments_4] [junit4:junit4] 2> 11704 T2609 C160 P32024 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 4[segments_4] [junit4:junit4] 2> 11706 T2609 C160 P32024 oasc.CachingDirectoryFactory.c= lose Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Sync= SliceTest-1355781770504/jetty3 [junit4:junit4] 2> 11706 T2609 C160 P32024 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 11706 T2609 C160 P32024 oasc.CachingDirectoryFactory.c= lose Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Sync= SliceTest-1355781770504/jetty3/index.20121217160302176 [junit4:junit4] 2> 11707 T2609 C160 P32024 oasc.CachingDirectoryFactory.c= lose Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Sync= SliceTest-1355781770504/jetty3/index [junit4:junit4] 2> 11707 T2609 C160 P32024 oasc.RecoveryStrategy.replay N= o replay needed. core=3Dcollection1 [junit4:junit4] 2> 11707 T2609 C160 P32024 oasc.RecoveryStrategy.doRecove= ry Replication Recovery was successful - registering as Active. core=3Dcoll= ection1 [junit4:junit4] 2> 11707 T2609 C160 P32024 oasc.ZkController.publish publ= ishing core=3Dcollection1 state=3Dactive [junit4:junit4] 2> 11707 T2609 C160 P32024 oasc.ZkController.publish numS= hards not found on descriptor - reading it from system property [junit4:junit4] 2> 11714 T2609 C160 P32024 oasc.RecoveryStrategy.doRecove= ry Finished recovery process. core=3Dcollection1 [junit4:junit4] 2> 11760 T2556 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 11761 T2556 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "shard":"shard1", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"active", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:32024_hh_ov%2Fxj", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:32024/hh_ov/xj"} [junit4:junit4] 2> 11775 T2561 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> 11775 T2623 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> 11775 T2589 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> 11775 T2606 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> 11775 T2574 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> 11775 T2555 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> 12140 T2533 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 13142 T2533 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> C161_STATE=3Dcoll:collection1 core:collection1 props:= {shard=3Dshard1, roles=3Dnull, state=3Drecovering, core=3Dcollection1, coll= ection=3Dcollection1, node_name=3D127.0.0.1:32029_hh_ov%2Fxj, base_url=3Dht= tp://127.0.0.1:32029/hh_ov/xj} [junit4:junit4] 2> 14138 T2627 C161 P32029 oasc.RecoveryStrategy.doRecove= ry Begin buffering updates. core=3Dcollection1 [junit4:junit4] 2> 14138 T2627 C161 P32029 oasu.UpdateLog.bufferUpdates S= tarting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog=3Dnull} [junit4:junit4] 2> 14138 T2627 C161 P32029 oasc.RecoveryStrategy.replicat= e Attempting to replicate from http://127.0.0.1:32013/hh_ov/xj/collection1/= . core=3Dcollection1 [junit4:junit4] 2> 14139 T2627 C161 P32029 oascsi.HttpClientUtil.createCl= ient Creating new http client, config:maxConnections=3D128&maxConnectionsPe= rHost=3D32&followRedirects=3Dfalse [junit4:junit4] 2> 14145 T2533 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 14154 T2565 C159 P32013 oasu.DirectUpdateHandler2.comm= it start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dfal= se,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 14201 T2565 C159 P32013 oasc.SolrDeletionPolicy.onComm= it SolrDeletionPolicy.onCommit: commits:num=3D3 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/o= rg.apache.solr.cloud.SyncSliceTest-1355781770504/jetty1/index lockFactory= =3Dorg.apache.lucene.store.NativeFSLockFactory@59130c74; maxCacheMB=3D48.0 = maxMergeSizeMB=3D4.0)),segFN=3Dsegments_2,generation=3D2,filenames=3D[segme= nts_2] [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/o= rg.apache.solr.cloud.SyncSliceTest-1355781770504/jetty1/index lockFactory= =3Dorg.apache.lucene.store.NativeFSLockFactory@59130c74; maxCacheMB=3D48.0 = maxMergeSizeMB=3D4.0)),segFN=3Dsegments_3,generation=3D3,filenames=3D[segme= nts_3] [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/o= rg.apache.solr.cloud.SyncSliceTest-1355781770504/jetty1/index lockFactory= =3Dorg.apache.lucene.store.NativeFSLockFactory@59130c74; maxCacheMB=3D48.0 = maxMergeSizeMB=3D4.0)),segFN=3Dsegments_4,generation=3D4,filenames=3D[segme= nts_4] [junit4:junit4] 2> 14202 T2565 C159 P32013 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 4[segments_4] [junit4:junit4] 2> 14204 T2565 C159 P32013 oasc.CachingDirectoryFactory.c= lose Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Sync= SliceTest-1355781770504/jetty1 [junit4:junit4] 2> 14205 T2565 C159 P32013 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 14205 T2565 C159 P32013 /update {waitSearcher=3Dtrue&o= penSearcher=3Dfalse&commit=3Dtrue&commit_end_point=3Dtrue&wt=3Djavabin&soft= Commit=3Dfalse&version=3D2} {commit=3D} 0 51 [junit4:junit4] 2> 14207 T2627 C161 P32029 oash.ReplicationHandler.inform= Commits will be reserved for 10000 [junit4:junit4] 2> 14207 T2627 C161 P32029 oash.SnapPuller. No val= ue set for 'pollInterval'. Timer Task not started. [junit4:junit4] 2> 14210 T2568 C159 P32013 REQ /replication {command=3Din= dexversion&wt=3Djavabin&qt=3D/replication&version=3D2} status=3D0 [...truncated too long message...] tCnxn$EventThread.run EventThread shut down [junit4:junit4] 2> 118970 T2533 oaz.ZooKeeper.close Session: 0x13baae40d0= d000c closed [junit4:junit4] 2> 118971 T2533 oejsh.ContextHandler.doStop stopped o.e.j= .s.ServletContextHandler{/hh_ov/xj,null} [junit4:junit4] 2> 119136 T2533 oas.SolrTestCaseJ4.tearDown ###Ending tes= tDistribSearch [junit4:junit4] 1> client port:0.0.0.0/0.0.0.0:0 [junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=3DSyncSlice= Test -Dtests.method=3DtestDistribSearch -Dtests.seed=3DBF39A2C09A4432F -Dte= sts.multiplier=3D3 -Dtests.slow=3Dtrue -Dtests.locale=3Dno_NO_NY -Dtests.ti= mezone=3DAmerica/Mexico_City -Dtests.file.encoding=3DUTF-8 [junit4:junit4] FAILURE 119s J1 | SyncSliceTest.testDistribSearch <<< [junit4:junit4] > Throwable #1: java.lang.AssertionError [junit4:junit4] > =09at __randomizedtesting.SeedInfo.seed([BF39A2C09A443= 2F:8A1514347EFB2313]:0) [junit4:junit4] > =09at org.junit.Assert.fail(Assert.java:92) [junit4:junit4] > =09at org.junit.Assert.assertTrue(Assert.java:43) [junit4:junit4] > =09at org.junit.Assert.assertNotNull(Assert.java:526) [junit4:junit4] > =09at org.junit.Assert.assertNotNull(Assert.java:537) [junit4:junit4] > =09at org.apache.solr.cloud.SyncSliceTest.doTest(SyncS= liceTest.java:211) [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:601) [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> 119157 T2533 oas.SolrTestCaseJ4.deleteCore ###deleteCo= re [junit4:junit4] 2> NOTE: test params are: codec=3DAsserting, sim=3DDefaul= tSimilarity, locale=3Dno_NO_NY, timezone=3DAmerica/Mexico_City [junit4:junit4] 2> NOTE: FreeBSD 9.0-RELEASE amd64/Oracle Corporation 1.7= .0_09 (64-bit)/cpus=3D16,threads=3D2,free=3D135720144,total=3D497025024 [junit4:junit4] 2> NOTE: All tests run in this JVM: [TestDocSet, FieldMut= atingUpdateProcessorTest, OpenExchangeRatesOrgProviderTest, RecoveryZkTest,= ClusterStateUpdateTest, XmlUpdateRequestHandlerTest, TestSolrXMLSerializer= , ZkSolrClientTest, BasicFunctionalityTest, SolrInfoMBeanTest, ZkCLITest, S= oftAutoCommitTest, ReturnFieldsTest, TestStressRecovery, PrimitiveFieldType= Test, StatelessScriptUpdateProcessorFactoryTest, TestRealTimeGet, Signature= UpdateProcessorFactoryTest, TestReplicationHandler, TestBinaryField, Direct= UpdateHandlerTest, SuggesterTest, TestSolrIndexConfig, FullSolrCloudDistrib= CmdsTest, LukeRequestHandlerTest, LeaderElectionTest, TestReversedWildcardF= ilterFactory, PolyFieldTest, TestSolrDeletionPolicy2, EchoParamsTest, DisMa= xRequestHandlerTest, ZkNodePropsTest, TestFastWriter, UpdateParamsTest, Dis= tributedQueryElevationComponentTest, TestUpdate, StatsComponentTest, Script= EngineTest, TestCodecSupport, TestSurroundQueryParser, TestPropInject, Inde= xSchemaRuntimeFieldTest, UUIDFieldTest, TestTrie, PeerSyncTest, XsltUpdateR= equestHandlerTest, TestStressVersions, IndexSchemaTest, SolrCoreTest, TestO= mitPositions, TestSolrCoreProperties, TestDistributedSearch, TestQuerySende= rListener, ResponseLogComponentTest, TestPluginEnable, TestElisionMultiterm= Query, TestJmxIntegration, BasicDistributedZkTest, TestMultiCoreConfBootstr= ap, TestSort, DirectSolrSpellCheckerTest, TestFiltering, TestIndexSearcher,= TestFunctionQuery, DirectSolrConnectionTest, QueryEqualityTest, TestCSVLoa= der, TestCSVResponseWriter, DocumentBuilderTest, BinaryUpdateRequestHandler= Test, QueryParsingTest, StandardRequestHandlerTest, TestPHPSerializedRespon= seWriter, PingRequestHandlerTest, JsonLoaderTest, DocumentAnalysisRequestHa= ndlerTest, TestValueSourceCache, SearchHandlerTest, SuggesterFSTTest, TestQ= ueryUtils, SuggesterTSTTest, TestSearchPerf, BadIndexSchemaTest, TestLucene= MatchVersion, TestWriterPerf, TestPropInjectDefaults, TestCollationField, I= ndexReaderFactoryTest, OutputWriterTest, MultiTermTest, SpellPossibilityIte= ratorTest, TestPerFieldSimilarity, TestDFRSimilarityFactory, TimeZoneUtilsT= est, DateMathParserTest, PluginInfoTest, ResourceLoaderTest, DateFieldTest,= TestBadConfig, PathHierarchyTokenizerFactoryTest, OverseerCollectionProces= sorTest, ShardRoutingTest, SyncSliceTest] [junit4:junit4] Completed on J1 in 119.18s, 1 test, 1 failure <<< FAILURES! [...truncated 36 lines...] BUILD FAILED /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/build.x= ml:353: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/build.x= ml:39: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/bu= ild.xml:178: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/co= mmon-build.xml:438: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/= common-build.xml:1175: The following error occurred while executing this li= ne: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/= common-build.xml:840: There were test failures: 243 suites, 1010 tests, 1 f= ailure, 21 ignored (3 assumptions) Total time: 36 minutes 28 seconds Build step 'Invoke Ant' marked build as failure Archiving artifacts Recording test results Email was triggered for: Failure Sending email for trigger: Failure ------=_Part_3768_823571361.1355781937851 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_3768_823571361.1355781937851--