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 45094DE69 for ; Wed, 19 Sep 2012 12:54:25 +0000 (UTC) Received: (qmail 86516 invoked by uid 500); 19 Sep 2012 12:54:23 -0000 Delivered-To: apmail-lucene-dev-archive@lucene.apache.org Received: (qmail 86375 invoked by uid 500); 19 Sep 2012 12:54:23 -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 86083 invoked by uid 99); 19 Sep 2012 12:54:20 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 19 Sep 2012 12:54:20 +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; Wed, 19 Sep 2012 12:54:12 +0000 Received: from aegis.apache.org (localhost [127.0.0.1]) by aegis.apache.org (Postfix) with ESMTP id B6104C00EB for ; Wed, 19 Sep 2012 12:53:51 +0000 (UTC) Date: Wed, 19 Sep 2012 12:53:41 +0000 (UTC) From: Apache Jenkins Server To: dev@lucene.apache.org Message-ID: <1382559590.444.1348059231736.JavaMail.hudson@aegis.apache.org> In-Reply-To: <1682023821.389.1348045182466.JavaMail.hudson@aegis.apache.org> References: <1682023821.389.1348045182466.JavaMail.hudson@aegis.apache.org> Subject: [JENKINS] Lucene-Solr-Tests-4.x-Java6 - Build # 673 - Still Failing MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="----=_Part_443_2145800783.1348059221833" X-Virus-Checked: Checked by ClamAV on apache.org ------=_Part_443_2145800783.1348059221833 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-Java6/673/ 1 tests failed. REGRESSION: org.apache.solr.cloud.SyncSliceTest.testDistribSearch Error Message: There are still nodes recoverying Stack Trace: java.lang.AssertionError: There are still nodes recoverying =09at __randomizedtesting.SeedInfo.seed([7FED73DFB5AF06E6:FE0BFDC7C2F066DA]= :0) =09at org.junit.Assert.fail(Assert.java:93) =09at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFi= nish(AbstractDistribZkTestBase.java:154) =09at org.apache.solr.cloud.AbstractFullDistribZkTestBase.waitForRecoveries= ToFinish(AbstractFullDistribZkTestBase.java:560) =09at org.apache.solr.cloud.AbstractFullDistribZkTestBase.waitForThingsToLe= velOut(AbstractFullDistribZkTestBase.java:1135) =09at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:162) =09at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseD= istributedSearchTestCase.java:695) =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:616) =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:45) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRul= e$1.evaluate(SystemPropertiesInvariantRule.java:55) =09at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleT= hreadAndTestName.java:48) =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:45) =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:679) Build Log: [...truncated 7149 lines...] [junit4:junit4] Suite: org.apache.solr.cloud.SyncSliceTest [junit4:junit4] 2> 3 T1446 oas.SolrTestCaseJ4.setUp ###Starting testDistr= ibSearch [junit4:junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/worksp= ace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-Syn= cSliceTest-1348058876740 [junit4:junit4] 2> 3 T1446 oasc.ZkTestServer.run STARTING ZK TEST SERVER [junit4:junit4] 2> 6 T1447 oazs.ZooKeeperServer.setTickTime tickTime set = to 1000 [junit4:junit4] 2> 6 T1447 oazs.NIOServerCnxn$Factory. binding to p= ort 0.0.0.0/0.0.0.0:0 [junit4:junit4] 2> 7 T1447 oazsp.FileTxnSnapLog.save Snapshotting: 0 [junit4:junit4] 2> 105 T1446 oasc.ZkTestServer.run start zk server on por= t:26491 [junit4:junit4] 2> 105 T1446 oaz.ZooKeeper. Initiating client conne= ction, connectString=3D127.0.0.1:26491 sessionTimeout=3D10000 watcher=3Dorg= .apache.solr.common.cloud.ConnectionManager@1787a02e [junit4:junit4] 2> 106 T1452 oaz.ClientCnxn$SendThread.startConnect Openi= ng socket connection to server /127.0.0.1:26491 [junit4:junit4] 2> 106 T1446 oascc.ConnectionManager.waitForConnected Wai= ting for client to connect to ZooKeeper [junit4:junit4] 2> 107 T1452 oaz.ClientCnxn$SendThread.primeConnection So= cket connection established to localhost/127.0.0.1:26491, initiating sessio= n [junit4:junit4] 2> 107 T1448 oazs.NIOServerCnxn$Factory.run Accepted sock= et connection from /140.211.11.196:26492 [junit4:junit4] 2> 107 T1448 oazs.NIOServerCnxn.readConnectRequest Client= attempting to establish new session at /140.211.11.196:26492 [junit4:junit4] 2> 107 T1450 oazsp.FileTxnLog.append Creating new log fil= e: log.1 [junit4:junit4] 2> 111 T1450 oazs.NIOServerCnxn.finishSessionInit Establi= shed session 0x139de920b480000 with negotiated timeout 10000 for client /14= 0.211.11.196:26492 [junit4:junit4] 2> 111 T1452 oaz.ClientCnxn$SendThread.readConnectResult = Session establishment complete on server localhost/127.0.0.1:26491, session= id =3D 0x139de920b480000, negotiated timeout =3D 10000 [junit4:junit4] 2> 111 T1453 oascc.ConnectionManager.process Watcher org.= apache.solr.common.cloud.ConnectionManager@1787a02e name:ZooKeeperConnectio= n Watcher:127.0.0.1:26491 got event WatchedEvent state:SyncConnected type:N= one path:null path:null type:None [junit4:junit4] 2> 111 T1446 oascc.ConnectionManager.waitForConnected Cli= ent is connected to ZooKeeper [junit4:junit4] 2> 112 T1446 oascc.SolrZkClient.makePath makePath: /solr [junit4:junit4] 2> 115 T1451 oazs.PrepRequestProcessor.pRequest Processed= session termination for sessionid: 0x139de920b480000 [junit4:junit4] 2> 115 T1453 oaz.ClientCnxn$EventThread.run EventThread s= hut down [junit4:junit4] 2> 116 T1448 oazs.NIOServerCnxn.closeSock Closed socket c= onnection for client /140.211.11.196:26492 which had sessionid 0x139de920b4= 80000 [junit4:junit4] 2> 115 T1446 oaz.ZooKeeper.close Session: 0x139de920b4800= 00 closed [junit4:junit4] 2> 116 T1446 oaz.ZooKeeper. Initiating client conne= ction, connectString=3D127.0.0.1:26491/solr sessionTimeout=3D10000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@55405fa [junit4:junit4] 2> 117 T1454 oaz.ClientCnxn$SendThread.startConnect Openi= ng socket connection to server /127.0.0.1:26491 [junit4:junit4] 2> 117 T1446 oascc.ConnectionManager.waitForConnected Wai= ting for client to connect to ZooKeeper [junit4:junit4] 2> 117 T1454 oaz.ClientCnxn$SendThread.primeConnection So= cket connection established to localhost/127.0.0.1:26491, initiating sessio= n [junit4:junit4] 2> 117 T1448 oazs.NIOServerCnxn$Factory.run Accepted sock= et connection from /140.211.11.196:26493 [junit4:junit4] 2> 118 T1448 oazs.NIOServerCnxn.readConnectRequest Client= attempting to establish new session at /140.211.11.196:26493 [junit4:junit4] 2> 125 T1450 oazs.NIOServerCnxn.finishSessionInit Establi= shed session 0x139de920b480001 with negotiated timeout 10000 for client /14= 0.211.11.196:26493 [junit4:junit4] 2> 125 T1454 oaz.ClientCnxn$SendThread.readConnectResult = Session establishment complete on server localhost/127.0.0.1:26491, session= id =3D 0x139de920b480001, negotiated timeout =3D 10000 [junit4:junit4] 2> 126 T1455 oascc.ConnectionManager.process Watcher org.= apache.solr.common.cloud.ConnectionManager@55405fa name:ZooKeeperConnection= Watcher:127.0.0.1:26491/solr got event WatchedEvent state:SyncConnected ty= pe:None path:null path:null type:None [junit4:junit4] 2> 126 T1446 oascc.ConnectionManager.waitForConnected Cli= ent is connected to ZooKeeper [junit4:junit4] 2> 126 T1446 oascc.SolrZkClient.makePath makePath: /colle= ctions/collection1 [junit4:junit4] 2> 129 T1446 oascc.SolrZkClient.makePath makePath: /colle= ctions/collection1/shards [junit4:junit4] 2> 131 T1446 oascc.SolrZkClient.makePath makePath: /colle= ctions/control_collection [junit4:junit4] 2> 133 T1446 oascc.SolrZkClient.makePath makePath: /colle= ctions/control_collection/shards [junit4:junit4] 2> 142 T1446 oasc.AbstractZkTestCase.putConfig put /usr/h= ome/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/so= lr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf1/s= olrconfig.xml [junit4:junit4] 2> 143 T1446 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/solrconfig.xml [junit4:junit4] 2> 153 T1446 oasc.AbstractZkTestCase.putConfig put /usr/h= ome/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/so= lr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schem= a.xml [junit4:junit4] 2> 154 T1446 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/schema.xml [junit4:junit4] 2> 257 T1446 oasc.AbstractZkTestCase.putConfig put /usr/h= ome/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/so= lr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf1/s= olrconfig.xml [junit4:junit4] 2> 257 T1446 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/solrconfig.xml [junit4:junit4] 2> 260 T1446 oasc.AbstractZkTestCase.putConfig put /usr/h= ome/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/so= lr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/st= opwords.txt [junit4:junit4] 2> 261 T1446 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/stopwords.txt [junit4:junit4] 2> 272 T1446 oasc.AbstractZkTestCase.putConfig put /usr/h= ome/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/so= lr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/pr= otwords.txt [junit4:junit4] 2> 273 T1446 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/protwords.txt [junit4:junit4] 2> 275 T1446 oasc.AbstractZkTestCase.putConfig put /usr/h= ome/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/so= lr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/cur= rency.xml [junit4:junit4] 2> 275 T1446 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/currency.xml [junit4:junit4] 2> 278 T1446 oasc.AbstractZkTestCase.putConfig put /usr/h= ome/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/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> 278 T1446 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/open-exchange-rates.json [junit4:junit4] 2> 286 T1446 oasc.AbstractZkTestCase.putConfig put /usr/h= ome/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/so= lr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /co= nfigs/conf1/mapping-ISOLatin1Accent.txt [junit4:junit4] 2> 286 T1446 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/mapping-ISOLatin1Accent.txt [junit4:junit4] 2> 288 T1446 oasc.AbstractZkTestCase.putConfig put /usr/h= ome/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/so= lr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1= /old_synonyms.txt [junit4:junit4] 2> 289 T1446 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/old_synonyms.txt [junit4:junit4] 2> 291 T1446 oasc.AbstractZkTestCase.putConfig put /usr/h= ome/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/so= lr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/syn= onyms.txt [junit4:junit4] 2> 292 T1446 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/synonyms.txt [junit4:junit4] 2> 299 T1451 oazs.PrepRequestProcessor.pRequest Processed= session termination for sessionid: 0x139de920b480001 [junit4:junit4] 2> 300 T1455 oaz.ClientCnxn$EventThread.run EventThread s= hut down [junit4:junit4] 2> 300 T1446 oaz.ZooKeeper.close Session: 0x139de920b4800= 01 closed [junit4:junit4] 2> 300 T1448 oazs.NIOServerCnxn.closeSock Closed socket c= onnection for client /140.211.11.196:26493 which had sessionid 0x139de920b4= 80001 [junit4:junit4] 2> 302 T1446 oejs.Server.doStart jetty-8.1.2.v20120308 [junit4:junit4] 2> 306 T1446 oejs.AbstractConnector.doStart Started Socke= tConnector@0.0.0.0:26494 [junit4:junit4] 2> 306 T1446 oasc.SolrResourceLoader.locateSolrHome JNDI = not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 307 T1446 oasc.SolrResourceLoader.locateSolrHome using= system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr [junit4:junit4] 2> 307 T1446 oasc.SolrResourceLoader. new SolrResou= rceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/' [junit4:junit4] 2> 342 T1446 oass.SolrDispatchFilter.init SolrDispatchFil= ter.init() [junit4:junit4] 2> 342 T1446 oasc.SolrResourceLoader.locateSolrHome JNDI = not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 343 T1446 oasc.SolrResourceLoader.locateSolrHome using= system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr [junit4:junit4] 2> 343 T1446 oasc.CoreContainer$Initializer.initialize lo= oking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tes= ts-4.x-Java6/solr/build/solr-core/test-files/solr/solr.xml [junit4:junit4] 2> 343 T1446 oasc.CoreContainer. New CoreContainer = 313856751 [junit4:junit4] 2> 344 T1446 oasc.CoreContainer.load Loading CoreContaine= r using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tes= ts-4.x-Java6/solr/build/solr-core/test-files/solr/' [junit4:junit4] 2> 344 T1446 oasc.SolrResourceLoader. new SolrResou= rceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-So= lr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/' [junit4:junit4] 2> 368 T1446 oasc.CoreContainer.load Registering Log List= ener [junit4:junit4] 2> 383 T1446 oasc.CoreContainer.initZooKeeper Zookeeper c= lient=3D127.0.0.1:26491/solr [junit4:junit4] 2> 383 T1446 oaz.ZooKeeper. Initiating client conne= ction, connectString=3D127.0.0.1:26491/solr sessionTimeout=3D5000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@6900eab5 [junit4:junit4] 2> 384 T1465 oaz.ClientCnxn$SendThread.startConnect Openi= ng socket connection to server /127.0.0.1:26491 [junit4:junit4] 2> 384 T1446 oascc.ConnectionManager.waitForConnected Wai= ting for client to connect to ZooKeeper [junit4:junit4] 2> 385 T1465 oaz.ClientCnxn$SendThread.primeConnection So= cket connection established to localhost/127.0.0.1:26491, initiating sessio= n [junit4:junit4] 2> 385 T1448 oazs.NIOServerCnxn$Factory.run Accepted sock= et connection from /140.211.11.196:26495 [junit4:junit4] 2> 386 T1448 oazs.NIOServerCnxn.readConnectRequest Client= attempting to establish new session at /140.211.11.196:26495 [junit4:junit4] 2> 387 T1450 oazs.NIOServerCnxn.finishSessionInit Establi= shed session 0x139de920b480002 with negotiated timeout 5000 for client /140= .211.11.196:26495 [junit4:junit4] 2> 387 T1465 oaz.ClientCnxn$SendThread.readConnectResult = Session establishment complete on server localhost/127.0.0.1:26491, session= id =3D 0x139de920b480002, negotiated timeout =3D 5000 [junit4:junit4] 2> 387 T1466 oascc.ConnectionManager.process Watcher org.= apache.solr.common.cloud.ConnectionManager@6900eab5 name:ZooKeeperConnectio= n Watcher:127.0.0.1:26491/solr got event WatchedEvent state:SyncConnected t= ype:None path:null path:null type:None [junit4:junit4] 2> 387 T1446 oascc.ConnectionManager.waitForConnected Cli= ent is connected to ZooKeeper [junit4:junit4] 2> 389 T1451 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x139de920b480002 type:crea= te cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:= /solr/overseer Error:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 400 T1446 oascc.SolrZkClient.makePath makePath: /live_= nodes [junit4:junit4] 2> 403 T1446 oasc.ZkController.createEphemeralLiveNode Re= gister node as live in ZooKeeper:/live_nodes/127.0.0.1:26494_solr [junit4:junit4] 2> 404 T1451 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x139de920b480002 type:dele= te cxid:0x7 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:= /solr/live_nodes/127.0.0.1:26494_solr Error:KeeperErrorCode =3D NoNode for = /solr/live_nodes/127.0.0.1:26494_solr [junit4:junit4] 2> 405 T1446 oascc.SolrZkClient.makePath makePath: /live_= nodes/127.0.0.1:26494_solr [junit4:junit4] 2> 412 T1446 oashc.HttpShardHandlerFactory.getParameter S= etting socketTimeout to: 0 [junit4:junit4] 2> 413 T1446 oashc.HttpShardHandlerFactory.getParameter S= etting urlScheme to: http:// [junit4:junit4] 2> 413 T1446 oashc.HttpShardHandlerFactory.getParameter S= etting connTimeout to: 0 [junit4:junit4] 2> 413 T1446 oashc.HttpShardHandlerFactory.getParameter S= etting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 414 T1446 oashc.HttpShardHandlerFactory.getParameter S= etting corePoolSize to: 0 [junit4:junit4] 2> 414 T1446 oashc.HttpShardHandlerFactory.getParameter S= etting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 415 T1446 oashc.HttpShardHandlerFactory.getParameter S= etting maxThreadIdleTime to: 5 [junit4:junit4] 2> 415 T1446 oashc.HttpShardHandlerFactory.getParameter S= etting sizeOfQueue to: -1 [junit4:junit4] 2> 415 T1446 oashc.HttpShardHandlerFactory.getParameter S= etting fairnessPolicy to: false [junit4:junit4] 2> 416 T1446 oascsi.HttpClientUtil.createClient Creating = new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000&s= ocketTimeout=3D0&connTimeout=3D0&retry=3Dfalse [junit4:junit4] 2> 431 T1446 oascc.SolrZkClient.makePath makePath: /overs= eer_elect/election [junit4:junit4] 2> 436 T1451 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x139de920b480002 type:dele= te cxid:0x15 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path= :/solr/overseer_elect/leader Error:KeeperErrorCode =3D NoNode for /solr/ove= rseer_elect/leader [junit4:junit4] 2> 448 T1446 oascc.SolrZkClient.makePath makePath: /overs= eer_elect/leader [junit4:junit4] 2> 450 T1446 oasc.Overseer.start Overseer (id=3D883463865= 46294786-127.0.0.1:26494_solr-n_0000000000) starting [junit4:junit4] 2> 450 T1451 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x139de920b480002 type:crea= te cxid:0x1a zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path= :/solr/overseer Error:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 452 T1451 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x139de920b480002 type:crea= te cxid:0x1b zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path= :/solr/overseer Error:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 453 T1451 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x139de920b480002 type:crea= te cxid:0x1c zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path= :/solr/overseer Error:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 462 T1451 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x139de920b480002 type:crea= te cxid:0x1d zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path= :/solr/overseer Error:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 463 T1468 oasc.OverseerCollectionProcessor.run Process= current queue of collection creations [junit4:junit4] 2> 463 T1446 oascc.SolrZkClient.makePath makePath: /clust= erstate.json [junit4:junit4] 2> 473 T1446 oascc.ZkStateReader.createClusterStateWatche= rsAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 474 T1467 oasc.Overseer$ClusterStateUpdater.run Starti= ng to work on the main queue [junit4:junit4] 2> 478 T1446 oasc.CoreContainer.create Creating SolrCore = 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1 [junit4:junit4] 2> 479 T1446 oasc.ZkController.createCollectionZkNode Che= ck for collection zkNode:control_collection [junit4:junit4] 2> 479 T1446 oasc.ZkController.createCollectionZkNode Col= lection zkNode exists [junit4:junit4] 2> 480 T1446 oasc.ZkController.readConfigName Load collec= tion config from:/collections/control_collection [junit4:junit4] 2> 481 T1446 oasc.SolrResourceLoader. new SolrResou= rceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-So= lr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/' [junit4:junit4] 2> 482 T1446 oasc.SolrResourceLoader.replaceClassLoader A= dding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-J= ava6/solr/build/solr-core/test-files/solr/collection1/lib/README' to classl= oader [junit4:junit4] 2> 483 T1446 oasc.SolrResourceLoader.replaceClassLoader A= dding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-J= ava6/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to clas= sloader [junit4:junit4] 2> 530 T1446 oasc.SolrConfig. Using Lucene MatchVer= sion: LUCENE_40 [junit4:junit4] 2> 597 T1446 oasc.SolrConfig. Loaded SolrConfig: so= lrconfig.xml [junit4:junit4] 2> 698 T1446 oass.IndexSchema.readSchema Reading Solr Sch= ema [junit4:junit4] 2> 702 T1446 oass.IndexSchema.readSchema Schema name=3Dte= st [junit4:junit4] 2> 1264 T1446 oass.OpenExchangeRatesOrgProvider.init Init= ialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 1275 T1446 oass.IndexSchema.readSchema default search = field in schema is text [junit4:junit4] 2> 1278 T1446 oass.IndexSchema.readSchema unique key fiel= d: id [junit4:junit4] 2> 1286 T1446 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 1290 T1446 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 1293 T1446 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 1294 T1446 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 1295 T1446 oasc.SolrCore. [collection1] Opening = new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4= .x-Java6/solr/build/solr-core/test-files/solr/collection1/, dataDir=3D./org= .apache.solr.cloud.SyncSliceTest-1348058876740/control/data/ [junit4:junit4] 2> 1295 T1446 oasc.JmxMonitoredMap. JMX monitoring = is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMB= eanServer@14426a6 [junit4:junit4] 2> 1296 T1446 oasc.SolrCore.getNewIndexDir WARNING New in= dex directory detected: old=3Dnull new=3D./org.apache.solr.cloud.SyncSliceT= est-1348058876740/control/data/index/ [junit4:junit4] 2> 1297 T1446 oasc.SolrCore.initIndex WARNING [collection= 1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-134805887674= 0/control/data/index' doesn't exist. Creating new index... [junit4:junit4] 2> 1298 T1446 oasc.CachingDirectoryFactory.get return new= directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.= x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-= 1348058876740/control/data/index forceNew:false [junit4:junit4] 2> 1303 T1446 oasc.SolrDeletionPolicy.onCommit SolrDeleti= onPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/control/data/index,segFN=3Dsegments_1,= generation=3D1,filenames=3D[segments_1] [junit4:junit4] 2> 1303 T1446 oasc.SolrDeletionPolicy.updateCommits newes= t commit =3D 1 [junit4:junit4] 2> 1304 T1446 oasc.SolrCore.initWriters created xml: solr= .XMLResponseWriter [junit4:junit4] 2> 1306 T1446 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe" [junit4:junit4] 2> 1306 T1446 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe-allfields" [junit4:junit4] 2> 1306 T1446 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "s= tored_sig" [junit4:junit4] 2> 1307 T1446 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "u= niq-fields" [junit4:junit4] 2> 1307 T1446 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= istrib-dup-test-chain-implicit" [junit4:junit4] 2> 1307 T1446 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 1308 T1446 oasc.RequestHandlers.initHandlersFromConfig= created /replication: solr.ReplicationHandler [junit4:junit4] 2> 1308 T1446 oasc.RequestHandlers.initHandlersFromConfig= created standard: solr.StandardRequestHandler [junit4:junit4] 2> 1309 T1446 oasc.RequestHandlers.initHandlersFromConfig= created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 1309 T1446 oasc.RequestHandlers.initHandlersFromConfig= created dismax: solr.SearchHandler [junit4:junit4] 2> 1310 T1446 oasc.RequestHandlers.initHandlersFromConfig= created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler [junit4:junit4] 2> 1310 T1446 oasc.RequestHandlers.initHandlersFromConfig= created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 1311 T1446 oasc.RequestHandlers.initHandlersFromConfig= created defaults: solr.StandardRequestHandler [junit4:junit4] 2> 1311 T1446 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.StandardRequestHandler [junit4:junit4] 2> 1311 T1446 oasc.RequestHandlers.initHandlersFromConfig= created lazy: solr.StandardRequestHandler [junit4:junit4] 2> 1312 T1446 oasc.RequestHandlers.initHandlersFromConfig= created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 1312 T1446 oasc.RequestHandlers.initHandlersFromConfig= created /terms: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 1313 T1446 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 1313 T1446 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchH= andler [junit4:junit4] 2> 1313 T1446 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchH= andler [junit4:junit4] 2> 1314 T1446 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.= SearchHandler [junit4:junit4] 2> 1314 T1446 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 1315 T1446 oasc.RequestHandlers.initHandlersFromConfig= created tvrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 1315 T1446 oasc.RequestHandlers.initHandlersFromConfig= created /mlt: solr.MoreLikeThisHandler [junit4:junit4] 2> 1316 T1446 oasc.RequestHandlers.initHandlersFromConfig= created /debug/dump: solr.DumpRequestHandler [junit4:junit4] 2> 1318 T1446 oashl.XMLLoader.init xsltCacheLifetimeSecon= ds=3D60 [junit4:junit4] 2> 1321 T1446 oasc.SolrCore.initDeprecatedSupport WARNING= solrconfig.xml uses deprecated , Please update your c= onfig to use the ShowFileRequestHandler. [junit4:junit4] 2> 1322 T1446 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> 1325 T1446 oass.SolrIndexSearcher. Opening Searc= her@2bdf228e main [junit4:junit4] 2> 1326 T1446 oasu.CommitTracker. Hard AutoCommit: = disabled [junit4:junit4] 2> 1326 T1446 oasu.CommitTracker. Soft AutoCommit: = disabled [junit4:junit4] 2> 1326 T1446 oashc.SpellCheckComponent.inform Initializi= ng spell checkers [junit4:junit4] 2> 1332 T1446 oass.DirectSolrSpellChecker.init init: {nam= e=3Ddirect,classname=3DDirectSolrSpellChecker,field=3Dlowerfilt,minQueryLen= gth=3D3} [junit4:junit4] 2> 1373 T1469 oasc.SolrCore.registerSearcher [collection1= ] Registered new searcher Searcher@2bdf228e main{StandardDirectoryReader(se= gments_1:1)} [junit4:junit4] 2> 1378 T1451 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x139de920b480002 type:cre= ate cxid:0x53 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Pat= h:/solr/overseer/queue Error:KeeperErrorCode =3D NoNode for /solr/overseer/= queue [junit4:junit4] 2> 1380 T1446 oasc.CoreContainer.register registering cor= e: collection1 [junit4:junit4] 2> 1381 T1446 oasc.ZkController.register Register shard -= core:collection1 address:http://127.0.0.1:26494/solr shardId:control_shard [junit4:junit4] 2> 1381 T1446 oascc.SolrZkClient.makePath makePath: /coll= ections/control_collection/leader_elect/control_shard/election [junit4:junit4] 2> 1406 T1451 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x139de920b480002 type:del= ete cxid:0x62 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Pat= h:/solr/collections/control_collection/leaders Error:KeeperErrorCode =3D No= Node for /solr/collections/control_collection/leaders [junit4:junit4] 2> 1407 T1446 oasc.ShardLeaderElectionContext.runLeaderPr= ocess Running the leader process. [junit4:junit4] 2> 1407 T1451 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x139de920b480002 type:cre= ate cxid:0x63 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Pat= h:/solr/overseer Error:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 1477 T1467 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 1478 T1451 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x139de920b480002 type:cre= ate cxid:0x6a zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Pat= h:/solr/overseer/queue-work Error:KeeperErrorCode =3D NoNode for /solr/over= seer/queue-work [junit4:junit4] 2> 1494 T1466 oascc.ZkStateReader$2.process A cluster sta= te change has occurred - updating... [junit4:junit4] 2> 1917 T1446 oasc.ShardLeaderElectionContext.waitForRepl= icasToComeUp Enough replicas found to continue. [junit4:junit4] 2> 1917 T1446 oasc.ShardLeaderElectionContext.runLeaderPr= ocess I may be the new leader - try and sync [junit4:junit4] 2> 1918 T1446 oasc.SyncStrategy.sync Sync replicas to htt= p://127.0.0.1:26494/solr/collection1/ [junit4:junit4] 2> 1918 T1446 oasc.SyncStrategy.syncReplicas Sync Success= - now sync replicas to me [junit4:junit4] 2> 1918 T1446 oasc.SyncStrategy.syncToMe http://127.0.0.1= :26494/solr/collection1/ has no replicas [junit4:junit4] 2> 1919 T1446 oasc.ShardLeaderElectionContext.runLeaderPr= ocess I am the new leader: http://127.0.0.1:26494/solr/collection1/ [junit4:junit4] 2> 1919 T1446 oascc.SolrZkClient.makePath makePath: /coll= ections/control_collection/leaders/control_shard [junit4:junit4] 2> 1933 T1451 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x139de920b480002 type:cre= ate cxid:0x88 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Pat= h:/solr/overseer Error:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 1997 T1467 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 2010 T1466 oascc.ZkStateReader$2.process A cluster sta= te change has occurred - updating... [junit4:junit4] 2> 2037 T1446 oasc.ZkController.register We are http://12= 7.0.0.1:26494/solr/collection1/ and leader is http://127.0.0.1:26494/solr/c= ollection1/ [junit4:junit4] 2> 2037 T1446 oasc.ZkController.register No LogReplay nee= ded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:26494/solr [junit4:junit4] 2> 2037 T1446 oasc.ZkController.checkRecovery I am the le= ader, no recovery necessary [junit4:junit4] 2> 2039 T1446 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 2039 T1446 oass.SolrDispatchFilter.init user.dir=3D/us= r/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build= /solr-core/test/J1 [junit4:junit4] 2> 2040 T1446 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() done [junit4:junit4] 2> 2040 T1446 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&fo= llowRedirects=3Dfalse [junit4:junit4] 2> 2387 T1446 oejs.Server.doStart jetty-8.1.2.v20120308 [junit4:junit4] 2> 2390 T1446 oejs.AbstractConnector.doStart Started Sock= etConnector@0.0.0.0:57977 [junit4:junit4] 2> 2390 T1446 oasc.SolrResourceLoader.locateSolrHome JNDI= not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 2391 T1446 oasc.SolrResourceLoader.locateSolrHome usin= g system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty1-1= 348058878786 [junit4:junit4] 2> 2391 T1446 oasc.SolrResourceLoader. new SolrReso= urceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/= Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty1-= 1348058878786/' [junit4:junit4] 2> 2426 T1446 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() [junit4:junit4] 2> 2426 T1446 oasc.SolrResourceLoader.locateSolrHome JNDI= not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 2427 T1446 oasc.SolrResourceLoader.locateSolrHome usin= g system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty1-1= 348058878786 [junit4:junit4] 2> 2427 T1446 oasc.CoreContainer$Initializer.initialize l= ooking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty1-1348058878786/= solr.xml [junit4:junit4] 2> 2428 T1446 oasc.CoreContainer. New CoreContainer= 1040311516 [junit4:junit4] 2> 2428 T1446 oasc.CoreContainer.load Loading CoreContain= er using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty1-1348058878786/= ' [junit4:junit4] 2> 2429 T1446 oasc.SolrResourceLoader. new SolrReso= urceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-S= olr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty1-13480588= 78786/' [junit4:junit4] 2> 2453 T1446 oasc.CoreContainer.load Registering Log Lis= tener [junit4:junit4] 2> 2467 T1446 oasc.CoreContainer.initZooKeeper Zookeeper = client=3D127.0.0.1:26491/solr [junit4:junit4] 2> 2468 T1446 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:26491/solr sessionTimeout=3D5000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@65b24f6f [junit4:junit4] 2> 2469 T1479 oaz.ClientCnxn$SendThread.startConnect Open= ing socket connection to server /127.0.0.1:26491 [junit4:junit4] 2> 2469 T1446 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 2470 T1479 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost/127.0.0.1:26491, initiating sessi= on [junit4:junit4] 2> 2470 T1448 oazs.NIOServerCnxn$Factory.run Accepted soc= ket connection from /140.211.11.196:59847 [junit4:junit4] 2> 2470 T1448 oazs.NIOServerCnxn.readConnectRequest Clien= t attempting to establish new session at /140.211.11.196:59847 [junit4:junit4] 2> 2476 T1450 oazs.NIOServerCnxn.finishSessionInit Establ= ished session 0x139de920b480003 with negotiated timeout 5000 for client /14= 0.211.11.196:59847 [junit4:junit4] 2> 2476 T1479 oaz.ClientCnxn$SendThread.readConnectResult= Session establishment complete on server localhost/127.0.0.1:26491, sessio= nid =3D 0x139de920b480003, negotiated timeout =3D 5000 [junit4:junit4] 2> 2476 T1480 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@65b24f6f name:ZooKeeperConnecti= on Watcher:127.0.0.1:26491/solr got event WatchedEvent state:SyncConnected = type:None path:null path:null type:None [junit4:junit4] 2> 2476 T1446 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 2477 T1451 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x139de920b480003 type:cre= ate cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path= :/solr/overseer Error:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 2489 T1451 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x139de920b480003 type:cre= ate cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path= :/solr/overseer Error:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 2491 T1446 oasc.ZkController.createEphemeralLiveNode R= egister node as live in ZooKeeper:/live_nodes/127.0.0.1:57977_solr [junit4:junit4] 2> 2491 T1451 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x139de920b480003 type:del= ete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path= :/solr/live_nodes/127.0.0.1:57977_solr Error:KeeperErrorCode =3D NoNode for= /solr/live_nodes/127.0.0.1:57977_solr [junit4:junit4] 2> 2492 T1446 oascc.SolrZkClient.makePath makePath: /live= _nodes/127.0.0.1:57977_solr [junit4:junit4] 2> 2494 T1466 oascc.ZkStateReader$3.process Updating live= nodes [junit4:junit4] 2> 2495 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting socketTimeout to: 0 [junit4:junit4] 2> 2495 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting urlScheme to: http:// [junit4:junit4] 2> 2496 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting connTimeout to: 0 [junit4:junit4] 2> 2496 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 2496 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting corePoolSize to: 0 [junit4:junit4] 2> 2497 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 2497 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting maxThreadIdleTime to: 5 [junit4:junit4] 2> 2498 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting sizeOfQueue to: -1 [junit4:junit4] 2> 2498 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting fairnessPolicy to: false [junit4:junit4] 2> 2498 T1446 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000&= socketTimeout=3D0&connTimeout=3D0&retry=3Dfalse [junit4:junit4] 2> 2513 T1467 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 2518 T1446 oascc.ZkStateReader.createClusterStateWatch= ersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 2525 T1446 oasc.CoreContainer.create Creating SolrCore= 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty1-1= 348058878786/collection1 [junit4:junit4] 2> 2525 T1446 oasc.ZkController.createCollectionZkNode Ch= eck for collection zkNode:collection1 [junit4:junit4] 2> 2527 T1446 oasc.ZkController.createCollectionZkNode Co= llection zkNode exists [junit4:junit4] 2> 2527 T1446 oasc.ZkController.readConfigName Load colle= ction config from:/collections/collection1 [junit4:junit4] 2> 2528 T1446 oasc.SolrResourceLoader. new SolrReso= urceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-S= olr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty1-13480588= 78786/collection1/' [junit4:junit4] 2> 2529 T1466 oascc.ZkStateReader$2.process A cluster sta= te change has occurred - updating... [junit4:junit4] 2> 2529 T1480 oascc.ZkStateReader$2.process A cluster sta= te change has occurred - updating... [junit4:junit4] 2> 2530 T1446 oasc.SolrResourceLoader.replaceClassLoader = Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-= Java6/solr/build/solr-core/test/J1/solrtest-jetty1-1348058878786/collection= 1/lib/classes/' to classloader [junit4:junit4] 2> 2531 T1446 oasc.SolrResourceLoader.replaceClassLoader = Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-= Java6/solr/build/solr-core/test/J1/solrtest-jetty1-1348058878786/collection= 1/lib/README' to classloader [junit4:junit4] 2> 2579 T1446 oasc.SolrConfig. Using Lucene MatchVe= rsion: LUCENE_40 [junit4:junit4] 2> 2647 T1446 oasc.SolrConfig. Loaded SolrConfig: s= olrconfig.xml [junit4:junit4] 2> 2748 T1446 oass.IndexSchema.readSchema Reading Solr Sc= hema [junit4:junit4] 2> 2754 T1446 oass.IndexSchema.readSchema Schema name=3Dt= est [junit4:junit4] 2> 3325 T1446 oass.OpenExchangeRatesOrgProvider.init Init= ialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 3332 T1446 oass.IndexSchema.readSchema default search = field in schema is text [junit4:junit4] 2> 3335 T1446 oass.IndexSchema.readSchema unique key fiel= d: id [junit4:junit4] 2> 3343 T1446 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 3346 T1446 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 3349 T1446 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 3349 T1446 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 3350 T1446 oasc.SolrCore. [collection1] Opening = new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4= .x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty1-1348058878786/colle= ction1/, dataDir=3D./org.apache.solr.cloud.SyncSliceTest-1348058876740/jett= y1/ [junit4:junit4] 2> 3351 T1446 oasc.JmxMonitoredMap. JMX monitoring = is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMB= eanServer@14426a6 [junit4:junit4] 2> 3352 T1446 oasc.SolrCore.getNewIndexDir WARNING New in= dex directory detected: old=3Dnull new=3D./org.apache.solr.cloud.SyncSliceT= est-1348058876740/jetty1/index/ [junit4:junit4] 2> 3352 T1446 oasc.SolrCore.initIndex WARNING [collection= 1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-134805887674= 0/jetty1/index' doesn't exist. Creating new index... [junit4:junit4] 2> 3353 T1446 oasc.CachingDirectoryFactory.get return new= directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.= x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-= 1348058876740/jetty1/index forceNew:false [junit4:junit4] 2> 3358 T1446 oasc.SolrDeletionPolicy.onCommit SolrDeleti= onPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/jetty1/index,segFN=3Dsegments_1,genera= tion=3D1,filenames=3D[segments_1] [junit4:junit4] 2> 3359 T1446 oasc.SolrDeletionPolicy.updateCommits newes= t commit =3D 1 [junit4:junit4] 2> 3359 T1446 oasc.SolrCore.initWriters created xml: solr= .XMLResponseWriter [junit4:junit4] 2> 3361 T1446 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe" [junit4:junit4] 2> 3361 T1446 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe-allfields" [junit4:junit4] 2> 3362 T1446 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "s= tored_sig" [junit4:junit4] 2> 3362 T1446 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "u= niq-fields" [junit4:junit4] 2> 3363 T1446 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= istrib-dup-test-chain-implicit" [junit4:junit4] 2> 3363 T1446 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 3363 T1446 oasc.RequestHandlers.initHandlersFromConfig= created /replication: solr.ReplicationHandler [junit4:junit4] 2> 3364 T1446 oasc.RequestHandlers.initHandlersFromConfig= created standard: solr.StandardRequestHandler [junit4:junit4] 2> 3365 T1446 oasc.RequestHandlers.initHandlersFromConfig= created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 3365 T1446 oasc.RequestHandlers.initHandlersFromConfig= created dismax: solr.SearchHandler [junit4:junit4] 2> 3366 T1446 oasc.RequestHandlers.initHandlersFromConfig= created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler [junit4:junit4] 2> 3366 T1446 oasc.RequestHandlers.initHandlersFromConfig= created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 3367 T1446 oasc.RequestHandlers.initHandlersFromConfig= created defaults: solr.StandardRequestHandler [junit4:junit4] 2> 3367 T1446 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.StandardRequestHandler [junit4:junit4] 2> 3367 T1446 oasc.RequestHandlers.initHandlersFromConfig= created lazy: solr.StandardRequestHandler [junit4:junit4] 2> 3368 T1446 oasc.RequestHandlers.initHandlersFromConfig= created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 3368 T1446 oasc.RequestHandlers.initHandlersFromConfig= created /terms: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 3369 T1446 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 3369 T1446 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchH= andler [junit4:junit4] 2> 3370 T1446 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchH= andler [junit4:junit4] 2> 3370 T1446 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.= SearchHandler [junit4:junit4] 2> 3371 T1446 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 3371 T1446 oasc.RequestHandlers.initHandlersFromConfig= created tvrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 3372 T1446 oasc.RequestHandlers.initHandlersFromConfig= created /mlt: solr.MoreLikeThisHandler [junit4:junit4] 2> 3372 T1446 oasc.RequestHandlers.initHandlersFromConfig= created /debug/dump: solr.DumpRequestHandler [junit4:junit4] 2> 3375 T1446 oashl.XMLLoader.init xsltCacheLifetimeSecon= ds=3D60 [junit4:junit4] 2> 3378 T1446 oasc.SolrCore.initDeprecatedSupport WARNING= solrconfig.xml uses deprecated , Please update your c= onfig to use the ShowFileRequestHandler. [junit4:junit4] 2> 3379 T1446 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> 3381 T1446 oass.SolrIndexSearcher. Opening Searc= her@5b5b072f main [junit4:junit4] 2> 3382 T1446 oasu.CommitTracker. Hard AutoCommit: = disabled [junit4:junit4] 2> 3383 T1446 oasu.CommitTracker. Soft AutoCommit: = disabled [junit4:junit4] 2> 3383 T1446 oashc.SpellCheckComponent.inform Initializi= ng spell checkers [junit4:junit4] 2> 3389 T1446 oass.DirectSolrSpellChecker.init init: {nam= e=3Ddirect,classname=3DDirectSolrSpellChecker,field=3Dlowerfilt,minQueryLen= gth=3D3} [junit4:junit4] 2> 3438 T1481 oasc.SolrCore.registerSearcher [collection1= ] Registered new searcher Searcher@5b5b072f main{StandardDirectoryReader(se= gments_1:1)} [junit4:junit4] 2> 3533 T1467 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 3547 T1480 oascc.ZkStateReader$2.process A cluster sta= te change has occurred - updating... [junit4:junit4] 2> 3547 T1466 oascc.ZkStateReader$2.process A cluster sta= te change has occurred - updating... [junit4:junit4] 2> 3945 T1446 oasc.CoreContainer.register registering cor= e: collection1 [junit4:junit4] 2> 3945 T1446 oasc.ZkController.register Register shard -= core:collection1 address:http://127.0.0.1:57977/solr shardId:shard1 [junit4:junit4] 2> 3946 T1446 oascc.SolrZkClient.makePath makePath: /coll= ections/collection1/leader_elect/shard1/election [junit4:junit4] 2> 4036 T1451 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x139de920b480003 type:del= ete cxid:0x43 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Pat= h:/solr/collections/collection1/leaders Error:KeeperErrorCode =3D NoNode fo= r /solr/collections/collection1/leaders [junit4:junit4] 2> 4059 T1446 oasc.ShardLeaderElectionContext.runLeaderPr= ocess Running the leader process. [junit4:junit4] 2> 4059 T1451 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x139de920b480003 type:cre= ate cxid:0x44 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Pat= h:/solr/overseer Error:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 4090 T1446 oasc.ShardLeaderElectionContext.waitForRepl= icasToComeUp Enough replicas found to continue. [junit4:junit4] 2> 4090 T1446 oasc.ShardLeaderElectionContext.runLeaderPr= ocess I may be the new leader - try and sync [junit4:junit4] 2> 4090 T1446 oasc.SyncStrategy.sync Sync replicas to htt= p://127.0.0.1:57977/solr/collection1/ [junit4:junit4] 2> 4090 T1446 oasc.SyncStrategy.syncReplicas Sync Success= - now sync replicas to me [junit4:junit4] 2> 4091 T1446 oasc.SyncStrategy.syncToMe http://127.0.0.1= :57977/solr/collection1/ has no replicas [junit4:junit4] 2> 4091 T1446 oasc.ShardLeaderElectionContext.runLeaderPr= ocess I am the new leader: http://127.0.0.1:57977/solr/collection1/ [junit4:junit4] 2> 4091 T1446 oascc.SolrZkClient.makePath makePath: /coll= ections/collection1/leaders/shard1 [junit4:junit4] 2> 4124 T1451 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x139de920b480003 type:cre= ate cxid:0x4e zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Pat= h:/solr/overseer Error:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 4560 T1467 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 4600 T1480 oascc.ZkStateReader$2.process A cluster sta= te change has occurred - updating... [junit4:junit4] 2> 4600 T1466 oascc.ZkStateReader$2.process A cluster sta= te change has occurred - updating... [junit4:junit4] 2> 4635 T1446 oasc.ZkController.register We are http://12= 7.0.0.1:57977/solr/collection1/ and leader is http://127.0.0.1:57977/solr/c= ollection1/ [junit4:junit4] 2> 4635 T1446 oasc.ZkController.register No LogReplay nee= ded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:57977/solr [junit4:junit4] 2> 4636 T1446 oasc.ZkController.checkRecovery I am the le= ader, no recovery necessary [junit4:junit4] 2> 4638 T1446 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 4639 T1446 oass.SolrDispatchFilter.init user.dir=3D/us= r/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build= /solr-core/test/J1 [junit4:junit4] 2> 4639 T1446 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() done [junit4:junit4] 2> 4639 T1446 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&fo= llowRedirects=3Dfalse [junit4:junit4] 2> 5109 T1446 oejs.Server.doStart jetty-8.1.2.v20120308 [junit4:junit4] 2> 5112 T1446 oejs.AbstractConnector.doStart Started Sock= etConnector@0.0.0.0:60077 [junit4:junit4] 2> 5112 T1446 oasc.SolrResourceLoader.locateSolrHome JNDI= not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 5113 T1446 oasc.SolrResourceLoader.locateSolrHome usin= g system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty2-1= 348058881390 [junit4:junit4] 2> 5113 T1446 oasc.SolrResourceLoader. new SolrReso= urceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/= Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty2-= 1348058881390/' [junit4:junit4] 2> 5114 T1467 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 5133 T1480 oascc.ZkStateReader$2.process A cluster sta= te change has occurred - updating... [junit4:junit4] 2> 5133 T1466 oascc.ZkStateReader$2.process A cluster sta= te change has occurred - updating... [junit4:junit4] 2> 5148 T1446 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() [junit4:junit4] 2> 5149 T1446 oasc.SolrResourceLoader.locateSolrHome JNDI= not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 5149 T1446 oasc.SolrResourceLoader.locateSolrHome usin= g system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty2-1= 348058881390 [junit4:junit4] 2> 5150 T1446 oasc.CoreContainer$Initializer.initialize l= ooking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty2-1348058881390/= solr.xml [junit4:junit4] 2> 5150 T1446 oasc.CoreContainer. New CoreContainer= 658201386 [junit4:junit4] 2> 5151 T1446 oasc.CoreContainer.load Loading CoreContain= er using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty2-1348058881390/= ' [junit4:junit4] 2> 5151 T1446 oasc.SolrResourceLoader. new SolrReso= urceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-S= olr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty2-13480588= 81390/' [junit4:junit4] 2> 5176 T1446 oasc.CoreContainer.load Registering Log Lis= tener [junit4:junit4] 2> 5190 T1446 oasc.CoreContainer.initZooKeeper Zookeeper = client=3D127.0.0.1:26491/solr [junit4:junit4] 2> 5191 T1446 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:26491/solr sessionTimeout=3D5000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@3bcd6b3c [junit4:junit4] 2> 5192 T1491 oaz.ClientCnxn$SendThread.startConnect Open= ing socket connection to server /127.0.0.1:26491 [junit4:junit4] 2> 5192 T1446 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 5193 T1491 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost/127.0.0.1:26491, initiating sessi= on [junit4:junit4] 2> 5193 T1448 oazs.NIOServerCnxn$Factory.run Accepted soc= ket connection from /140.211.11.196:14502 [junit4:junit4] 2> 5193 T1448 oazs.NIOServerCnxn.readConnectRequest Clien= t attempting to establish new session at /140.211.11.196:14502 [junit4:junit4] 2> 5195 T1450 oazs.NIOServerCnxn.finishSessionInit Establ= ished session 0x139de920b480004 with negotiated timeout 5000 for client /14= 0.211.11.196:14502 [junit4:junit4] 2> 5195 T1491 oaz.ClientCnxn$SendThread.readConnectResult= Session establishment complete on server localhost/127.0.0.1:26491, sessio= nid =3D 0x139de920b480004, negotiated timeout =3D 5000 [junit4:junit4] 2> 5195 T1492 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@3bcd6b3c name:ZooKeeperConnecti= on Watcher:127.0.0.1:26491/solr got event WatchedEvent state:SyncConnected = type:None path:null path:null type:None [junit4:junit4] 2> 5196 T1446 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 5196 T1451 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x139de920b480004 type:cre= ate cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path= :/solr/overseer Error:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 5198 T1451 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x139de920b480004 type:cre= ate cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path= :/solr/overseer Error:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 5206 T1446 oasc.ZkController.createEphemeralLiveNode R= egister node as live in ZooKeeper:/live_nodes/127.0.0.1:60077_solr [junit4:junit4] 2> 5207 T1451 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x139de920b480004 type:del= ete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path= :/solr/live_nodes/127.0.0.1:60077_solr Error:KeeperErrorCode =3D NoNode for= /solr/live_nodes/127.0.0.1:60077_solr [junit4:junit4] 2> 5208 T1446 oascc.SolrZkClient.makePath makePath: /live= _nodes/127.0.0.1:60077_solr [junit4:junit4] 2> 5210 T1466 oascc.ZkStateReader$3.process Updating live= nodes [junit4:junit4] 2> 5210 T1480 oascc.ZkStateReader$3.process Updating live= nodes [junit4:junit4] 2> 5210 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting socketTimeout to: 0 [junit4:junit4] 2> 5211 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting urlScheme to: http:// [junit4:junit4] 2> 5211 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting connTimeout to: 0 [junit4:junit4] 2> 5212 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 5212 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting corePoolSize to: 0 [junit4:junit4] 2> 5213 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 5213 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting maxThreadIdleTime to: 5 [junit4:junit4] 2> 5213 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting sizeOfQueue to: -1 [junit4:junit4] 2> 5214 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting fairnessPolicy to: false [junit4:junit4] 2> 5214 T1446 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000&= socketTimeout=3D0&connTimeout=3D0&retry=3Dfalse [junit4:junit4] 2> 5232 T1446 oascc.ZkStateReader.createClusterStateWatch= ersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 5237 T1446 oasc.CoreContainer.create Creating SolrCore= 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty2-1= 348058881390/collection1 [junit4:junit4] 2> 5238 T1446 oasc.ZkController.createCollectionZkNode Ch= eck for collection zkNode:collection1 [junit4:junit4] 2> 5238 T1446 oasc.ZkController.createCollectionZkNode Co= llection zkNode exists [junit4:junit4] 2> 5239 T1446 oasc.ZkController.readConfigName Load colle= ction config from:/collections/collection1 [junit4:junit4] 2> 5240 T1446 oasc.SolrResourceLoader. new SolrReso= urceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-S= olr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty2-13480588= 81390/collection1/' [junit4:junit4] 2> 5241 T1446 oasc.SolrResourceLoader.replaceClassLoader = Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-= Java6/solr/build/solr-core/test/J1/solrtest-jetty2-1348058881390/collection= 1/lib/classes/' to classloader [junit4:junit4] 2> 5242 T1446 oasc.SolrResourceLoader.replaceClassLoader = Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-= Java6/solr/build/solr-core/test/J1/solrtest-jetty2-1348058881390/collection= 1/lib/README' to classloader [junit4:junit4] 2> 5290 T1446 oasc.SolrConfig. Using Lucene MatchVe= rsion: LUCENE_40 [junit4:junit4] 2> 5359 T1446 oasc.SolrConfig. Loaded SolrConfig: s= olrconfig.xml [junit4:junit4] 2> 5459 T1446 oass.IndexSchema.readSchema Reading Solr Sc= hema [junit4:junit4] 2> 5465 T1446 oass.IndexSchema.readSchema Schema name=3Dt= est [junit4:junit4] 2> 6063 T1446 oass.OpenExchangeRatesOrgProvider.init Init= ialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 6074 T1446 oass.IndexSchema.readSchema default search = field in schema is text [junit4:junit4] 2> 6078 T1446 oass.IndexSchema.readSchema unique key fiel= d: id [junit4:junit4] 2> 6088 T1446 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 6093 T1446 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 6097 T1446 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 6098 T1446 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 6100 T1446 oasc.SolrCore. [collection1] Opening = new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4= .x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty2-1348058881390/colle= ction1/, dataDir=3D./org.apache.solr.cloud.SyncSliceTest-1348058876740/jett= y2/ [junit4:junit4] 2> 6100 T1446 oasc.JmxMonitoredMap. JMX monitoring = is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMB= eanServer@14426a6 [junit4:junit4] 2> 6102 T1446 oasc.SolrCore.getNewIndexDir WARNING New in= dex directory detected: old=3Dnull new=3D./org.apache.solr.cloud.SyncSliceT= est-1348058876740/jetty2/index/ [junit4:junit4] 2> 6103 T1446 oasc.SolrCore.initIndex WARNING [collection= 1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-134805887674= 0/jetty2/index' doesn't exist. Creating new index... [junit4:junit4] 2> 6104 T1446 oasc.CachingDirectoryFactory.get return new= directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.= x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-= 1348058876740/jetty2/index forceNew:false [junit4:junit4] 2> 6137 T1446 oasc.SolrDeletionPolicy.onCommit SolrDeleti= onPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/jetty2/index,segFN=3Dsegments_1,genera= tion=3D1,filenames=3D[segments_1] [junit4:junit4] 2> 6137 T1446 oasc.SolrDeletionPolicy.updateCommits newes= t commit =3D 1 [junit4:junit4] 2> 6138 T1446 oasc.SolrCore.initWriters created xml: solr= .XMLResponseWriter [junit4:junit4] 2> 6141 T1446 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe" [junit4:junit4] 2> 6141 T1446 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe-allfields" [junit4:junit4] 2> 6142 T1446 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "s= tored_sig" [junit4:junit4] 2> 6143 T1446 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "u= niq-fields" [junit4:junit4] 2> 6143 T1446 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= istrib-dup-test-chain-implicit" [junit4:junit4] 2> 6144 T1446 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 6144 T1446 oasc.RequestHandlers.initHandlersFromConfig= created /replication: solr.ReplicationHandler [junit4:junit4] 2> 6145 T1446 oasc.RequestHandlers.initHandlersFromConfig= created standard: solr.StandardRequestHandler [junit4:junit4] 2> 6146 T1446 oasc.RequestHandlers.initHandlersFromConfig= created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 6147 T1446 oasc.RequestHandlers.initHandlersFromConfig= created dismax: solr.SearchHandler [junit4:junit4] 2> 6147 T1446 oasc.RequestHandlers.initHandlersFromConfig= created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler [junit4:junit4] 2> 6148 T1446 oasc.RequestHandlers.initHandlersFromConfig= created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 6149 T1446 oasc.RequestHandlers.initHandlersFromConfig= created defaults: solr.StandardRequestHandler [junit4:junit4] 2> 6149 T1446 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.StandardRequestHandler [junit4:junit4] 2> 6150 T1446 oasc.RequestHandlers.initHandlersFromConfig= created lazy: solr.StandardRequestHandler [junit4:junit4] 2> 6151 T1446 oasc.RequestHandlers.initHandlersFromConfig= created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 6152 T1446 oasc.RequestHandlers.initHandlersFromConfig= created /terms: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 6152 T1446 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 6153 T1446 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchH= andler [junit4:junit4] 2> 6154 T1446 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchH= andler [junit4:junit4] 2> 6154 T1446 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.= SearchHandler [junit4:junit4] 2> 6155 T1446 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 6156 T1446 oasc.RequestHandlers.initHandlersFromConfig= created tvrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 6157 T1446 oasc.RequestHandlers.initHandlersFromConfig= created /mlt: solr.MoreLikeThisHandler [junit4:junit4] 2> 6157 T1446 oasc.RequestHandlers.initHandlersFromConfig= created /debug/dump: solr.DumpRequestHandler [junit4:junit4] 2> 6161 T1446 oashl.XMLLoader.init xsltCacheLifetimeSecon= ds=3D60 [junit4:junit4] 2> 6166 T1446 oasc.SolrCore.initDeprecatedSupport WARNING= solrconfig.xml uses deprecated , Please update your c= onfig to use the ShowFileRequestHandler. [junit4:junit4] 2> 6167 T1446 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> 6171 T1446 oass.SolrIndexSearcher. Opening Searc= her@6e6017e7 main [junit4:junit4] 2> 6172 T1446 oasu.CommitTracker. Hard AutoCommit: = disabled [junit4:junit4] 2> 6173 T1446 oasu.CommitTracker. Soft AutoCommit: = disabled [junit4:junit4] 2> 6174 T1446 oashc.SpellCheckComponent.inform Initializi= ng spell checkers [junit4:junit4] 2> 6182 T1446 oass.DirectSolrSpellChecker.init init: {nam= e=3Ddirect,classname=3DDirectSolrSpellChecker,field=3Dlowerfilt,minQueryLen= gth=3D3} [junit4:junit4] 2> 6239 T1493 oasc.SolrCore.registerSearcher [collection1= ] Registered new searcher Searcher@6e6017e7 main{StandardDirectoryReader(se= gments_1:1)} [junit4:junit4] 2> 6637 T1467 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 6650 T1480 oascc.ZkStateReader$2.process A cluster sta= te change has occurred - updating... [junit4:junit4] 2> 6650 T1492 oascc.ZkStateReader$2.process A cluster sta= te change has occurred - updating... [junit4:junit4] 2> 6650 T1466 oascc.ZkStateReader$2.process A cluster sta= te change has occurred - updating... [junit4:junit4] 2> 6748 T1446 oasc.CoreContainer.register registering cor= e: collection1 [junit4:junit4] 2> 6748 T1446 oasc.ZkController.register Register shard -= core:collection1 address:http://127.0.0.1:60077/solr shardId:shard1 [junit4:junit4] 2> 6751 T1446 oasc.ZkController.register We are http://12= 7.0.0.1:60077/solr/collection1/ and leader is http://127.0.0.1:57977/solr/c= ollection1/ [junit4:junit4] 2> 6751 T1446 oasc.ZkController.register No LogReplay nee= ded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:60077/solr [junit4:junit4] 2> 6751 T1446 oasc.ZkController.checkRecovery Core needs = to recover:collection1 [junit4:junit4] 2> 6752 T1446 oasu.DefaultSolrCoreState.doRecovery Runnin= g recovery - first canceling any ongoing recovery [junit4:junit4] 2> ASYNC NEW_CORE C100 name=3Dcollection1 org.apache.sol= r.core.SolrCore@5d811d55 url=3Dhttp://127.0.0.1:60077/solr/collection1 node= =3D127.0.0.1:60077_solr [junit4:junit4] 2> 6753 T1494 C100 P60077 oasc.RecoveryStrategy.run Start= ing recovery process. core=3Dcollection1 recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 6753 T1446 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 6754 T1494 C100 P60077 oasc.RecoveryStrategy.doRecover= y ###### startupVersions=3D[] [junit4:junit4] 2> 6755 T1446 oass.SolrDispatchFilter.init user.dir=3D/us= r/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build= /solr-core/test/J1 [junit4:junit4] 2> 6755 T1446 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() done [junit4:junit4] 2> 6755 T1494 C100 P60077 oasc.RecoveryStrategy.doRecover= y Attempting to PeerSync from http://127.0.0.1:57977/solr/collection1/ core= =3Dcollection1 - recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 6756 T1494 C100 P60077 oasu.PeerSync.sync PeerSync: co= re=3Dcollection1 url=3Dhttp://127.0.0.1:60077/solr START replicas=3D[http:/= /127.0.0.1:57977/solr/collection1/] nUpdates=3D100 [junit4:junit4] 2> 6756 T1446 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&fo= llowRedirects=3Dfalse [junit4:junit4] 2> 6756 T1494 C100 P60077 oasu.PeerSync.sync WARNING no f= rame of reference to tell of we've missed updates [junit4:junit4] 2> 6757 T1494 C100 P60077 oasc.RecoveryStrategy.doRecover= y PeerSync Recovery was not successful - trying replication. core=3Dcollect= ion1 [junit4:junit4] 2> 6757 T1494 C100 P60077 oasc.RecoveryStrategy.doRecover= y Starting Replication Recovery. core=3Dcollection1 [junit4:junit4] 2> 6757 T1494 C100 P60077 oascsi.HttpClientUtil.createCli= ent Creating new http client, config:maxConnections=3D128&maxConnectionsPer= Host=3D32&followRedirects=3Dfalse [junit4:junit4] 2> ASYNC NEW_CORE C101 name=3Dcollection1 org.apache.sol= r.core.SolrCore@12b69af7 url=3Dhttp://127.0.0.1:57977/solr/collection1 node= =3D127.0.0.1:57977_solr [junit4:junit4] 2> 6766 T1472 C101 P57977 REQ /get {distrib=3Dfalse&qt=3D= /get&wt=3Djavabin&version=3D2&getVersions=3D100} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 7154 T1467 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 7175 T1480 oascc.ZkStateReader$2.process A cluster sta= te change has occurred - updating... [junit4:junit4] 2> 7175 T1492 oascc.ZkStateReader$2.process A cluster sta= te change has occurred - updating... [junit4:junit4] 2> 7175 T1466 oascc.ZkStateReader$2.process A cluster sta= te change has occurred - updating... [junit4:junit4] 2> 7224 T1446 oejs.Server.doStart jetty-8.1.2.v20120308 [junit4:junit4] 2> 7227 T1446 oejs.AbstractConnector.doStart Started Sock= etConnector@0.0.0.0:19335 [junit4:junit4] 2> 7227 T1446 oasc.SolrResourceLoader.locateSolrHome JNDI= not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 7228 T1446 oasc.SolrResourceLoader.locateSolrHome usin= g system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty3-1= 348058883515 [junit4:junit4] 2> 7228 T1446 oasc.SolrResourceLoader. new SolrReso= urceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/= Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty3-= 1348058883515/' [junit4:junit4] 2> 7263 T1446 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() [junit4:junit4] 2> 7263 T1446 oasc.SolrResourceLoader.locateSolrHome JNDI= not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 7264 T1446 oasc.SolrResourceLoader.locateSolrHome usin= g system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty3-1= 348058883515 [junit4:junit4] 2> 7264 T1446 oasc.CoreContainer$Initializer.initialize l= ooking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty3-1348058883515/= solr.xml [junit4:junit4] 2> 7265 T1446 oasc.CoreContainer. New CoreContainer= 721147002 [junit4:junit4] 2> 7265 T1446 oasc.CoreContainer.load Loading CoreContain= er using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty3-1348058883515/= ' [junit4:junit4] 2> 7266 T1446 oasc.SolrResourceLoader. new SolrReso= urceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-S= olr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty3-13480588= 83515/' [junit4:junit4] 2> 7285 T1446 oasc.CoreContainer.load Registering Log Lis= tener [junit4:junit4] 2> 7299 T1446 oasc.CoreContainer.initZooKeeper Zookeeper = client=3D127.0.0.1:26491/solr [junit4:junit4] 2> 7299 T1446 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:26491/solr sessionTimeout=3D5000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@45fee545 [junit4:junit4] 2> 7300 T1505 oaz.ClientCnxn$SendThread.startConnect Open= ing socket connection to server /127.0.0.1:26491 [junit4:junit4] 2> 7300 T1446 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 7301 T1505 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost/127.0.0.1:26491, initiating sessi= on [junit4:junit4] 2> 7301 T1448 oazs.NIOServerCnxn$Factory.run Accepted soc= ket connection from /140.211.11.196:60051 [junit4:junit4] 2> 7302 T1448 oazs.NIOServerCnxn.readConnectRequest Clien= t attempting to establish new session at /140.211.11.196:60051 [junit4:junit4] 2> 7303 T1450 oazs.NIOServerCnxn.finishSessionInit Establ= ished session 0x139de920b480005 with negotiated timeout 5000 for client /14= 0.211.11.196:60051 [junit4:junit4] 2> 7303 T1505 oaz.ClientCnxn$SendThread.readConnectResult= Session establishment complete on server localhost/127.0.0.1:26491, sessio= nid =3D 0x139de920b480005, negotiated timeout =3D 5000 [junit4:junit4] 2> 7304 T1506 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@45fee545 name:ZooKeeperConnecti= on Watcher:127.0.0.1:26491/solr got event WatchedEvent state:SyncConnected = type:None path:null path:null type:None [junit4:junit4] 2> 7304 T1446 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 7304 T1451 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x139de920b480005 type:cre= ate cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path= :/solr/overseer Error:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 7306 T1451 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x139de920b480005 type:cre= ate cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path= :/solr/overseer Error:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 7315 T1446 oasc.ZkController.createEphemeralLiveNode R= egister node as live in ZooKeeper:/live_nodes/127.0.0.1:19335_solr [junit4:junit4] 2> 7316 T1451 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x139de920b480005 type:del= ete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path= :/solr/live_nodes/127.0.0.1:19335_solr Error:KeeperErrorCode =3D NoNode for= /solr/live_nodes/127.0.0.1:19335_solr [junit4:junit4] 2> 7317 T1446 oascc.SolrZkClient.makePath makePath: /live= _nodes/127.0.0.1:19335_solr [junit4:junit4] 2> 7318 T1480 oascc.ZkStateReader$3.process Updating live= nodes [junit4:junit4] 2> 7318 T1466 oascc.ZkStateReader$3.process Updating live= nodes [junit4:junit4] 2> 7318 T1492 oascc.ZkStateReader$3.process Updating live= nodes [junit4:junit4] 2> 7319 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting socketTimeout to: 0 [junit4:junit4] 2> 7319 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting urlScheme to: http:// [junit4:junit4] 2> 7320 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting connTimeout to: 0 [junit4:junit4] 2> 7320 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 7320 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting corePoolSize to: 0 [junit4:junit4] 2> 7320 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 7321 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting maxThreadIdleTime to: 5 [junit4:junit4] 2> 7321 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting sizeOfQueue to: -1 [junit4:junit4] 2> 7321 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting fairnessPolicy to: false [junit4:junit4] 2> 7321 T1446 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000&= socketTimeout=3D0&connTimeout=3D0&retry=3Dfalse [junit4:junit4] 2> 7333 T1446 oascc.ZkStateReader.createClusterStateWatch= ersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 7338 T1446 oasc.CoreContainer.create Creating SolrCore= 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty3-1= 348058883515/collection1 [junit4:junit4] 2> 7338 T1446 oasc.ZkController.createCollectionZkNode Ch= eck for collection zkNode:collection1 [junit4:junit4] 2> 7338 T1446 oasc.ZkController.createCollectionZkNode Co= llection zkNode exists [junit4:junit4] 2> 7339 T1446 oasc.ZkController.readConfigName Load colle= ction config from:/collections/collection1 [junit4:junit4] 2> 7340 T1446 oasc.SolrResourceLoader. new SolrReso= urceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-S= olr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty3-13480588= 83515/collection1/' [junit4:junit4] 2> 7340 T1446 oasc.SolrResourceLoader.replaceClassLoader = Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-= Java6/solr/build/solr-core/test/J1/solrtest-jetty3-1348058883515/collection= 1/lib/classes/' to classloader [junit4:junit4] 2> 7341 T1446 oasc.SolrResourceLoader.replaceClassLoader = Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-= Java6/solr/build/solr-core/test/J1/solrtest-jetty3-1348058883515/collection= 1/lib/README' to classloader [junit4:junit4] 2> 7373 T1446 oasc.SolrConfig. Using Lucene MatchVe= rsion: LUCENE_40 [junit4:junit4] 2> 7435 T1446 oasc.SolrConfig. Loaded SolrConfig: s= olrconfig.xml [junit4:junit4] 2> 7536 T1446 oass.IndexSchema.readSchema Reading Solr Sc= hema [junit4:junit4] 2> 7540 T1446 oass.IndexSchema.readSchema Schema name=3Dt= est [junit4:junit4] 2> 7936 T1446 oass.OpenExchangeRatesOrgProvider.init Init= ialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 7943 T1446 oass.IndexSchema.readSchema default search = field in schema is text [junit4:junit4] 2> 7946 T1446 oass.IndexSchema.readSchema unique key fiel= d: id [junit4:junit4] 2> 7954 T1446 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 7957 T1446 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 7960 T1446 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 7961 T1446 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 7962 T1446 oasc.SolrCore. [collection1] Opening = new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4= .x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty3-1348058883515/colle= ction1/, dataDir=3D./org.apache.solr.cloud.SyncSliceTest-1348058876740/jett= y3/ [junit4:junit4] 2> 7962 T1446 oasc.JmxMonitoredMap. JMX monitoring = is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMB= eanServer@14426a6 [junit4:junit4] 2> 7963 T1446 oasc.SolrCore.getNewIndexDir WARNING New in= dex directory detected: old=3Dnull new=3D./org.apache.solr.cloud.SyncSliceT= est-1348058876740/jetty3/index/ [junit4:junit4] 2> 7964 T1446 oasc.SolrCore.initIndex WARNING [collection= 1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-134805887674= 0/jetty3/index' doesn't exist. Creating new index... [junit4:junit4] 2> 7964 T1446 oasc.CachingDirectoryFactory.get return new= directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.= x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-= 1348058876740/jetty3/index forceNew:false [junit4:junit4] 2> 7994 T1446 oasc.SolrDeletionPolicy.onCommit SolrDeleti= onPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/jetty3/index,segFN=3Dsegments_1,genera= tion=3D1,filenames=3D[segments_1] [junit4:junit4] 2> 7994 T1446 oasc.SolrDeletionPolicy.updateCommits newes= t commit =3D 1 [junit4:junit4] 2> 7995 T1446 oasc.SolrCore.initWriters created xml: solr= .XMLResponseWriter [junit4:junit4] 2> 7997 T1446 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe" [junit4:junit4] 2> 7997 T1446 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe-allfields" [junit4:junit4] 2> 7997 T1446 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "s= tored_sig" [junit4:junit4] 2> 7998 T1446 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "u= niq-fields" [junit4:junit4] 2> 7998 T1446 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= istrib-dup-test-chain-implicit" [junit4:junit4] 2> 7999 T1446 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 7999 T1446 oasc.RequestHandlers.initHandlersFromConfig= created /replication: solr.ReplicationHandler [junit4:junit4] 2> 7999 T1446 oasc.RequestHandlers.initHandlersFromConfig= created standard: solr.StandardRequestHandler [junit4:junit4] 2> 8000 T1446 oasc.RequestHandlers.initHandlersFromConfig= created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 8001 T1446 oasc.RequestHandlers.initHandlersFromConfig= created dismax: solr.SearchHandler [junit4:junit4] 2> 8001 T1446 oasc.RequestHandlers.initHandlersFromConfig= created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler [junit4:junit4] 2> 8001 T1446 oasc.RequestHandlers.initHandlersFromConfig= created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 8002 T1446 oasc.RequestHandlers.initHandlersFromConfig= created defaults: solr.StandardRequestHandler [junit4:junit4] 2> 8002 T1446 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.StandardRequestHandler [junit4:junit4] 2> 8003 T1446 oasc.RequestHandlers.initHandlersFromConfig= created lazy: solr.StandardRequestHandler [junit4:junit4] 2> 8003 T1446 oasc.RequestHandlers.initHandlersFromConfig= created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 8004 T1446 oasc.RequestHandlers.initHandlersFromConfig= created /terms: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 8004 T1446 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 8005 T1446 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchH= andler [junit4:junit4] 2> 8005 T1446 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchH= andler [junit4:junit4] 2> 8006 T1446 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.= SearchHandler [junit4:junit4] 2> 8006 T1446 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 8007 T1446 oasc.RequestHandlers.initHandlersFromConfig= created tvrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 8007 T1446 oasc.RequestHandlers.initHandlersFromConfig= created /mlt: solr.MoreLikeThisHandler [junit4:junit4] 2> 8008 T1446 oasc.RequestHandlers.initHandlersFromConfig= created /debug/dump: solr.DumpRequestHandler [junit4:junit4] 2> 8010 T1446 oashl.XMLLoader.init xsltCacheLifetimeSecon= ds=3D60 [junit4:junit4] 2> 8013 T1446 oasc.SolrCore.initDeprecatedSupport WARNING= solrconfig.xml uses deprecated , Please update your c= onfig to use the ShowFileRequestHandler. [junit4:junit4] 2> 8014 T1446 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> 8017 T1446 oass.SolrIndexSearcher. Opening Searc= her@1246c18c main [junit4:junit4] 2> 8018 T1446 oasu.CommitTracker. Hard AutoCommit: = disabled [junit4:junit4] 2> 8018 T1446 oasu.CommitTracker. Soft AutoCommit: = disabled [junit4:junit4] 2> 8019 T1446 oashc.SpellCheckComponent.inform Initializi= ng spell checkers [junit4:junit4] 2> 8025 T1446 oass.DirectSolrSpellChecker.init init: {nam= e=3Ddirect,classname=3DDirectSolrSpellChecker,field=3Dlowerfilt,minQueryLen= gth=3D3} [junit4:junit4] 2> 8076 T1507 oasc.SolrCore.registerSearcher [collection1= ] Registered new searcher Searcher@1246c18c main{StandardDirectoryReader(se= gments_1:1)} [junit4:junit4] 2> 8180 T1467 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 8193 T1506 oascc.ZkStateReader$2.process A cluster sta= te change has occurred - updating... [junit4:junit4] 2> 8193 T1480 oascc.ZkStateReader$2.process A cluster sta= te change has occurred - updating... [junit4:junit4] 2> 8193 T1492 oascc.ZkStateReader$2.process A cluster sta= te change has occurred - updating... [junit4:junit4] 2> 8193 T1466 oascc.ZkStateReader$2.process A cluster sta= te change has occurred - updating... [junit4:junit4] 2> 8582 T1446 oasc.CoreContainer.register registering cor= e: collection1 [junit4:junit4] 2> 8582 T1446 oasc.ZkController.register Register shard -= core:collection1 address:http://127.0.0.1:19335/solr shardId:shard1 [junit4:junit4] 2> 8584 T1446 oasc.ZkController.register We are http://12= 7.0.0.1:19335/solr/collection1/ and leader is http://127.0.0.1:57977/solr/c= ollection1/ [junit4:junit4] 2> 8585 T1446 oasc.ZkController.register No LogReplay nee= ded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:19335/solr [junit4:junit4] 2> 8585 T1446 oasc.ZkController.checkRecovery Core needs = to recover:collection1 [junit4:junit4] 2> 8586 T1446 oasu.DefaultSolrCoreState.doRecovery Runnin= g recovery - first canceling any ongoing recovery [junit4:junit4] 2> ASYNC NEW_CORE C102 name=3Dcollection1 org.apache.sol= r.core.SolrCore@3776648f url=3Dhttp://127.0.0.1:19335/solr/collection1 node= =3D127.0.0.1:19335_solr [junit4:junit4] 2> 8587 T1508 C102 P19335 oasc.RecoveryStrategy.run Start= ing recovery process. core=3Dcollection1 recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 8587 T1508 C102 P19335 oasc.RecoveryStrategy.doRecover= y ###### startupVersions=3D[] [junit4:junit4] 2> 8587 T1446 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 8588 T1508 C102 P19335 oasc.RecoveryStrategy.doRecover= y Attempting to PeerSync from http://127.0.0.1:57977/solr/collection1/ core= =3Dcollection1 - recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 8588 T1508 C102 P19335 oasu.PeerSync.sync PeerSync: co= re=3Dcollection1 url=3Dhttp://127.0.0.1:19335/solr START replicas=3D[http:/= /127.0.0.1:57977/solr/collection1/] nUpdates=3D100 [junit4:junit4] 2> 8588 T1446 oass.SolrDispatchFilter.init user.dir=3D/us= r/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build= /solr-core/test/J1 [junit4:junit4] 2> 8589 T1508 C102 P19335 oasu.PeerSync.sync WARNING no f= rame of reference to tell of we've missed updates [junit4:junit4] 2> 8589 T1508 C102 P19335 oasc.RecoveryStrategy.doRecover= y PeerSync Recovery was not successful - trying replication. core=3Dcollect= ion1 [junit4:junit4] 2> 8589 T1446 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() done [junit4:junit4] 2> 8589 T1508 C102 P19335 oasc.RecoveryStrategy.doRecover= y Starting Replication Recovery. core=3Dcollection1 [junit4:junit4] 2> 8590 T1508 C102 P19335 oascsi.HttpClientUtil.createCli= ent Creating new http client, config:maxConnections=3D128&maxConnectionsPer= Host=3D32&followRedirects=3Dfalse [junit4:junit4] 2> 8590 T1446 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&fo= llowRedirects=3Dfalse [junit4:junit4] 2> 8591 T1472 C101 P57977 REQ /get {distrib=3Dfalse&qt=3D= /get&wt=3Djavabin&version=3D2&getVersions=3D100} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 8696 T1467 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 8712 T1480 oascc.ZkStateReader$2.process A cluster sta= te change has occurred - updating... [junit4:junit4] 2> 8712 T1492 oascc.ZkStateReader$2.process A cluster sta= te change has occurred - updating... [junit4:junit4] 2> 8712 T1466 oascc.ZkStateReader$2.process A cluster sta= te change has occurred - updating... [junit4:junit4] 2> 8712 T1506 oascc.ZkStateReader$2.process A cluster sta= te change has occurred - updating... [junit4:junit4] 2> 9076 T1446 oejs.Server.doStart jetty-8.1.2.v20120308 [junit4:junit4] 2> 9079 T1446 oejs.AbstractConnector.doStart Started Sock= etConnector@0.0.0.0:41421 [junit4:junit4] 2> 9079 T1446 oasc.SolrResourceLoader.locateSolrHome JNDI= not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 9080 T1446 oasc.SolrResourceLoader.locateSolrHome usin= g system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty4-1= 348058885343 [junit4:junit4] 2> 9080 T1446 oasc.SolrResourceLoader. new SolrReso= urceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/= Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty4-= 1348058885343/' [junit4:junit4] 2> 9115 T1446 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() [junit4:junit4] 2> 9115 T1446 oasc.SolrResourceLoader.locateSolrHome JNDI= not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 9115 T1446 oasc.SolrResourceLoader.locateSolrHome usin= g system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty4-1= 348058885343 [junit4:junit4] 2> 9116 T1446 oasc.CoreContainer$Initializer.initialize l= ooking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty4-1348058885343/= solr.xml [junit4:junit4] 2> 9116 T1446 oasc.CoreContainer. New CoreContainer= 70264423 [junit4:junit4] 2> 9117 T1446 oasc.CoreContainer.load Loading CoreContain= er using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty4-1348058885343/= ' [junit4:junit4] 2> 9117 T1446 oasc.SolrResourceLoader. new SolrReso= urceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-S= olr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty4-13480588= 85343/' [junit4:junit4] 2> 9142 T1446 oasc.CoreContainer.load Registering Log Lis= tener [junit4:junit4] 2> 9156 T1446 oasc.CoreContainer.initZooKeeper Zookeeper = client=3D127.0.0.1:26491/solr [junit4:junit4] 2> 9156 T1446 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:26491/solr sessionTimeout=3D5000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@64ae8431 [junit4:junit4] 2> 9157 T1519 oaz.ClientCnxn$SendThread.startConnect Open= ing socket connection to server /127.0.0.1:26491 [junit4:junit4] 2> 9157 T1446 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 9159 T1519 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost/127.0.0.1:26491, initiating sessi= on [junit4:junit4] 2> 9159 T1448 oazs.NIOServerCnxn$Factory.run Accepted soc= ket connection from /140.211.11.196:55280 [junit4:junit4] 2> 9160 T1448 oazs.NIOServerCnxn.readConnectRequest Clien= t attempting to establish new session at /140.211.11.196:55280 [junit4:junit4] 2> 9166 T1450 oazs.NIOServerCnxn.finishSessionInit Establ= ished session 0x139de920b480006 with negotiated timeout 5000 for client /14= 0.211.11.196:55280 [junit4:junit4] 2> 9166 T1519 oaz.ClientCnxn$SendThread.readConnectResult= Session establishment complete on server localhost/127.0.0.1:26491, sessio= nid =3D 0x139de920b480006, negotiated timeout =3D 5000 [junit4:junit4] 2> 9167 T1520 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@64ae8431 name:ZooKeeperConnecti= on Watcher:127.0.0.1:26491/solr got event WatchedEvent state:SyncConnected = type:None path:null path:null type:None [junit4:junit4] 2> 9167 T1446 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 9167 T1451 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x139de920b480006 type:cre= ate cxid:0x1 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path= :/solr/overseer Error:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 9168 T1451 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x139de920b480006 type:cre= ate cxid:0x2 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path= :/solr/overseer Error:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 9170 T1446 oasc.ZkController.createEphemeralLiveNode R= egister node as live in ZooKeeper:/live_nodes/127.0.0.1:41421_solr [junit4:junit4] 2> 9170 T1451 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x139de920b480006 type:del= ete cxid:0x4 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path= :/solr/live_nodes/127.0.0.1:41421_solr Error:KeeperErrorCode =3D NoNode for= /solr/live_nodes/127.0.0.1:41421_solr [junit4:junit4] 2> 9171 T1446 oascc.SolrZkClient.makePath makePath: /live= _nodes/127.0.0.1:41421_solr [junit4:junit4] 2> 9173 T1480 oascc.ZkStateReader$3.process Updating live= nodes [junit4:junit4] 2> 9173 T1466 oascc.ZkStateReader$3.process Updating live= nodes [junit4:junit4] 2> 9173 T1506 oascc.ZkStateReader$3.process Updating live= nodes [junit4:junit4] 2> 9173 T1492 oascc.ZkStateReader$3.process Updating live= nodes [junit4:junit4] 2> 9173 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting socketTimeout to: 0 [junit4:junit4] 2> 9174 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting urlScheme to: http:// [junit4:junit4] 2> 9174 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting connTimeout to: 0 [junit4:junit4] 2> 9174 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 9175 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting corePoolSize to: 0 [junit4:junit4] 2> 9175 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 9176 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting maxThreadIdleTime to: 5 [junit4:junit4] 2> 9176 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting sizeOfQueue to: -1 [junit4:junit4] 2> 9177 T1446 oashc.HttpShardHandlerFactory.getParameter = Setting fairnessPolicy to: false [junit4:junit4] 2> 9177 T1446 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000&= socketTimeout=3D0&connTimeout=3D0&retry=3Dfalse [junit4:junit4] 2> 9192 T1446 oascc.ZkStateReader.createClusterStateWatch= ersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 9198 T1446 oasc.CoreContainer.create Creating SolrCore= 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty4-1= 348058885343/collection1 [junit4:junit4] 2> 9198 T1446 oasc.ZkController.createCollectionZkNode Ch= eck for collection zkNode:collection1 [junit4:junit4] 2> 9199 T1446 oasc.ZkController.createCollectionZkNode Co= llection zkNode exists [junit4:junit4] 2> 9199 T1446 oasc.ZkController.readConfigName Load colle= ction config from:/collections/collection1 [junit4:junit4] 2> 9200 T1446 oasc.SolrResourceLoader. new SolrReso= urceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-S= olr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty4-13480588= 85343/collection1/' [junit4:junit4] 2> 9202 T1446 oasc.SolrResourceLoader.replaceClassLoader = Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-= Java6/solr/build/solr-core/test/J1/solrtest-jetty4-1348058885343/collection= 1/lib/README' to classloader [junit4:junit4] 2> 9202 T1446 oasc.SolrResourceLoader.replaceClassLoader = Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-= Java6/solr/build/solr-core/test/J1/solrtest-jetty4-1348058885343/collection= 1/lib/classes/' to classloader [junit4:junit4] 2> 9250 T1446 oasc.SolrConfig. Using Lucene MatchVe= rsion: LUCENE_40 [junit4:junit4] 2> 9317 T1446 oasc.SolrConfig. Loaded SolrConfig: s= olrconfig.xml [junit4:junit4] 2> 9418 T1446 oass.IndexSchema.readSchema Reading Solr Sc= hema [junit4:junit4] 2> 9424 T1446 oass.IndexSchema.readSchema Schema name=3Dt= est [junit4:junit4] 2> C100_STATE=3Dcoll:collection1 core:collection1 props:= {shard=3Dshard1, roles=3Dnull, state=3Drecovering, core=3Dcollection1, coll= ection=3Dcollection1, node_name=3D127.0.0.1:60077_solr, base_url=3Dhttp://1= 27.0.0.1:60077/solr} [junit4:junit4] 2> 9781 T1494 C100 P60077 oasc.RecoveryStrategy.doRecover= y Begin buffering updates. core=3Dcollection1 [junit4:junit4] 2> 9781 T1494 C100 P60077 oasu.UpdateLog.bufferUpdates St= arting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog=3Dnull} [junit4:junit4] 2> 9781 T1494 C100 P60077 oasc.RecoveryStrategy.replicate= Attempting to replicate from http://127.0.0.1:57977/solr/collection1/. cor= e=3Dcollection1 [junit4:junit4] 2> 9781 T1494 C100 P60077 oascsi.HttpClientUtil.createCli= ent Creating new http client, config:maxConnections=3D128&maxConnectionsPer= Host=3D32&followRedirects=3Dfalse [junit4:junit4] 2> 9792 T1475 C101 P57977 oasu.DirectUpdateHandler2.commi= t start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dtrue= ,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 9797 T1475 C101 P57977 oasc.SolrDeletionPolicy.onInit = SolrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/jetty1/index,segFN=3Dsegments_1,genera= tion=3D1,filenames=3D[segments_1] [junit4:junit4] 2> 9797 T1475 C101 P57977 oasc.SolrDeletionPolicy.updateC= ommits newest commit =3D 1 [junit4:junit4] 2> 9799 T1475 C101 P57977 oass.SolrIndexSearcher. O= pening Searcher@5014be26 main [junit4:junit4] 2> 9799 T1475 C101 P57977 oasu.DirectUpdateHandler2.commi= t end_commit_flush [junit4:junit4] 2> 9801 T1481 oasc.SolrCore.registerSearcher [collection1= ] Registered new searcher Searcher@5014be26 main{StandardDirectoryReader(se= gments_1:1)} [junit4:junit4] 2> 9801 T1475 C101 P57977 /update {waitSearcher=3Dtrue&co= mmit=3Dtrue&commit_end_point=3Dtrue&wt=3Djavabin&softCommit=3Dfalse&version= =3D2} {commit=3D} 0 9 [junit4:junit4] 2> 9802 T1494 C100 P60077 oash.ReplicationHandler.inform = Commits will be reserved for 10000 [junit4:junit4] 2> 9802 T1494 C100 P60077 oash.SnapPuller. No valu= e set for 'pollInterval'. Timer Task not started. [junit4:junit4] 2> 9804 T1476 C101 P57977 oash.ReplicationHandler.inform = Commits will be reserved for 10000 [junit4:junit4] 2> 9804 T1476 C101 P57977 REQ /replication {command=3Dind= exversion&wt=3Djavabin&qt=3D/replication&version=3D2} status=3D0 QTime=3D1= =20 [junit4:junit4] 2> 9809 T1494 C100 P60077 oasc.SolrDeletionPolicy.onInit = SolrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/jetty2/index,segFN=3Dsegments_1,genera= tion=3D1,filenames=3D[segments_1] [junit4:junit4] 2> 9809 T1494 C100 P60077 oasc.SolrDeletionPolicy.updateC= ommits newest commit =3D 1 [junit4:junit4] 2> 9810 T1494 C100 P60077 oasu.DirectUpdateHandler2.commi= t start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dtrue= ,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 9839 T1494 C100 P60077 oasc.SolrDeletionPolicy.onCommi= t SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/jetty2/index,segFN=3Dsegments_1,genera= tion=3D1,filenames=3D[segments_1] [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/jetty2/index,segFN=3Dsegments_2,genera= tion=3D2,filenames=3D[segments_2] [junit4:junit4] 2> 9839 T1494 C100 P60077 oasc.SolrDeletionPolicy.updateC= ommits newest commit =3D 2 [junit4:junit4] 2> 9844 T1494 C100 P60077 oass.SolrIndexSearcher. O= pening Searcher@317bf727 main [junit4:junit4] 2> 9844 T1494 C100 P60077 oasu.DirectUpdateHandler2.commi= t end_commit_flush [junit4:junit4] 2> 9845 T1493 oasc.SolrCore.registerSearcher [collection1= ] Registered new searcher Searcher@317bf727 main{StandardDirectoryReader(se= gments_2:2)} [junit4:junit4] 2> 9846 T1494 C100 P60077 oasc.RecoveryStrategy.replay No= replay needed. core=3Dcollection1 [junit4:junit4] 2> 9846 T1494 C100 P60077 oasc.RecoveryStrategy.doRecover= y Replication Recovery was successful - registering as Active. core=3Dcolle= ction1 [junit4:junit4] 2> 9847 T1494 C100 P60077 oasc.RecoveryStrategy.doRecover= y Finished recovery process. core=3Dcollection1 [junit4:junit4] 2> 10023 T1446 oass.OpenExchangeRatesOrgProvider.init Ini= tialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 10034 T1446 oass.IndexSchema.readSchema default search= field in schema is text [junit4:junit4] 2> 10039 T1446 oass.IndexSchema.readSchema unique key fie= ld: id [junit4:junit4] 2> 10048 T1446 oass.FileExchangeRateProvider.reload Reloa= ding exchange rates from file currency.xml [junit4:junit4] 2> 10058 T1446 oass.FileExchangeRateProvider.reload Reloa= ding exchange rates from file currency.xml [junit4:junit4] 2> 10062 T1446 oass.OpenExchangeRatesOrgProvider.reload R= eloading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 10063 T1446 oass.OpenExchangeRatesOrgProvider.reload R= eloading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 10064 T1446 oasc.SolrCore. [collection1] Opening= new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-= 4.x-Java6/solr/build/solr-core/test/J1/./solrtest-jetty4-1348058885343/coll= ection1/, dataDir=3D./org.apache.solr.cloud.SyncSliceTest-1348058876740/jet= ty4/ [junit4:junit4] 2> 10065 T1446 oasc.JmxMonitoredMap. JMX monitoring= is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxM= BeanServer@14426a6 [junit4:junit4] 2> 10066 T1446 oasc.SolrCore.getNewIndexDir WARNING New i= ndex directory detected: old=3Dnull new=3D./org.apache.solr.cloud.SyncSlice= Test-1348058876740/jetty4/index/ [junit4:junit4] 2> 10067 T1446 oasc.SolrCore.initIndex WARNING [collectio= n1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-13480588767= 40/jetty4/index' doesn't exist. Creating new index... [junit4:junit4] 2> 10068 T1446 oasc.CachingDirectoryFactory.get return ne= w directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4= .x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest= -1348058876740/jetty4/index forceNew:false [junit4:junit4] 2> 10075 T1446 oasc.SolrDeletionPolicy.onCommit SolrDelet= ionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/jetty4/index,segFN=3Dsegments_1,genera= tion=3D1,filenames=3D[segments_1] [junit4:junit4] 2> 10075 T1446 oasc.SolrDeletionPolicy.updateCommits newe= st commit =3D 1 [junit4:junit4] 2> 10076 T1446 oasc.SolrCore.initWriters created xml: sol= r.XMLResponseWriter [junit4:junit4] 2> 10078 T1446 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= dedupe" [junit4:junit4] 2> 10079 T1446 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= dedupe-allfields" [junit4:junit4] 2> 10079 T1446 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= stored_sig" [junit4:junit4] 2> 10080 T1446 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= uniq-fields" [junit4:junit4] 2> 10081 T1446 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= distrib-dup-test-chain-implicit" [junit4:junit4] 2> 10081 T1446 oasc.RequestHandlers.initHandlersFromConfi= g adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 10082 T1446 oasc.RequestHandlers.initHandlersFromConfi= g created /replication: solr.ReplicationHandler [junit4:junit4] 2> 10082 T1446 oasc.RequestHandlers.initHandlersFromConfi= g created standard: solr.StandardRequestHandler [junit4:junit4] 2> 10083 T1446 oasc.RequestHandlers.initHandlersFromConfi= g created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 10084 T1446 oasc.RequestHandlers.initHandlersFromConfi= g created dismax: solr.SearchHandler [junit4:junit4] 2> 10085 T1446 oasc.RequestHandlers.initHandlersFromConfi= g created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler [junit4:junit4] 2> 10085 T1446 oasc.RequestHandlers.initHandlersFromConfi= g created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 10086 T1446 oasc.RequestHandlers.initHandlersFromConfi= g created defaults: solr.StandardRequestHandler [junit4:junit4] 2> 10086 T1446 oasc.RequestHandlers.initHandlersFromConfi= g adding lazy requestHandler: solr.StandardRequestHandler [junit4:junit4] 2> 10087 T1446 oasc.RequestHandlers.initHandlersFromConfi= g created lazy: solr.StandardRequestHandler [junit4:junit4] 2> 10088 T1446 oasc.RequestHandlers.initHandlersFromConfi= g created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 10088 T1446 oasc.RequestHandlers.initHandlersFromConfi= g created /terms: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 10089 T1446 oasc.RequestHandlers.initHandlersFromConfi= g created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 10090 T1446 oasc.RequestHandlers.initHandlersFromConfi= g created spellCheckCompRH_Direct: org.apache.solr.handler.component.Search= Handler [junit4:junit4] 2> 10090 T1446 oasc.RequestHandlers.initHandlersFromConfi= g created spellCheckWithWordbreak: org.apache.solr.handler.component.Search= Handler [junit4:junit4] 2> 10091 T1446 oasc.RequestHandlers.initHandlersFromConfi= g created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component= .SearchHandler [junit4:junit4] 2> 10092 T1446 oasc.RequestHandlers.initHandlersFromConfi= g created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandle= r [junit4:junit4] 2> 10092 T1446 oasc.RequestHandlers.initHandlersFromConfi= g created tvrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 10093 T1446 oasc.RequestHandlers.initHandlersFromConfi= g created /mlt: solr.MoreLikeThisHandler [junit4:junit4] 2> 10094 T1446 oasc.RequestHandlers.initHandlersFromConfi= g created /debug/dump: solr.DumpRequestHandler [junit4:junit4] 2> 10097 T1446 oashl.XMLLoader.init xsltCacheLifetimeSeco= nds=3D60 [junit4:junit4] 2> 10102 T1446 oasc.SolrCore.initDeprecatedSupport WARNIN= G solrconfig.xml uses deprecated , Please update your = config to use the ShowFileRequestHandler. [junit4:junit4] 2> 10103 T1446 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> 10107 T1446 oass.SolrIndexSearcher. Opening Sear= cher@63ed4b47 main [junit4:junit4] 2> 10108 T1446 oasu.CommitTracker. Hard AutoCommit:= disabled [junit4:junit4] 2> 10109 T1446 oasu.CommitTracker. Soft AutoCommit:= disabled [junit4:junit4] 2> 10110 T1446 oashc.SpellCheckComponent.inform Initializ= ing spell checkers [junit4:junit4] 2> 10117 T1446 oass.DirectSolrSpellChecker.init init: {na= me=3Ddirect,classname=3DDirectSolrSpellChecker,field=3Dlowerfilt,minQueryLe= ngth=3D3} [junit4:junit4] 2> 10181 T1521 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@63ed4b47 main{StandardDirectoryReader(s= egments_1:1)} [junit4:junit4] 2> 10217 T1467 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 10232 T1506 oascc.ZkStateReader$2.process A cluster st= ate change has occurred - updating... [junit4:junit4] 2> 10232 T1480 oascc.ZkStateReader$2.process A cluster st= ate change has occurred - updating... [junit4:junit4] 2> 10232 T1492 oascc.ZkStateReader$2.process A cluster st= ate change has occurred - updating... [junit4:junit4] 2> 10232 T1466 oascc.ZkStateReader$2.process A cluster st= ate change has occurred - updating... [junit4:junit4] 2> 10232 T1520 oascc.ZkStateReader$2.process A cluster st= ate change has occurred - updating... [junit4:junit4] 2> 10688 T1446 oasc.CoreContainer.register registering co= re: collection1 [junit4:junit4] 2> 10688 T1446 oasc.ZkController.register Register shard = - core:collection1 address:http://127.0.0.1:41421/solr shardId:shard1 [junit4:junit4] 2> 10693 T1446 oasc.ZkController.register We are http://1= 27.0.0.1:41421/solr/collection1/ and leader is http://127.0.0.1:57977/solr/= collection1/ [junit4:junit4] 2> 10694 T1446 oasc.ZkController.register No LogReplay ne= eded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:41421/solr [junit4:junit4] 2> 10694 T1446 oasc.ZkController.checkRecovery Core needs= to recover:collection1 [junit4:junit4] 2> 10694 T1446 oasu.DefaultSolrCoreState.doRecovery Runni= ng recovery - first canceling any ongoing recovery [junit4:junit4] 2> ASYNC NEW_CORE C103 name=3Dcollection1 org.apache.sol= r.core.SolrCore@3cced2a6 url=3Dhttp://127.0.0.1:41421/solr/collection1 node= =3D127.0.0.1:41421_solr [junit4:junit4] 2> 10696 T1522 C103 P41421 oasc.RecoveryStrategy.run Star= ting recovery process. core=3Dcollection1 recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 10696 T1522 C103 P41421 oasc.RecoveryStrategy.doRecove= ry ###### startupVersions=3D[] [junit4:junit4] 2> 10696 T1446 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 10697 T1522 C103 P41421 oasc.RecoveryStrategy.doRecove= ry Attempting to PeerSync from http://127.0.0.1:57977/solr/collection1/ cor= e=3Dcollection1 - recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 10697 T1522 C103 P41421 oasu.PeerSync.sync PeerSync: c= ore=3Dcollection1 url=3Dhttp://127.0.0.1:41421/solr START replicas=3D[http:= //127.0.0.1:57977/solr/collection1/] nUpdates=3D100 [junit4:junit4] 2> 10697 T1446 oass.SolrDispatchFilter.init user.dir=3D/u= sr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/buil= d/solr-core/test/J1 [junit4:junit4] 2> 10698 T1522 C103 P41421 oasu.PeerSync.sync WARNING no = frame of reference to tell of we've missed updates [junit4:junit4] 2> 10698 T1446 oass.SolrDispatchFilter.init SolrDispatchF= ilter.init() done [junit4:junit4] 2> 10698 T1522 C103 P41421 oasc.RecoveryStrategy.doRecove= ry PeerSync Recovery was not successful - trying replication. core=3Dcollec= tion1 [junit4:junit4] 2> 10699 T1522 C103 P41421 oasc.RecoveryStrategy.doRecove= ry Starting Replication Recovery. core=3Dcollection1 [junit4:junit4] 2> 10699 T1446 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&f= ollowRedirects=3Dfalse [junit4:junit4] 2> 10699 T1522 C103 P41421 oascsi.HttpClientUtil.createCl= ient Creating new http client, config:maxConnections=3D128&maxConnectionsPe= rHost=3D32&followRedirects=3Dfalse [junit4:junit4] 2> 10700 T1472 C101 P57977 REQ /get {distrib=3Dfalse&qt= =3D/get&wt=3Djavabin&version=3D2&getVersions=3D100} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 10714 T1446 oaz.ZooKeeper. Initiating client con= nection, connectString=3D127.0.0.1:26491/solr sessionTimeout=3D10000 watche= r=3Dorg.apache.solr.common.cloud.ConnectionManager@78849039 [junit4:junit4] 2> 10715 T1524 oaz.ClientCnxn$SendThread.startConnect Ope= ning socket connection to server /127.0.0.1:26491 [junit4:junit4] 2> 10715 T1446 oascc.ConnectionManager.waitForConnected W= aiting for client to connect to ZooKeeper [junit4:junit4] 2> 10716 T1524 oaz.ClientCnxn$SendThread.primeConnection = Socket connection established to localhost/127.0.0.1:26491, initiating sess= ion [junit4:junit4] 2> 10716 T1448 oazs.NIOServerCnxn$Factory.run Accepted so= cket connection from /140.211.11.196:38023 [junit4:junit4] 2> 10716 T1448 oazs.NIOServerCnxn.readConnectRequest Clie= nt attempting to establish new session at /140.211.11.196:38023 [junit4:junit4] 2> 10717 T1450 oazs.NIOServerCnxn.finishSessionInit Estab= lished session 0x139de920b480007 with negotiated timeout 10000 for client /= 140.211.11.196:38023 [junit4:junit4] 2> 10717 T1524 oaz.ClientCnxn$SendThread.readConnectResul= t Session establishment complete on server localhost/127.0.0.1:26491, sessi= onid =3D 0x139de920b480007, negotiated timeout =3D 10000 [junit4:junit4] 2> 10718 T1525 oascc.ConnectionManager.process Watcher or= g.apache.solr.common.cloud.ConnectionManager@78849039 name:ZooKeeperConnect= ion Watcher:127.0.0.1:26491/solr got event WatchedEvent state:SyncConnected= type:None path:null path:null type:None [junit4:junit4] 2> 10718 T1446 oascc.ConnectionManager.waitForConnected C= lient is connected to ZooKeeper [junit4:junit4] 2> 10719 T1446 oascc.ZkStateReader.createClusterStateWatc= hersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 10720 T1446 oasc.ChaosMonkey.monkeyLog monkey: init - = expire sessions:true cause connection loss:true [junit4:junit4] 2> 10720 T1446 oascsi.HttpClientUtil.createClient Creatin= g new http client, config: [junit4:junit4] 2> 10729 T1446 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 10730 T1446 oasc.AbstractFullDistribZkTestBase.waitFor= ThingsToLevelOut Wait for recoveries to finish - wait 15 for each attempt [junit4:junit4] 2> 10730 T1446 oasc.AbstractDistribZkTestBase.waitForReco= veriesToFinish Wait for recoveries to finish - collection: collection1 fail= OnTimeout:true timeout (sec):15 [junit4:junit4] 2> 10731 T1446 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 10747 T1467 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 10760 T1466 oascc.ZkStateReader$2.process A cluster st= ate change has occurred - updating... [junit4:junit4] 2> 10760 T1520 oascc.ZkStateReader$2.process A cluster st= ate change has occurred - updating... [junit4:junit4] 2> 10760 T1492 oascc.ZkStateReader$2.process A cluster st= ate change has occurred - updating... [junit4:junit4] 2> 10760 T1506 oascc.ZkStateReader$2.process A cluster st= ate change has occurred - updating... [junit4:junit4] 2> 10760 T1525 oascc.ZkStateReader$2.process A cluster st= ate change has occurred - updating... [junit4:junit4] 2> 10760 T1480 oascc.ZkStateReader$2.process A cluster st= ate change has occurred - updating... [junit4:junit4] 2> C102_STATE=3Dcoll:collection1 core:collection1 props:= {shard=3Dshard1, roles=3Dnull, state=3Drecovering, core=3Dcollection1, coll= ection=3Dcollection1, node_name=3D127.0.0.1:19335_solr, base_url=3Dhttp://1= 27.0.0.1:19335/solr} [junit4:junit4] 2> 11609 T1508 C102 P19335 oasc.RecoveryStrategy.doRecove= ry Begin buffering updates. core=3Dcollection1 [junit4:junit4] 2> 11609 T1508 C102 P19335 oasu.UpdateLog.bufferUpdates S= tarting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog=3Dnull} [junit4:junit4] 2> 11609 T1508 C102 P19335 oasc.RecoveryStrategy.replicat= e Attempting to replicate from http://127.0.0.1:57977/solr/collection1/. co= re=3Dcollection1 [junit4:junit4] 2> 11609 T1508 C102 P19335 oascsi.HttpClientUtil.createCl= ient Creating new http client, config:maxConnections=3D128&maxConnectionsPe= rHost=3D32&followRedirects=3Dfalse [junit4:junit4] 2> 11619 T1478 C101 P57977 oasu.DirectUpdateHandler2.comm= it start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dtru= e,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 11623 T1478 C101 P57977 oass.SolrIndexSearcher. = Opening Searcher@49601df2 main [junit4:junit4] 2> 11624 T1478 C101 P57977 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 11625 T1481 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@49601df2 main{StandardDirectoryReader(s= egments_1:1)} [junit4:junit4] 2> 11625 T1478 C101 P57977 /update {waitSearcher=3Dtrue&c= ommit=3Dtrue&commit_end_point=3Dtrue&wt=3Djavabin&softCommit=3Dfalse&versio= n=3D2} {commit=3D} 0 6 [junit4:junit4] 2> 11626 T1508 C102 P19335 oash.ReplicationHandler.inform= Commits will be reserved for 10000 [junit4:junit4] 2> 11626 T1508 C102 P19335 oash.SnapPuller. No val= ue set for 'pollInterval'. Timer Task not started. [junit4:junit4] 2> 11629 T1476 C101 P57977 REQ /replication {command=3Din= dexversion&wt=3Djavabin&qt=3D/replication&version=3D2} status=3D0 QTime=3D0= =20 [junit4:junit4] 2> 11633 T1508 C102 P19335 oasc.SolrDeletionPolicy.onInit= SolrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/jetty3/index,segFN=3Dsegments_1,genera= tion=3D1,filenames=3D[segments_1] [junit4:junit4] 2> 11634 T1508 C102 P19335 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 1 [junit4:junit4] 2> 11634 T1508 C102 P19335 oasu.DirectUpdateHandler2.comm= it start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dtru= e,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 11662 T1508 C102 P19335 oasc.SolrDeletionPolicy.onComm= it SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/jetty3/index,segFN=3Dsegments_1,genera= tion=3D1,filenames=3D[segments_1] [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/jetty3/index,segFN=3Dsegments_2,genera= tion=3D2,filenames=3D[segments_2] [junit4:junit4] 2> 11662 T1508 C102 P19335 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 2 [junit4:junit4] 2> 11665 T1508 C102 P19335 oass.SolrIndexSearcher. = Opening Searcher@2ced9829 main [junit4:junit4] 2> 11665 T1508 C102 P19335 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 11667 T1507 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@2ced9829 main{StandardDirectoryReader(s= egments_2:2)} [junit4:junit4] 2> 11667 T1508 C102 P19335 oasc.RecoveryStrategy.replay N= o replay needed. core=3Dcollection1 [junit4:junit4] 2> 11667 T1508 C102 P19335 oasc.RecoveryStrategy.doRecove= ry Replication Recovery was successful - registering as Active. core=3Dcoll= ection1 [junit4:junit4] 2> 11669 T1508 C102 P19335 oasc.RecoveryStrategy.doRecove= ry Finished recovery process. core=3Dcollection1 [junit4:junit4] 2> 11733 T1446 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 11764 T1467 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 11777 T1480 oascc.ZkStateReader$2.process A cluster st= ate change has occurred - updating... [junit4:junit4] 2> 11777 T1466 oascc.ZkStateReader$2.process A cluster st= ate change has occurred - updating... [junit4:junit4] 2> 11777 T1525 oascc.ZkStateReader$2.process A cluster st= ate change has occurred - updating... [junit4:junit4] 2> 11777 T1492 oascc.ZkStateReader$2.process A cluster st= ate change has occurred - updating... [junit4:junit4] 2> 11777 T1520 oascc.ZkStateReader$2.process A cluster st= ate change has occurred - updating... [junit4:junit4] 2> 11777 T1506 oascc.ZkStateReader$2.process A cluster st= ate change has occurred - updating... [junit4:junit4] 2> 12735 T1446 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> C103_STATE=3Dcoll:collection1 core:collection1 props:= {shard=3Dshard1, roles=3Dnull, state=3Drecovering, core=3Dcollection1, coll= ection=3Dcollection1, node_name=3D127.0.0.1:41421_solr, base_url=3Dhttp://1= 27.0.0.1:41421/solr} [junit4:junit4] 2> 13717 T1522 C103 P41421 oasc.RecoveryStrategy.doRecove= ry Begin buffering updates. core=3Dcollection1 [junit4:junit4] 2> 13717 T1522 C103 P41421 oasu.UpdateLog.bufferUpdates S= tarting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog=3Dnull} [junit4:junit4] 2> 13717 T1522 C103 P41421 oasc.RecoveryStrategy.replicat= e Attempting to replicate from http://127.0.0.1:57977/solr/collection1/. co= re=3Dcollection1 [junit4:junit4] 2> 13717 T1522 C103 P41421 oascsi.HttpClientUtil.createCl= ient Creating new http client, config:maxConnections=3D128&maxConnectionsPe= rHost=3D32&followRedirects=3Dfalse [junit4:junit4] 2> 13732 T1473 C101 P57977 oasu.DirectUpdateHandler2.comm= it start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dtru= e,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 13735 T1473 C101 P57977 oass.SolrIndexSearcher. = Opening Searcher@44354005 main [junit4:junit4] 2> 13735 T1473 C101 P57977 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 13737 T1481 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@44354005 main{StandardDirectoryReader(s= egments_1:1)} [junit4:junit4] 2> 13742 T1446 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 13742 T1473 C101 P57977 /update {waitSearcher=3Dtrue&c= ommit=3Dtrue&commit_end_point=3Dtrue&wt=3Djavabin&softCommit=3Dfalse&versio= n=3D2} {commit=3D} 0 10 [junit4:junit4] 2> 13743 T1522 C103 P41421 oash.ReplicationHandler.inform= Commits will be reserved for 10000 [junit4:junit4] 2> 13743 T1522 C103 P41421 oash.SnapPuller. No val= ue set for 'pollInterval'. Timer Task not started. [junit4:junit4] 2> 13745 T1476 C101 P57977 REQ /replication {command=3Din= dexversion&wt=3Djavabin&qt=3D/replication&version=3D2} status=3D0 QTime=3D0= =20 [junit4:junit4] 2> 13750 T1522 C103 P41421 oasc.SolrDeletionPolicy.onInit= SolrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/jetty4/index,segFN=3Dsegments_1,genera= tion=3D1,filenames=3D[segments_1] [junit4:junit4] 2> 13750 T1522 C103 P41421 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 1 [junit4:junit4] 2> 13751 T1522 C103 P41421 oasu.DirectUpdateHandler2.comm= it start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dtru= e,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 13753 T1522 C103 P41421 oasc.SolrDeletionPolicy.onComm= it SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/jetty4/index,segFN=3Dsegments_1,genera= tion=3D1,filenames=3D[segments_1] [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/jetty4/index,segFN=3Dsegments_2,genera= tion=3D2,filenames=3D[segments_2] [junit4:junit4] 2> 13754 T1522 C103 P41421 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 2 [junit4:junit4] 2> 13757 T1522 C103 P41421 oass.SolrIndexSearcher. = Opening Searcher@400f94ca main [junit4:junit4] 2> 13757 T1522 C103 P41421 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 13758 T1521 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@400f94ca main{StandardDirectoryReader(s= egments_2:2)} [junit4:junit4] 2> 13759 T1522 C103 P41421 oasc.RecoveryStrategy.replay N= o replay needed. core=3Dcollection1 [junit4:junit4] 2> 13759 T1522 C103 P41421 oasc.RecoveryStrategy.doRecove= ry Replication Recovery was successful - registering as Active. core=3Dcoll= ection1 [junit4:junit4] 2> 13766 T1522 C103 P41421 oasc.RecoveryStrategy.doRecove= ry Finished recovery process. core=3Dcollection1 [junit4:junit4] 2> 13783 T1467 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 13795 T1480 oascc.ZkStateReader$2.process A cluster st= ate change has occurred - updating... [junit4:junit4] 2> 13795 T1492 oascc.ZkStateReader$2.process A cluster st= ate change has occurred - updating... [junit4:junit4] 2> 13795 T1525 oascc.ZkStateReader$2.process A cluster st= ate change has occurred - updating... [junit4:junit4] 2> 13795 T1506 oascc.ZkStateReader$2.process A cluster st= ate change has occurred - updating... [junit4:junit4] 2> 13795 T1466 oascc.ZkStateReader$2.process A cluster st= ate change has occurred - updating... [junit4:junit4] 2> 13795 T1520 oascc.ZkStateReader$2.process A cluster st= ate change has occurred - updating... [junit4:junit4] 2> 14744 T1446 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> ASYNC NEW_CORE C104 name=3Dcollection1 org.apache.sol= r.core.SolrCore@2d581156 url=3Dhttp://127.0.0.1:26494/solr/collection1 node= =3D127.0.0.1:26494_solr [junit4:junit4] 2> 14755 T1458 C104 P26494 oasu.DirectUpdateHandler2.comm= it start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dtru= e,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 14759 T1458 C104 P26494 oasc.SolrDeletionPolicy.onInit= SolrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/control/data/index,segFN=3Dsegments_1,= generation=3D1,filenames=3D[segments_1] [junit4:junit4] 2> 14760 T1458 C104 P26494 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 1 [junit4:junit4] 2> 14761 T1458 C104 P26494 oass.SolrIndexSearcher. = Opening Searcher@63a73411 main [junit4:junit4] 2> 14761 T1458 C104 P26494 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 14763 T1469 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@63a73411 main{StandardDirectoryReader(s= egments_1:1)} [junit4:junit4] 2> 14763 T1458 C104 P26494 /update {waitSearcher=3Dtrue&w= t=3Djavabin&commit=3Dtrue&softCommit=3Dfalse&version=3D2} {commit=3D} 0 8 [junit4:junit4] 2> 14764 T1446 oaz.ZooKeeper. Initiating client con= nection, connectString=3D127.0.0.1:26491/solr sessionTimeout=3D10000 watche= r=3Dorg.apache.solr.common.cloud.ConnectionManager@764b7b33 [junit4:junit4] 2> 14765 T1526 oaz.ClientCnxn$SendThread.startConnect Ope= ning socket connection to server /127.0.0.1:26491 [junit4:junit4] 2> 14765 T1446 oascc.ConnectionManager.waitForConnected W= aiting for client to connect to ZooKeeper [junit4:junit4] 2> 14766 T1526 oaz.ClientCnxn$SendThread.primeConnection = Socket connection established to localhost/127.0.0.1:26491, initiating sess= ion [junit4:junit4] 2> 14766 T1448 oazs.NIOServerCnxn$Factory.run Accepted so= cket connection from /140.211.11.196:63512 [junit4:junit4] 2> 14766 T1448 oazs.NIOServerCnxn.readConnectRequest Clie= nt attempting to establish new session at /140.211.11.196:63512 [junit4:junit4] 2> 14795 T1450 oazs.NIOServerCnxn.finishSessionInit Estab= lished session 0x139de920b480008 with negotiated timeout 10000 for client /= 140.211.11.196:63512 [junit4:junit4] 2> 14795 T1526 oaz.ClientCnxn$SendThread.readConnectResul= t Session establishment complete on server localhost/127.0.0.1:26491, sessi= onid =3D 0x139de920b480008, negotiated timeout =3D 10000 [junit4:junit4] 2> 14795 T1527 oascc.ConnectionManager.process Watcher or= g.apache.solr.common.cloud.ConnectionManager@764b7b33 name:ZooKeeperConnect= ion Watcher:127.0.0.1:26491/solr got event WatchedEvent state:SyncConnected= type:None path:null path:null type:None [junit4:junit4] 2> 14796 T1446 oascc.ConnectionManager.waitForConnected C= lient is connected to ZooKeeper [junit4:junit4] 2> 14796 T1446 oascc.ZkStateReader.createClusterStateWatc= hersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 14798 T1474 C101 P57977 oasu.DirectUpdateHandler2.comm= it start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dtru= e,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 14801 T1474 C101 P57977 oass.SolrIndexSearcher. = Opening Searcher@41c47be6 main [junit4:junit4] 2> 14802 T1474 C101 P57977 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 14803 T1481 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@41c47be6 main{StandardDirectoryReader(s= egments_1:1)} [junit4:junit4] 2> 14803 T1474 C101 P57977 oasu.SolrCmdDistributor.distri= bCommit Distrib commit to:[StdNode: http://127.0.0.1:60077/solr/collection1= /, StdNode: http://127.0.0.1:19335/solr/collection1/, StdNode: http://127.0= .0.1:41421/solr/collection1/] [junit4:junit4] 2> C100_STATE=3Dcoll:collection1 core:collection1 props:= {shard=3Dshard1, roles=3Dnull, state=3Dactive, core=3Dcollection1, collecti= on=3Dcollection1, node_name=3D127.0.0.1:60077_solr, base_url=3Dhttp://127.0= .0.1:60077/solr} [junit4:junit4] 2> 14810 T1484 C100 P60077 oasu.DirectUpdateHandler2.comm= it start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dtru= e,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> C102_STATE=3Dcoll:collection1 core:collection1 props:= {shard=3Dshard1, roles=3Dnull, state=3Dactive, core=3Dcollection1, collecti= on=3Dcollection1, node_name=3D127.0.0.1:19335_solr, base_url=3Dhttp://127.0= .0.1:19335/solr} [junit4:junit4] 2> 14811 T1498 C102 P19335 oasu.DirectUpdateHandler2.comm= it start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dtru= e,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> C103_STATE=3Dcoll:collection1 core:collection1 props:= {shard=3Dshard1, roles=3Dnull, state=3Dactive, core=3Dcollection1, collecti= on=3Dcollection1, node_name=3D127.0.0.1:41421_solr, base_url=3Dhttp://127.0= .0.1:41421/solr} [junit4:junit4] 2> 14811 T1512 C103 P41421 oasu.DirectUpdateHandler2.comm= it start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dtru= e,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 14814 T1512 C103 P41421 oass.SolrIndexSearcher. = Opening Searcher@3e173b55 main [junit4:junit4] 2> 14815 T1512 C103 P41421 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 14815 T1484 C100 P60077 oass.SolrIndexSearcher. = Opening Searcher@2888efde main [junit4:junit4] 2> 14816 T1498 C102 P19335 oass.SolrIndexSearcher. = Opening Searcher@182b1195 main [junit4:junit4] 2> 14816 T1484 C100 P60077 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 14816 T1498 C102 P19335 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 14817 T1521 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@3e173b55 main{StandardDirectoryReader(s= egments_2:2)} [junit4:junit4] 2> 14817 T1512 C103 P41421 /update {waitSearcher=3Dtrue&c= ommit=3Dtrue&wt=3Djavabin&commit_end_point=3Dtrue&expungeDeletes=3Dfalse&so= ftCommit=3Dfalse&version=3D2} {commit=3D} 0 7 [junit4:junit4] 2> 14818 T1493 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@2888efde main{StandardDirectoryReader(s= egments_2:2)} [junit4:junit4] 2> 14818 T1507 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@182b1195 main{StandardDirectoryReader(s= egments_2:2)} [junit4:junit4] 2> 14818 T1484 C100 P60077 /update {waitSearcher=3Dtrue&c= ommit=3Dtrue&wt=3Djavabin&commit_end_point=3Dtrue&expungeDeletes=3Dfalse&so= ftCommit=3Dfalse&version=3D2} {commit=3D} 0 8 [junit4:junit4] 2> 14818 T1498 C102 P19335 /update {waitSearcher=3Dtrue&c= ommit=3Dtrue&wt=3Djavabin&commit_end_point=3Dtrue&expungeDeletes=3Dfalse&so= ftCommit=3Dfalse&version=3D2} {commit=3D} 0 8 [junit4:junit4] 2> 14819 T1474 C101 P57977 /update {waitSearcher=3Dtrue&w= t=3Djavabin&commit=3Dtrue&softCommit=3Dfalse&version=3D2} {commit=3D} 0 21 [junit4:junit4] 2> 14820 T1446 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 14822 T1475 C101 P57977 REQ /select {distrib=3Dfalse&w= t=3Djavabin&q=3D*:*&version=3D2} hits=3D0 status=3D0 QTime=3D0=20 [junit4:junit4] 2> 14824 T1485 C100 P60077 REQ /select {distrib=3Dfalse&w= t=3Djavabin&q=3D*:*&version=3D2} hits=3D0 status=3D0 QTime=3D1=20 [junit4:junit4] 2> 14825 T1499 C102 P19335 REQ /select {distrib=3Dfalse&w= t=3Djavabin&q=3D*:*&version=3D2} hits=3D0 status=3D0 QTime=3D0=20 [junit4:junit4] 2> 14827 T1513 C103 P41421 REQ /select {distrib=3Dfalse&w= t=3Djavabin&q=3D*:*&version=3D2} hits=3D0 status=3D0 QTime=3D0=20 [junit4:junit4] 2> 16833 T1458 C104 P26494 oass.SolrIndexSearcher. = Opening Searcher@e45a028 realtime [junit4:junit4] 2> 16833 T1458 C104 P26494 /update {wt=3Djavabin&version= =3D2} {deleteByQuery=3D*:* (-1413542202381959168)} 0 2 [junit4:junit4] 2> 16837 T1474 C101 P57977 oass.SolrIndexSearcher. = Opening Searcher@19256ca7 realtime [junit4:junit4] 2> 16841 T1498 C102 P19335 oass.SolrIndexSearcher. = Opening Searcher@3b0933e7 realtime [junit4:junit4] 2> 16841 T1498 C102 P19335 REQ /update {update.distrib=3D= FROMLEADER&_version_=3D-1413542202387202048&update.from=3Dhttp://127.0.0.1:= 57977/solr/collection1/&wt=3Djavabin&version=3D2} status=3D0 QTime=3D1=20 [junit4:junit4] 2> 16842 T1512 C103 P41421 oass.SolrIndexSearcher. = Opening Searcher@44a2786 realtime [junit4:junit4] 2> 16842 T1484 C100 P60077 oass.SolrIndexSearcher. = Opening Searcher@44a2786 realtime [junit4:junit4] 2> 16842 T1512 C103 P41421 REQ /update {update.distrib=3D= FROMLEADER&_version_=3D-1413542202387202048&update.from=3Dhttp://127.0.0.1:= 57977/solr/collection1/&wt=3Djavabin&version=3D2} status=3D0 QTime=3D2=20 [junit4:junit4] 2> 16842 T1484 C100 P60077 REQ /update {update.distrib=3D= FROMLEADER&_version_=3D-1413542202387202048&update.from=3Dhttp://127.0.0.1:= 57977/solr/collection1/&wt=3Djavabin&version=3D2} status=3D0 QTime=3D2=20 [junit4:junit4] 2> 16843 T1474 C101 P57977 /update {wt=3Djavabin&version= =3D2} {deleteByQuery=3D*:* (-1413542202387202048)} 0 7 [junit4:junit4] 2> 16848 T1458 C104 P26494 /update {wt=3Djavabin&version= =3D2} {add=3D[0 (1413542202397687808)]} 0 2 [junit4:junit4] 2> 16857 T1498 C102 P19335 REQ /update {distrib.from=3Dht= tp://127.0.0.1:57977/solr/collection1/&update.distrib=3DFROMLEADER&wt=3Djav= abin&version=3D2} status=3D0 QTime=3D2=20 [junit4:junit4] 2> 16858 T1512 C103 P41421 REQ /update {distrib.from=3Dht= tp://127.0.0.1:57977/solr/collection1/&update.distrib=3DFROMLEADER&wt=3Djav= abin&version=3D2} status=3D0 QTime=3D3=20 [junit4:junit4] 2> 16858 T1484 C100 P60077 REQ /update {distrib.from=3Dht= tp://127.0.0.1:57977/solr/collection1/&update.distrib=3DFROMLEADER&wt=3Djav= abin&version=3D2} status=3D0 QTime=3D3=20 [junit4:junit4] 2> 16858 T1474 C101 P57977 /update {wt=3Djavabin&version= =3D2} {add=3D[0 (1413542202402930688)]} 0 7 [junit4:junit4] 2> 16861 T1458 C104 P26494 /update {wt=3Djavabin&version= =3D2} {add=3D[1 (1413542202413416448)]} 0 0 [junit4:junit4] 2> 16868 T1498 C102 P19335 REQ /update {distrib.from=3Dht= tp://127.0.0.1:57977/solr/collection1/&update.distrib=3DFROMLEADER&wt=3Djav= abin&version=3D2} status=3D0 QTime=3D1=20 [junit4:junit4] 2> 16868 T1512 C103 P41421 REQ /update {distrib.from=3Dht= tp://127.0.0.1:57977/solr/collection1/&update.distrib=3DFROMLEADER&wt=3Djav= abin&version=3D2} status=3D0 QTime=3D1=20 [junit4:junit4] 2> 16868 T1484 C100 P60077 REQ /update {distrib.from=3Dht= tp://127.0.0.1:57977/solr/collection1/&update.distrib=3DFROMLEADER&wt=3Djav= abin&version=3D2} status=3D0 QTime=3D1=20 [junit4:junit4] 2> 16868 T1474 C101 P57977 /update {wt=3Djavabin&version= =3D2} {add=3D[1 (1413542202416562176)]} 0 4 [junit4:junit4] 2> 16871 T1458 C104 P26494 /update {wt=3Djavabin&version= =3D2} {add=3D[2 (1413542202423902208)]} 0 0 [junit4:junit4] 2> 16877 T1498 C102 P19335 REQ /update {distrib.from=3Dht= tp://127.0.0.1:57977/solr/collection1/&update.distrib=3DFROMLEADER&test.dis= trib.skip.servers=3Dhttp://127.0.0.1:60077/solr/collection1/&wt=3Djavabin&v= ersion=3D2} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 16878 T1512 C103 P41421 REQ /update {distrib.from=3Dht= tp://127.0.0.1:57977/solr/collection1/&update.distrib=3DFROMLEADER&test.dis= trib.skip.servers=3Dhttp://127.0.0.1:60077/solr/collection1/&wt=3Djavabin&v= ersion=3D2} status=3D0 QTime=3D1=20 [junit4:junit4] 2> 16878 T1474 C101 P57977 /update {test.distrib.skip.ser= vers=3Dhttp://127.0.0.1:60077/solr/collection1/&wt=3Djavabin&version=3D2} {= add=3D[2 (1413542202427047936)]} 0 4 [junit4:junit4] 2> 16881 T1458 C104 P26494 /update {wt=3Djavabin&version= =3D2} {add=3D[3 (1413542202434387968)]} 0 0 [junit4:junit4] 2> 16888 T1512 C103 P41421 REQ /update {distrib.from=3Dht= tp://127.0.0.1:57977/solr/collection1/&update.distrib=3DFROMLEADER&test.dis= trib.skip.servers=3Dhttp://127.0.0.1:60077/solr/collection1/&test.distrib.s= kip.servers=3Dhttp://127.0.0.1:19335/solr/collection1/&wt=3Djavabin&version= =3D2} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 16888 T1474 C101 P57977 /update {test.distrib.skip.ser= vers=3Dhttp://127.0.0.1:60077/solr/collection1/&test.distrib.skip.servers= =3Dhttp://127.0.0.1:19335/solr/collection1/&wt=3Djavabin&version=3D2} {add= =3D[3 (1413542202437533696)]} 0 4 [junit4:junit4] 2> 16890 T1458 C104 P26494 oasu.DirectUpdateHandler2.comm= it start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dtru= e,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 16936 T1458 C104 P26494 oasc.SolrDeletionPolicy.onComm= it SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/control/data/index,segFN=3Dsegments_1,= generation=3D1,filenames=3D[segments_1] [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/control/data/index,segFN=3Dsegments_2,= generation=3D2,filenames=3D[_0.tis, _0.nrm, _0.fnm, _0.tii, _0.frq, segment= s_2, _0.fdx, _0.si, _0.prx, _0.fdt] [junit4:junit4] 2> 16937 T1458 C104 P26494 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 2 [junit4:junit4] 2> 16941 T1458 C104 P26494 oass.SolrIndexSearcher. = Opening Searcher@4bdc2e72 main [junit4:junit4] 2> 16942 T1458 C104 P26494 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 16943 T1469 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@4bdc2e72 main{StandardDirectoryReader(s= egments_2:3:nrt _0(4.0.0.2):C4)} [junit4:junit4] 2> 16944 T1458 C104 P26494 /update {waitSearcher=3Dtrue&w= t=3Djavabin&commit=3Dtrue&softCommit=3Dfalse&version=3D2} {commit=3D} 0 54 [junit4:junit4] 2> 16946 T1474 C101 P57977 oasu.DirectUpdateHandler2.comm= it start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dtru= e,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 16958 T1474 C101 P57977 oasc.SolrDeletionPolicy.onComm= it SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/jetty1/index,segFN=3Dsegments_1,genera= tion=3D1,filenames=3D[segments_1] [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/jetty1/index,segFN=3Dsegments_2,genera= tion=3D2,filenames=3D[_0.tis, _0.nrm, _0.fnm, _0.tii, _0.frq, segments_2, _= 0.fdx, _0.si, _0.prx, _0.fdt] [junit4:junit4] 2> 16959 T1474 C101 P57977 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 2 [junit4:junit4] 2> 16963 T1474 C101 P57977 oass.SolrIndexSearcher. = Opening Searcher@23a86a12 main [junit4:junit4] 2> 16963 T1474 C101 P57977 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 16964 T1481 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@23a86a12 main{StandardDirectoryReader(s= egments_2:3:nrt _0(4.0.0.2):C4)} [junit4:junit4] 2> 16965 T1474 C101 P57977 oasu.SolrCmdDistributor.distri= bCommit Distrib commit to:[StdNode: http://127.0.0.1:60077/solr/collection1= /, StdNode: http://127.0.0.1:19335/solr/collection1/, StdNode: http://127.0= .0.1:41421/solr/collection1/] [junit4:junit4] 2> 16967 T1484 C100 P60077 oasu.DirectUpdateHandler2.comm= it start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dtru= e,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 16967 T1512 C103 P41421 oasu.DirectUpdateHandler2.comm= it start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dtru= e,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 16967 T1498 C102 P19335 oasu.DirectUpdateHandler2.comm= it start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dtru= e,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 17048 T1484 C100 P60077 oasc.SolrDeletionPolicy.onComm= it SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/jetty2/index,segFN=3Dsegments_2,genera= tion=3D2,filenames=3D[segments_2] [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/jetty2/index,segFN=3Dsegments_3,genera= tion=3D3,filenames=3D[_0.tis, _0.nrm, _0.fnm, _0.tii, _0.frq, _0.fdx, _0.si= , _0.prx, _0.fdt, segments_3] [junit4:junit4] 2> 17048 T1484 C100 P60077 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 3 [junit4:junit4] 2> 17051 T1498 C102 P19335 oasc.SolrDeletionPolicy.onComm= it SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/jetty3/index,segFN=3Dsegments_2,genera= tion=3D2,filenames=3D[segments_2] [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/jetty3/index,segFN=3Dsegments_3,genera= tion=3D3,filenames=3D[_0.tis, _0.nrm, _0.fnm, _0.tii, _0.frq, _0.fdx, _0.si= , _0.prx, _0.fdt, segments_3] [junit4:junit4] 2> 17051 T1512 C103 P41421 oasc.SolrDeletionPolicy.onComm= it SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/jetty4/index,segFN=3Dsegments_2,genera= tion=3D2,filenames=3D[segments_2] [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/jetty4/index,segFN=3Dsegments_3,genera= tion=3D3,filenames=3D[_0.tis, _0.nrm, _0.fnm, _0.tii, _0.frq, _0.fdx, _0.si= , _0.prx, _0.fdt, segments_3] [junit4:junit4] 2> 17051 T1498 C102 P19335 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 3 [junit4:junit4] 2> 17051 T1512 C103 P41421 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 3 [junit4:junit4] 2> 17053 T1484 C100 P60077 oass.SolrIndexSearcher. = Opening Searcher@32b8020b main [junit4:junit4] 2> 17054 T1484 C100 P60077 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 17056 T1493 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@32b8020b main{StandardDirectoryReader(s= egments_3:4:nrt _0(4.0.0.2):C2)} [junit4:junit4] 2> 17056 T1484 C100 P60077 /update {waitSearcher=3Dtrue&c= ommit=3Dtrue&wt=3Djavabin&commit_end_point=3Dtrue&expungeDeletes=3Dfalse&so= ftCommit=3Dfalse&version=3D2} {commit=3D} 0 89 [junit4:junit4] 2> 17057 T1498 C102 P19335 oass.SolrIndexSearcher. = Opening Searcher@36075ad3 main [junit4:junit4] 2> 17057 T1512 C103 P41421 oass.SolrIndexSearcher. = Opening Searcher@72e9cc72 main [junit4:junit4] 2> 17058 T1498 C102 P19335 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 17058 T1512 C103 P41421 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 17059 T1507 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@36075ad3 main{StandardDirectoryReader(s= egments_3:4:nrt _0(4.0.0.2):C3)} [junit4:junit4] 2> 17060 T1521 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@72e9cc72 main{StandardDirectoryReader(s= egments_3:4:nrt _0(4.0.0.2):C4)} [junit4:junit4] 2> 17060 T1498 C102 P19335 /update {waitSearcher=3Dtrue&c= ommit=3Dtrue&wt=3Djavabin&commit_end_point=3Dtrue&expungeDeletes=3Dfalse&so= ftCommit=3Dfalse&version=3D2} {commit=3D} 0 93 [junit4:junit4] 2> 17060 T1512 C103 P41421 /update {waitSearcher=3Dtrue&c= ommit=3Dtrue&wt=3Djavabin&commit_end_point=3Dtrue&expungeDeletes=3Dfalse&so= ftCommit=3Dfalse&version=3D2} {commit=3D} 0 93 [junit4:junit4] 2> 17061 T1474 C101 P57977 /update {waitSearcher=3Dtrue&w= t=3Djavabin&commit=3Dtrue&softCommit=3Dfalse&version=3D2} {commit=3D} 0 115 [junit4:junit4] 2> 17061 T1446 oasc.AbstractDistribZkTestBase.waitForReco= veriesToFinish Wait for recoveries to finish - collection: collection1 fail= OnTimeout:true timeout (sec):1800 [junit4:junit4] 2> 17062 T1446 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> check const of shard1 [junit4:junit4] 2> client0 [junit4:junit4] 2> PROPS:127.0.0.1:57977_solr_collection1:{"shard":"shard= 1","roles":null,"state":"active","core":"collection1","collection":"collect= ion1","node_name":"127.0.0.1:57977_solr","base_url":"http://127.0.0.1:57977= /solr","leader":"true"} [junit4:junit4] 2> 17065 T1475 C101 P57977 REQ /select {distrib=3Dfalse&w= t=3Djavabin&q=3D*:*&version=3D2} hits=3D4 status=3D0 QTime=3D0=20 [junit4:junit4] 2> live:true [junit4:junit4] 2> num:4 [junit4:junit4] 2>=20 [junit4:junit4] 2> client1 [junit4:junit4] 2> PROPS:127.0.0.1:60077_solr_collection1:{"shard":"shard= 1","roles":null,"state":"active","core":"collection1","collection":"collect= ion1","node_name":"127.0.0.1:60077_solr","base_url":"http://127.0.0.1:60077= /solr"} [junit4:junit4] 2> 17068 T1485 C100 P60077 REQ /select {distrib=3Dfalse&w= t=3Djavabin&q=3D*:*&version=3D2} hits=3D2 status=3D0 QTime=3D0=20 [junit4:junit4] 2> live:true [junit4:junit4] 2> num:2 [junit4:junit4] 2>=20 [junit4:junit4] 2> ######shard1 is not consistent. Got 4 from http://127= .0.0.1:57977/solr/collection1lastClient and got 2 from http://127.0.0.1:600= 77/solr/collection1 [junit4:junit4] 2> 17072 T1475 C101 P57977 REQ /select {fl=3Did,_version_= &sort=3Did+asc&q=3D*:*&distrib=3Dfalse&wt=3Djavabin&rows=3D1000&version=3D2= } hits=3D4 status=3D0 QTime=3D1=20 [junit4:junit4] 2> 17075 T1485 C100 P60077 REQ /select {fl=3Did,_version_= &sort=3Did+asc&q=3D*:*&distrib=3Dfalse&wt=3Djavabin&rows=3D1000&version=3D2= } hits=3D2 status=3D0 QTime=3D1=20 [junit4:junit4] 2> ######http://127.0.0.1:57977/solr/collection1: {numFou= nd=3D4,start=3D0,docs=3D[SolrDocument{id=3D0, _version_=3D14135422024029306= 88}, SolrDocument{id=3D1, _version_=3D1413542202416562176}, SolrDocument{id= =3D2, _version_=3D1413542202427047936}, SolrDocument{id=3D3, _version_=3D14= 13542202437533696}]} [junit4:junit4] 2> ######http://127.0.0.1:60077/solr/collection1: {numFou= nd=3D2,start=3D0,docs=3D[SolrDocument{id=3D0, _version_=3D14135422024029306= 88}, SolrDocument{id=3D1, _version_=3D1413542202416562176}]} [junit4:junit4] 2> ###### sizes=3D4,2 [junit4:junit4] 2> ###### Only in http://127.0.0.1:57977/solr/collection1= : [{id=3D2, _version_=3D1413542202427047936}, {id=3D3, _version_=3D14135422= 02437533696}] [junit4:junit4] 2> client2 [junit4:junit4] 2> PROPS:127.0.0.1:19335_solr_collection1:{"shard":"shard= 1","roles":null,"state":"active","core":"collection1","collection":"collect= ion1","node_name":"127.0.0.1:19335_solr","base_url":"http://127.0.0.1:19335= /solr"} [junit4:junit4] 2> 17078 T1499 C102 P19335 REQ /select {distrib=3Dfalse&w= t=3Djavabin&q=3D*:*&version=3D2} hits=3D3 status=3D0 QTime=3D0=20 [junit4:junit4] 2> live:true [junit4:junit4] 2> num:3 [junit4:junit4] 2>=20 [junit4:junit4] 2> client3 [junit4:junit4] 2> PROPS:127.0.0.1:41421_solr_collection1:{"shard":"shard= 1","roles":null,"state":"active","core":"collection1","collection":"collect= ion1","node_name":"127.0.0.1:41421_solr","base_url":"http://127.0.0.1:41421= /solr"} [junit4:junit4] 2> 17081 T1513 C103 P41421 REQ /select {distrib=3Dfalse&w= t=3Djavabin&q=3D*:*&version=3D2} hits=3D4 status=3D0 QTime=3D0=20 [junit4:junit4] 2> live:true [junit4:junit4] 2> num:4 [junit4:junit4] 2>=20 [junit4:junit4] 2> 17087 T1446 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&f= ollowRedirects=3Dfalse [junit4:junit4] 2> 17108 T1500 oasha.CollectionsHandler.handleSyncShardAc= tion Syncing shard : action=3DSYNCSHARD&collection=3Dcollection1&shard=3Dsh= ard1&wt=3Djavabin&version=3D2 [junit4:junit4] 2> 17109 T1500 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&f= ollowRedirects=3Dfalse [junit4:junit4] 2> 17121 T1478 oasha.CoreAdminHandler.handleRequestSyncAc= tion I have been requested to sync up my shard [junit4:junit4] 2> 17121 T1478 oasc.SyncStrategy.sync Sync replicas to ht= tp://127.0.0.1:57977/solr/collection1/ [junit4:junit4] 2> 17121 T1478 oasu.PeerSync.sync PeerSync: core=3Dcollec= tion1 url=3Dhttp://127.0.0.1:57977/solr START replicas=3D[http://127.0.0.1:= 60077/solr/collection1/, http://127.0.0.1:19335/solr/collection1/, http://1= 27.0.0.1:41421/solr/collection1/] nUpdates=3D100 [junit4:junit4] 2> 17123 T1486 C100 P60077 REQ /get {distrib=3Dfalse&qt= =3D/get&wt=3Djavabin&version=3D2&getVersions=3D100} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 17123 T1501 C102 P19335 REQ /get {distrib=3Dfalse&qt= =3D/get&wt=3Djavabin&version=3D2&getVersions=3D100} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 17124 T1514 C103 P41421 REQ /get {distrib=3Dfalse&qt= =3D/get&wt=3Djavabin&version=3D2&getVersions=3D100} status=3D0 QTime=3D1=20 [junit4:junit4] 2> 17124 T1478 oasu.PeerSync.handleVersions PeerSync: cor= e=3Dcollection1 url=3Dhttp://127.0.0.1:57977/solr Received 4 versions from= 127.0.0.1:19335/solr/collection1/ [junit4:junit4] 2> 17124 T1478 oasu.PeerSync.handleVersions PeerSync: cor= e=3Dcollection1 url=3Dhttp://127.0.0.1:57977/solr Our versions are newer. = ourLowThreshold=3D1413542202387202048 otherHigh=3D1413542202427047936 [junit4:junit4] 2> 17124 T1478 oasu.PeerSync.handleVersions PeerSync: cor= e=3Dcollection1 url=3Dhttp://127.0.0.1:57977/solr Received 3 versions from= 127.0.0.1:60077/solr/collection1/ [junit4:junit4] 2> 17125 T1478 oasu.PeerSync.handleVersions PeerSync: cor= e=3Dcollection1 url=3Dhttp://127.0.0.1:57977/solr Our versions are newer. = ourLowThreshold=3D1413542202387202048 otherHigh=3D1413542202416562176 [junit4:junit4] 2> 17125 T1478 oasu.PeerSync.handleVersions PeerSync: cor= e=3Dcollection1 url=3Dhttp://127.0.0.1:57977/solr Received 5 versions from= 127.0.0.1:41421/solr/collection1/ [junit4:junit4] 2> 17125 T1478 oasu.PeerSync.handleVersions PeerSync: cor= e=3Dcollection1 url=3Dhttp://127.0.0.1:57977/solr Our versions are newer. = ourLowThreshold=3D1413542202387202048 otherHigh=3D1413542202427047936 [junit4:junit4] 2> 17126 T1478 oasu.PeerSync.sync PeerSync: core=3Dcollec= tion1 url=3Dhttp://127.0.0.1:57977/solr DONE. sync succeeded [junit4:junit4] 2> 17126 T1478 oasc.SyncStrategy.syncReplicas Sync Succes= s - now sync replicas to me [junit4:junit4] 2> 17126 T1478 oasc.SyncStrategy.syncToMe http://127.0.0.= 1:57977/solr/collection1/: try and ask http://127.0.0.1:60077/solr/collecti= on1/ to sync [junit4:junit4] 2> 17127 T1478 oasc.SyncStrategy.syncToMe http://127.0.0.= 1:57977/solr/collection1/: try and ask http://127.0.0.1:19335/solr/collecti= on1/ to sync [junit4:junit4] 2> 17127 T1478 oasc.SyncStrategy.syncToMe http://127.0.0.= 1:57977/solr/collection1/: try and ask http://127.0.0.1:41421/solr/collecti= on1/ to sync [junit4:junit4] 2> 17131 T1487 C100 P60077 oasu.PeerSync.sync PeerSync: c= ore=3Dcollection1 url=3Dhttp://127.0.0.1:60077/solr START replicas=3D[http:= //127.0.0.1:57977/solr/collection1/] nUpdates=3D100 [junit4:junit4] 2> 17131 T1502 C102 P19335 oasu.PeerSync.sync PeerSync: c= ore=3Dcollection1 url=3Dhttp://127.0.0.1:19335/solr START replicas=3D[http:= //127.0.0.1:57977/solr/collection1/] nUpdates=3D100 [junit4:junit4] 2> 17132 T1515 C103 P41421 oasu.PeerSync.sync PeerSync: c= ore=3Dcollection1 url=3Dhttp://127.0.0.1:41421/solr START replicas=3D[http:= //127.0.0.1:57977/solr/collection1/] nUpdates=3D100 [junit4:junit4] 2> 17133 T1477 C101 P57977 REQ /get {distrib=3Dfalse&qt= =3D/get&wt=3Djavabin&version=3D2&getVersions=3D100} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 17134 T1473 C101 P57977 REQ /get {distrib=3Dfalse&qt= =3D/get&wt=3Djavabin&version=3D2&getVersions=3D100} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 17134 T1502 C102 P19335 oasu.PeerSync.handleVersions P= eerSync: core=3Dcollection1 url=3Dhttp://127.0.0.1:19335/solr Received 5 v= ersions from 127.0.0.1:57977/solr/collection1/ [junit4:junit4] 2> 17134 T1472 C101 P57977 REQ /get {distrib=3Dfalse&qt= =3D/get&wt=3Djavabin&version=3D2&getVersions=3D100} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 17134 T1502 C102 P19335 oasu.PeerSync.requestUpdates P= eerSync: core=3Dcollection1 url=3Dhttp://127.0.0.1:19335/solr Requesting up= dates from 127.0.0.1:57977/solr/collection1/n=3D1 versions=3D[1413542202437= 533696] [junit4:junit4] 2> 17134 T1515 C103 P41421 oasu.PeerSync.handleVersions P= eerSync: core=3Dcollection1 url=3Dhttp://127.0.0.1:41421/solr Received 5 v= ersions from 127.0.0.1:57977/solr/collection1/ [junit4:junit4] 2> 17135 T1487 C100 P60077 oasu.PeerSync.handleVersions P= eerSync: core=3Dcollection1 url=3Dhttp://127.0.0.1:60077/solr Received 5 v= ersions from 127.0.0.1:57977/solr/collection1/ [junit4:junit4] 2> 17135 T1515 C103 P41421 oasu.PeerSync.handleVersions P= eerSync: core=3Dcollection1 url=3Dhttp://127.0.0.1:41421/solr Our versions= are newer. ourLowThreshold=3D1413542202387202048 otherHigh=3D1413542202427= 047936 [junit4:junit4] 2> 17135 T1487 C100 P60077 oasu.PeerSync.requestUpdates P= eerSync: core=3Dcollection1 url=3Dhttp://127.0.0.1:60077/solr Requesting up= dates from 127.0.0.1:57977/solr/collection1/n=3D2 versions=3D[1413542202437= 533696, 1413542202427047936] [junit4:junit4] 2> 17135 T1515 C103 P41421 oasu.PeerSync.sync PeerSync: c= ore=3Dcollection1 url=3Dhttp://127.0.0.1:41421/solr DONE. sync succeeded [junit4:junit4] 2> 17136 T1515 C103 P41421 REQ /get {sync=3Dhttp://127.0.= 0.1:57977/solr/collection1/&getVersions=3D100&distrib=3Dfalse&qt=3D/get&wt= =3Djavabin&version=3D2} status=3D0 QTime=3D4=20 [junit4:junit4] 2> 17136 T1478 oasc.SyncStrategy.syncToMe http://127.0.0.= 1:57977/solr/collection1/: sync completed with http://127.0.0.1:41421/solr= /collection1/ [junit4:junit4] 2> 17137 T1472 C101 P57977 REQ /get {distrib=3Dfalse&getU= pdates=3D1413542202437533696&qt=3D/get&wt=3Djavabin&version=3D2} status=3D0= QTime=3D0=20 [junit4:junit4] 2> 17138 T1473 C101 P57977 REQ /get {distrib=3Dfalse&getU= pdates=3D1413542202437533696,1413542202427047936&qt=3D/get&wt=3Djavabin&ver= sion=3D2} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 17142 T1502 C102 P19335 oasu.PeerSync.sync PeerSync: c= ore=3Dcollection1 url=3Dhttp://127.0.0.1:19335/solr DONE. sync succeeded [junit4:junit4] 2> 17142 T1502 C102 P19335 REQ /get {sync=3Dhttp://127.0.= 0.1:57977/solr/collection1/&getVersions=3D100&distrib=3Dfalse&qt=3D/get&wt= =3Djavabin&version=3D2} status=3D0 QTime=3D11=20 [junit4:junit4] 2> 17143 T1478 oasc.SyncStrategy.syncToMe http://127.0.0.= 1:57977/solr/collection1/: sync completed with http://127.0.0.1:19335/solr= /collection1/ [junit4:junit4] 2> 17143 T1487 C100 P60077 oasu.PeerSync.sync PeerSync: c= ore=3Dcollection1 url=3Dhttp://127.0.0.1:60077/solr DONE. sync succeeded [junit4:junit4] 2> 17144 T1487 C100 P60077 REQ /get {sync=3Dhttp://127.0.= 0.1:57977/solr/collection1/&getVersions=3D100&distrib=3Dfalse&qt=3D/get&wt= =3Djavabin&version=3D2} status=3D0 QTime=3D14=20 [junit4:junit4] 2> 17144 T1478 oasc.SyncStrategy.syncToMe http://127.0.0.= 1:57977/solr/collection1/: sync completed with http://127.0.0.1:60077/solr= /collection1/ [junit4:junit4] 2> 17145 T1446 oasc.AbstractFullDistribZkTestBase.waitFor= ThingsToLevelOut Wait for recoveries to finish - wait 15 for each attempt [junit4:junit4] 2> 17145 T1446 oasc.AbstractDistribZkTestBase.waitForReco= veriesToFinish Wait for recoveries to finish - collection: collection1 fail= OnTimeout:true timeout (sec):15 [junit4:junit4] 2> 17146 T1446 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 17149 T1458 C104 P26494 oasu.DirectUpdateHandler2.comm= it start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dtru= e,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 17150 T1458 C104 P26494 oass.SolrIndexSearcher. = Opening Searcher@76454e71 main [junit4:junit4] 2> 17151 T1458 C104 P26494 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 17152 T1469 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@76454e71 main{StandardDirectoryReader(s= egments_2:3:nrt _0(4.0.0.2):C4)} [junit4:junit4] 2> 17153 T1458 C104 P26494 /update {waitSearcher=3Dtrue&w= t=3Djavabin&commit=3Dtrue&softCommit=3Dfalse&version=3D2} {commit=3D} 0 4 [junit4:junit4] 2> 17155 T1474 C101 P57977 oasu.DirectUpdateHandler2.comm= it start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dtru= e,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 17156 T1474 C101 P57977 oass.SolrIndexSearcher. = Opening Searcher@3d090e84 main [junit4:junit4] 2> 17157 T1474 C101 P57977 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 17158 T1481 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@3d090e84 main{StandardDirectoryReader(s= egments_2:3:nrt _0(4.0.0.2):C4)} [junit4:junit4] 2> 17159 T1474 C101 P57977 oasu.SolrCmdDistributor.distri= bCommit Distrib commit to:[StdNode: http://127.0.0.1:60077/solr/collection1= /, StdNode: http://127.0.0.1:19335/solr/collection1/, StdNode: http://127.0= .0.1:41421/solr/collection1/] [junit4:junit4] 2> 17161 T1498 C102 P19335 oasu.DirectUpdateHandler2.comm= it start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dtru= e,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 17161 T1512 C103 P41421 oasu.DirectUpdateHandler2.comm= it start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dtru= e,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 17161 T1484 C100 P60077 oasu.DirectUpdateHandler2.comm= it start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dtru= e,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 17162 T1512 C103 P41421 oass.SolrIndexSearcher. = Opening Searcher@12a20e8b main [junit4:junit4] 2> 17162 T1512 C103 P41421 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 17164 T1521 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@12a20e8b main{StandardDirectoryReader(s= egments_3:4:nrt _0(4.0.0.2):C4)} [junit4:junit4] 2> 17164 T1512 C103 P41421 /update {waitSearcher=3Dtrue&c= ommit=3Dtrue&wt=3Djavabin&commit_end_point=3Dtrue&expungeDeletes=3Dfalse&so= ftCommit=3Dfalse&version=3D2} {commit=3D} 0 3 [junit4:junit4] 2> 17233 T1498 C102 P19335 oasc.SolrDeletionPolicy.onComm= it SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/jetty3/index,segFN=3Dsegments_3,genera= tion=3D3,filenames=3D[_0.tis, _0.nrm, _0.fnm, _0.tii, _0.frq, _0.fdx, _0.si= , _0.prx, _0.fdt, segments_3] [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/jetty3/index,segFN=3Dsegments_4,genera= tion=3D4,filenames=3D[_0.nrm, _0.tis, _0.fnm, _1.tis, _1.frq, _1.fnm, _1.pr= x, _1.fdx, _0.tii, _1.fdt, _1.si, _0.frq, _1.tii, _0.fdx, _0.si, _0.prx, _1= .nrm, _0.fdt, segments_4] [junit4:junit4] 2> 17233 T1498 C102 P19335 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 4 [junit4:junit4] 2> 17237 T1498 C102 P19335 oass.SolrIndexSearcher. = Opening Searcher@3dab3ff9 main [junit4:junit4] 2> 17238 T1498 C102 P19335 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 17239 T1507 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@3dab3ff9 main{StandardDirectoryReader(s= egments_4:6:nrt _0(4.0.0.2):C3 _1(4.0.0.2):C1)} [junit4:junit4] 2> 17239 T1498 C102 P19335 /update {waitSearcher=3Dtrue&c= ommit=3Dtrue&wt=3Djavabin&commit_end_point=3Dtrue&expungeDeletes=3Dfalse&so= ftCommit=3Dfalse&version=3D2} {commit=3D} 0 78 [junit4:junit4] 2> 17242 T1484 C100 P60077 oasc.SolrDeletionPolicy.onComm= it SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/jetty2/index,segFN=3Dsegments_3,genera= tion=3D3,filenames=3D[_0.tis, _0.nrm, _0.fnm, _0.tii, _0.frq, _0.fdx, _0.si= , _0.prx, _0.fdt, segments_3] [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/jetty2/index,segFN=3Dsegments_4,genera= tion=3D4,filenames=3D[_0.nrm, _0.tis, _0.fnm, _1.tis, _1.frq, _1.fnm, _1.pr= x, _1.fdx, _0.tii, _1.fdt, _1.si, _0.frq, _1.tii, _0.fdx, _0.si, _0.prx, _1= .nrm, _0.fdt, segments_4] [junit4:junit4] 2> 17242 T1484 C100 P60077 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 4 [junit4:junit4] 2> 17246 T1484 C100 P60077 oass.SolrIndexSearcher. = Opening Searcher@666dfddb main [junit4:junit4] 2> 17247 T1484 C100 P60077 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 17249 T1493 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@666dfddb main{StandardDirectoryReader(s= egments_4:6:nrt _0(4.0.0.2):C2 _1(4.0.0.2):C2)} [junit4:junit4] 2> 17249 T1484 C100 P60077 /update {waitSearcher=3Dtrue&c= ommit=3Dtrue&wt=3Djavabin&commit_end_point=3Dtrue&expungeDeletes=3Dfalse&so= ftCommit=3Dfalse&version=3D2} {commit=3D} 0 88 [junit4:junit4] 2> 17250 T1474 C101 P57977 /update {waitSearcher=3Dtrue&w= t=3Djavabin&commit=3Dtrue&softCommit=3Dfalse&version=3D2} {commit=3D} 0 95 [junit4:junit4] 2> 17250 T1446 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 17253 T1475 C101 P57977 REQ /select {distrib=3Dfalse&w= t=3Djavabin&q=3D*:*&version=3D2} hits=3D4 status=3D0 QTime=3D0=20 [junit4:junit4] 2> 17256 T1485 C100 P60077 REQ /select {distrib=3Dfalse&w= t=3Djavabin&q=3D*:*&version=3D2} hits=3D4 status=3D0 QTime=3D0=20 [junit4:junit4] 2> 17259 T1499 C102 P19335 REQ /select {distrib=3Dfalse&w= t=3Djavabin&q=3D*:*&version=3D2} hits=3D4 status=3D0 QTime=3D0=20 [junit4:junit4] 2> 17262 T1513 C103 P41421 REQ /select {distrib=3Dfalse&w= t=3Djavabin&q=3D*:*&version=3D2} hits=3D4 status=3D0 QTime=3D0=20 [junit4:junit4] 2> 19269 T1459 C104 P26494 REQ /select {fl=3Did,score&sha= rd.url=3D127.0.0.1:26494/solr/collection1/&NOW=3D1348058896003&start=3D0&q= =3D*:*&distrib=3Dfalse&isShard=3Dtrue&wt=3Djavabin&fsv=3Dtrue&rows=3D10&ver= sion=3D2} hits=3D4 status=3D0 QTime=3D0=20 [junit4:junit4] 2> 19273 T1459 C104 P26494 REQ /select {shard.url=3D127.0= .0.1:26494/solr/collection1/&NOW=3D1348058896003&q=3D*:*&ids=3D3,2,1,0&dist= rib=3Dfalse&isShard=3Dtrue&wt=3Djavabin&version=3D2} status=3D0 QTime=3D1= =20 [junit4:junit4] 2> 19274 T1458 C104 P26494 REQ /select {wt=3Djavabin&q=3D= *:*&version=3D2} hits=3D4 status=3D0 QTime=3D8=20 [junit4:junit4] 2> Control Docs:4 [junit4:junit4] 2> 19275 T1446 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> check const of shard1 [junit4:junit4] 2> client0 [junit4:junit4] 2> PROPS:127.0.0.1:57977_solr_collection1:{"shard":"shard= 1","roles":null,"state":"active","core":"collection1","collection":"collect= ion1","node_name":"127.0.0.1:57977_solr","base_url":"http://127.0.0.1:57977= /solr","leader":"true"} [junit4:junit4] 2> 19278 T1475 C101 P57977 REQ /select {distrib=3Dfalse&w= t=3Djavabin&q=3D*:*&version=3D2} hits=3D4 status=3D0 QTime=3D0=20 [junit4:junit4] 2> live:true [junit4:junit4] 2> num:4 [junit4:junit4] 2>=20 [junit4:junit4] 2> client1 [junit4:junit4] 2> PROPS:127.0.0.1:60077_solr_collection1:{"shard":"shard= 1","roles":null,"state":"active","core":"collection1","collection":"collect= ion1","node_name":"127.0.0.1:60077_solr","base_url":"http://127.0.0.1:60077= /solr"} [junit4:junit4] 2> 19281 T1485 C100 P60077 REQ /select {distrib=3Dfalse&w= t=3Djavabin&q=3D*:*&version=3D2} hits=3D4 status=3D0 QTime=3D0=20 [junit4:junit4] 2> live:true [junit4:junit4] 2> num:4 [junit4:junit4] 2>=20 [junit4:junit4] 2> client2 [junit4:junit4] 2> PROPS:127.0.0.1:19335_solr_collection1:{"shard":"shard= 1","roles":null,"state":"active","core":"collection1","collection":"collect= ion1","node_name":"127.0.0.1:19335_solr","base_url":"http://127.0.0.1:19335= /solr"} [junit4:junit4] 2> 19284 T1499 C102 P19335 REQ /select {distrib=3Dfalse&w= t=3Djavabin&q=3D*:*&version=3D2} hits=3D4 status=3D0 QTime=3D0=20 [junit4:junit4] 2> live:true [junit4:junit4] 2> num:4 [junit4:junit4] 2>=20 [junit4:junit4] 2> client3 [junit4:junit4] 2> PROPS:127.0.0.1:41421_solr_collection1:{"shard":"shard= 1","roles":null,"state":"active","core":"collection1","collection":"collect= ion1","node_name":"127.0.0.1:41421_solr","base_url":"http://127.0.0.1:41421= /solr"} [junit4:junit4] 2> 19287 T1513 C103 P41421 REQ /select {distrib=3Dfalse&w= t=3Djavabin&q=3D*:*&version=3D2} hits=3D4 status=3D0 QTime=3D0=20 [junit4:junit4] 2> live:true [junit4:junit4] 2> num:4 [junit4:junit4] 2>=20 [junit4:junit4] 2> 19291 T1542 C101 P57977 REQ /select {fl=3Did,score&sha= rd.url=3D127.0.0.1:57977/solr/collection1/|127.0.0.1:60077/solr/collection1= /|127.0.0.1:19335/solr/collection1/|127.0.0.1:41421/solr/collection1/&NOW= =3D1348058896026&start=3D0&q=3D*:*&distrib=3Dfalse&isShard=3Dtrue&wt=3Djava= bin&fsv=3Dtrue&rows=3D10&version=3D2} hits=3D4 status=3D0 QTime=3D0=20 [junit4:junit4] 2> 19295 T1542 C101 P57977 REQ /select {shard.url=3D127.0= .0.1:57977/solr/collection1/|127.0.0.1:60077/solr/collection1/|127.0.0.1:19= 335/solr/collection1/|127.0.0.1:41421/solr/collection1/&NOW=3D1348058896026= &q=3D*:*&ids=3D3,2,1,0&distrib=3Dfalse&isShard=3Dtrue&wt=3Djavabin&version= =3D2} status=3D0 QTime=3D1=20 [junit4:junit4] 2> 19296 T1503 C102 P19335 REQ /select {wt=3Djavabin&q=3D= *:*&version=3D2} hits=3D4 status=3D0 QTime=3D7=20 [junit4:junit4] 2> 19301 T1458 C104 P26494 /update {wt=3Djavabin&version= =3D2} {add=3D[4 (1413542204968796160)]} 0 3 [junit4:junit4] 2> 19310 T1512 C103 P41421 REQ /update {distrib.from=3Dht= tp://127.0.0.1:57977/solr/collection1/&update.distrib=3DFROMLEADER&test.dis= trib.skip.servers=3Dhttp://127.0.0.1:19335/solr/collection1/&wt=3Djavabin&v= ersion=3D2} status=3D0 QTime=3D3=20 [junit4:junit4] 2> 19310 T1484 C100 P60077 REQ /update {distrib.from=3Dht= tp://127.0.0.1:57977/solr/collection1/&update.distrib=3DFROMLEADER&test.dis= trib.skip.servers=3Dhttp://127.0.0.1:19335/solr/collection1/&wt=3Djavabin&v= ersion=3D2} status=3D0 QTime=3D3=20 [junit4:junit4] 2> 19311 T1474 C101 P57977 /update {test.distrib.skip.ser= vers=3Dhttp://127.0.0.1:19335/solr/collection1/&wt=3Djavabin&version=3D2} {= add=3D[4 (1413542204974039040)]} 0 8 [junit4:junit4] 2> 19311 T1446 oasc.ChaosMonkey.monkeyLog monkey: kill sh= ard! 57977 [junit4:junit4] 2> 19312 T1446 oasc.CoreContainer.shutdown Shutting down = CoreContainer instance=3D1040311516 [junit4:junit4] 2> 19313 T1446 oasc.SolrCore.close [collection1] CLOSING= SolrCore org.apache.solr.core.SolrCore@12b69af7 [junit4:junit4] 2> 19324 T1446 oasc.SolrCore.closeSearcher [collection1] = Closing main searcher on request. [junit4:junit4] 2> 19325 T1446 oasu.DirectUpdateHandler2.close closing Di= rectUpdateHandler2{commits=3D6,autocommits=3D0,soft autocommits=3D0,optimiz= es=3D0,rollbacks=3D0,expungeDeletes=3D0,docsPending=3D1,adds=3D1,deletesByI= d=3D0,deletesByQuery=3D0,errors=3D0,cumulative_adds=3D5,cumulative_deletesB= yId=3D0,cumulative_deletesByQuery=3D1,cumulative_errors=3D0} [junit4:junit4] 2> 19325 T1446 oasu.DefaultSolrCoreState.decref SolrCoreS= tate ref count has reached 0 - closing IndexWriter [junit4:junit4] 2> 19379 T1446 C101 P57977 oasc.SolrDeletionPolicy.onComm= it SolrDeletionPolicy.onCommit: commits:num=3D3 [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/jetty1/index,segFN=3Dsegments_1,genera= tion=3D1,filenames=3D[segments_1] [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/jetty1/index,segFN=3Dsegments_2,genera= tion=3D2,filenames=3D[_0.tis, _0.nrm, _0.fnm, _0.tii, _0.frq, segments_2, _= 0.fdx, _0.si, _0.prx, _0.fdt] [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/jetty1/index,segFN=3Dsegments_3,genera= tion=3D3,filenames=3D[_0.nrm, _0.tis, _0.fnm, _1.tis, _1.frq, _1.fnm, _1.pr= x, _1.fdx, _0.tii, _1.fdt, _1.si, _0.frq, _1.tii, _0.fdx, _0.si, _0.prx, _1= .nrm, segments_3, _0.fdt] [junit4:junit4] 2> 19380 T1446 C101 P57977 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 3 [junit4:junit4] 2> 19382 T1446 oasu.DefaultSolrCoreState.decref Closing S= olrCoreState - canceling any ongoing recovery [junit4:junit4] 2> 19383 T1451 oazs.PrepRequestProcessor.pRequest Process= ed session termination for sessionid: 0x139de920b480003 [junit4:junit4] 2> 19384 T1466 oascc.ZkStateReader$3.process Updating liv= e nodes [junit4:junit4] 2> 19384 T1506 oascc.ZkStateReader$3.process Updating liv= e nodes [junit4:junit4] 2> 19384 T1527 oascc.ZkStateReader$3.process Updating liv= e nodes [junit4:junit4] 2> 19385 T1448 oazs.NIOServerCnxn.closeSock Closed socket= connection for client /140.211.11.196:59847 which had sessionid 0x139de920= b480003 [junit4:junit4] 2> 19384 T1525 oascc.ZkStateReader$3.process Updating liv= e nodes [junit4:junit4] 2> 19384 T1480 oascc.ZkStateReader$3.process Updating liv= e nodes [junit4:junit4] 2> 19384 T1446 oaz.ZooKeeper.close Session: 0x139de920b48= 0003 closed [junit4:junit4] 2> 19385 T1451 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x139de920b480004 type:de= lete cxid:0x49 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Pa= th:/solr/collections/collection1/leaders/shard1 Error:KeeperErrorCode =3D N= oNode for /solr/collections/collection1/leaders/shard1 [junit4:junit4] 2> 19384 T1520 oascc.ZkStateReader$3.process Updating liv= e nodes [junit4:junit4] 2> 19385 T1480 oascc.ZkStateReader$3.process WARNING ZooK= eeper watch triggered, but Solr cannot talk to ZK [junit4:junit4] 2> 19385 T1446 oejsh.ContextHandler.doStop stopped o.e.j.= s.ServletContextHandler{/solr,null} [junit4:junit4] 2> 19385 T1480 oaz.ClientCnxn$EventThread.run EventThread= shut down [junit4:junit4] 2> 19386 T1492 oasc.ShardLeaderElectionContext.runLeaderP= rocess Running the leader process. [junit4:junit4] 2> 19386 T1451 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x139de920b480004 type:cr= eate cxid:0x4a zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Pa= th:/solr/overseer Error:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 19395 T1492 oasc.ShardLeaderElectionContext.shouldIBeL= eader Checking if I should try and be the leader. [junit4:junit4] 2> 19395 T1492 oasc.ShardLeaderElectionContext.shouldIBeL= eader My last published State was Active, it's okay to be the leader. [junit4:junit4] 2> 19395 T1492 oasc.ShardLeaderElectionContext.runLeaderP= rocess I may be the new leader - try and sync [junit4:junit4] 2> 19395 T1492 oasc.SyncStrategy.sync Sync replicas to ht= tp://127.0.0.1:60077/solr/collection1/ [junit4:junit4] 2> 19396 T1492 oasu.PeerSync.sync PeerSync: core=3Dcollec= tion1 url=3Dhttp://127.0.0.1:60077/solr START replicas=3D[http://127.0.0.1:= 57977/solr/collection1/, http://127.0.0.1:19335/solr/collection1/, http://1= 27.0.0.1:41421/solr/collection1/] nUpdates=3D100 [junit4:junit4] 2> 19398 T1514 C103 P41421 REQ /get {distrib=3Dfalse&qt= =3D/get&wt=3Djavabin&version=3D2&getVersions=3D100} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 19398 T1501 C102 P19335 REQ /get {distrib=3Dfalse&qt= =3D/get&wt=3Djavabin&version=3D2&getVersions=3D100} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 19399 T1492 oasu.PeerSync.handleVersions PeerSync: cor= e=3Dcollection1 url=3Dhttp://127.0.0.1:60077/solr Received 6 versions from= 127.0.0.1:41421/solr/collection1/ [junit4:junit4] 2> 19399 T1492 oasu.PeerSync.handleVersions PeerSync: cor= e=3Dcollection1 url=3Dhttp://127.0.0.1:60077/solr Our versions are newer. = ourLowThreshold=3D1413542202402930688 otherHigh=3D1413542202437533696 [junit4:junit4] 2> 19399 T1492 oasu.PeerSync.handleVersions PeerSync: cor= e=3Dcollection1 url=3Dhttp://127.0.0.1:60077/solr Received 5 versions from= 127.0.0.1:19335/solr/collection1/ [junit4:junit4] 2> 19399 T1492 oasu.PeerSync.handleVersions PeerSync: cor= e=3Dcollection1 url=3Dhttp://127.0.0.1:60077/solr Our versions are newer. = ourLowThreshold=3D1413542202402930688 otherHigh=3D1413542202427047936 [junit4:junit4] 2> 19438 T1446 oasc.ChaosMonkey.monkeyLog monkey: stop sh= ard! 57977 [junit4:junit4] 2> 19810 T1467 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 19825 T1466 oascc.ZkStateReader$2.process A cluster st= ate change has occurred - updating... [junit4:junit4] 2> 19825 T1520 oascc.ZkStateReader$2.process A cluster st= ate change has occurred - updating... [junit4:junit4] 2> 19825 T1506 oascc.ZkStateReader$2.process A cluster st= ate change has occurred - updating... [junit4:junit4] 2> 19825 T1527 oascc.ZkStateReader$2.process A cluster st= ate change has occurred - updating... [junit4:junit4] 2> 19825 T1525 oascc.ZkStateReader$2.process A cluster st= ate change has occurred - updating... [junit4:junit4] 2> 49398 T1492 oasu.PeerSync.handleResponse WARNING PeerS= ync: core=3Dcollection1 url=3Dhttp://127.0.0.1:60077/solr exception talkin= g to http://127.0.0.1:57977/solr/collection1/, failed org.apache.solr.clien= t.solrj.SolrServerException: IOException occured when talking to server at:= http://127.0.0.1:57977/solr/collection1 [junit4:junit4] 2> =09at org.apache.solr.client.solrj.impl.HttpSolrServer= .request(HttpSolrServer.java:414) [junit4:junit4] 2> =09at org.apache.solr.client.solrj.impl.HttpSolrServer= .request(HttpSolrServer.java:182) [junit4:junit4] 2> =09at org.apache.solr.handler.component.HttpShardHandl= er$1.call(HttpShardHandler.java:166) [junit4:junit4] 2> =09at org.apache.solr.handler.component.HttpShardHandl= er$1.call(HttpShardHandler.java:133) [junit4:junit4] 2> =09at java.util.concurrent.FutureTask$Sync.innerRun(Fu= tureTask.java:334) [junit4:junit4] 2> =09at java.util.concurrent.FutureTask.run(FutureTask.j= ava:166) [junit4:junit4] 2> =09at java.util.concurrent.Executors$RunnableAdapter.c= all(Executors.java:471) [junit4:junit4] 2> =09at java.util.concurrent.FutureTask$Sync.innerRun(Fu= tureTask.java:334) [junit4:junit4] 2> =09at java.util.concurrent.FutureTask.run(FutureTask.j= ava:166) [junit4:junit4] 2> =09at java.util.concurrent.ThreadPoolExecutor.runWorke= r(ThreadPoolExecutor.java:1110) [junit4:junit4] 2> =09at java.util.concurrent.ThreadPoolExecutor$Worker.r= un(ThreadPoolExecutor.java:603) [junit4:junit4] 2> =09at java.lang.Thread.run(Thread.java:679) [junit4:junit4] 2> Caused by: org.apache.http.conn.ConnectTimeoutExceptio= n: Connect to 127.0.0.1:57977 timed out [junit4:junit4] 2> =09at org.apache.http.conn.scheme.PlainSocketFactory.c= onnectSocket(PlainSocketFactory.java:125) [junit4:junit4] 2> =09at org.apache.http.impl.conn.DefaultClientConnectio= nOperator.openConnection(DefaultClientConnectionOperator.java:148) [junit4:junit4] 2> =09at org.apache.http.impl.conn.AbstractPoolEntry.open= (AbstractPoolEntry.java:150) [junit4:junit4] 2> =09at org.apache.http.impl.conn.AbstractPooledConnAdap= ter.open(AbstractPooledConnAdapter.java:121) [junit4:junit4] 2> =09at org.apache.http.impl.client.DefaultRequestDirect= or.tryConnect(DefaultRequestDirector.java:575) [junit4:junit4] 2> =09at org.apache.http.impl.client.DefaultRequestDirect= or.execute(DefaultRequestDirector.java:425) [junit4:junit4] 2> =09at org.apache.http.impl.client.AbstractHttpClient.e= xecute(AbstractHttpClient.java:820) [junit4:junit4] 2> =09at org.apache.http.impl.client.AbstractHttpClient.e= xecute(AbstractHttpClient.java:754) [junit4:junit4] 2> =09at org.apache.http.impl.client.AbstractHttpClient.e= xecute(AbstractHttpClient.java:732) [junit4:junit4] 2> =09at org.apache.solr.client.solrj.impl.HttpSolrServer= .request(HttpSolrServer.java:353) [junit4:junit4] 2> =09... 11 more [junit4:junit4] 2>=20 [junit4:junit4] 2> 49400 T1492 oasu.PeerSync.sync PeerSync: core=3Dcollec= tion1 url=3Dhttp://127.0.0.1:60077/solr DONE. sync failed [junit4:junit4] 2> 49400 T1492 oasc.SolrException.log SEVERE Sync Failed [junit4:junit4] 2> 49400 T1492 oasc.ShardLeaderElectionContext.rejoinLead= erElection There is a better leader candidate than us - going back into rec= overy [junit4:junit4] 2> 49402 T1492 oasu.DefaultSolrCoreState.doRecovery Runni= ng recovery - first canceling any ongoing recovery [junit4:junit4] 2> 49403 T1546 C100 P60077 oasc.RecoveryStrategy.run Star= ting recovery process. core=3Dcollection1 recoveringAfterStartup=3Dfalse [junit4:junit4] 2> 49403 T1451 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x139de920b480005 type:de= lete cxid:0x48 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Pa= th:/solr/collections/collection1/leaders/shard1 Error:KeeperErrorCode =3D N= oNode for /solr/collections/collection1/leaders/shard1 [junit4:junit4] 2> 49416 T1506 oasc.ShardLeaderElectionContext.runLeaderP= rocess Running the leader process. [junit4:junit4] 2> 49417 T1451 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x139de920b480005 type:cr= eate cxid:0x49 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Pa= th:/solr/overseer Error:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 49417 T1546 C100 P60077 oasc.RecoveryStrategy.doRecove= ry Attempting to PeerSync from http://127.0.0.1:57977/solr/collection1/ cor= e=3Dcollection1 - recoveringAfterStartup=3Dfalse [junit4:junit4] 2> 49417 T1546 C100 P60077 oasu.PeerSync.sync PeerSync: c= ore=3Dcollection1 url=3Dhttp://127.0.0.1:60077/solr START replicas=3D[http:= //127.0.0.1:57977/solr/collection1/] nUpdates=3D100 [junit4:junit4] 2> 49418 T1506 oasc.ShardLeaderElectionContext.shouldIBeL= eader Checking if I should try and be the leader. [junit4:junit4] 2> 49418 T1506 oasc.ShardLeaderElectionContext.shouldIBeL= eader My last published State was Active, it's okay to be the leader. [junit4:junit4] 2> 49419 T1506 oasc.ShardLeaderElectionContext.runLeaderP= rocess I may be the new leader - try and sync [junit4:junit4] 2> 49419 T1506 oasc.SyncStrategy.sync Sync replicas to ht= tp://127.0.0.1:19335/solr/collection1/ [junit4:junit4] 2> 49419 T1492 oascc.ZkStateReader$3.process Updating liv= e nodes [junit4:junit4] 2> 49419 T1506 oasu.PeerSync.sync PeerSync: core=3Dcollec= tion1 url=3Dhttp://127.0.0.1:19335/solr START replicas=3D[http://127.0.0.1:= 60077/solr/collection1/, http://127.0.0.1:41421/solr/collection1/] nUpdates= =3D100 [junit4:junit4] 2> 49419 T1492 oascc.ZkStateReader$2.process A cluster st= ate change has occurred - updating... [junit4:junit4] 2> 49421 T1486 C100 P60077 REQ /get {distrib=3Dfalse&qt= =3D/get&wt=3Djavabin&version=3D2&getVersions=3D100} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 49422 T1506 oasu.PeerSync.handleVersions PeerSync: cor= e=3Dcollection1 url=3Dhttp://127.0.0.1:19335/solr Received 6 versions from= 127.0.0.1:60077/solr/collection1/ [junit4:junit4] 2> 49422 T1514 C103 P41421 REQ /get {distrib=3Dfalse&qt= =3D/get&wt=3Djavabin&version=3D2&getVersions=3D100} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 49422 T1506 oasu.PeerSync.requestUpdates PeerSync: cor= e=3Dcollection1 url=3Dhttp://127.0.0.1:19335/solr Requesting updates from 1= 27.0.0.1:60077/solr/collection1/n=3D1 versions=3D[1413542204974039040] [junit4:junit4] 2> 49423 T1506 oasu.PeerSync.handleVersions PeerSync: cor= e=3Dcollection1 url=3Dhttp://127.0.0.1:19335/solr Received 6 versions from= 127.0.0.1:41421/solr/collection1/ [junit4:junit4] 2> 49423 T1506 oasu.PeerSync.handleVersions PeerSync: cor= e=3Dcollection1 url=3Dhttp://127.0.0.1:19335/solr Our versions are newer. = ourLowThreshold=3D1413542202387202048 otherHigh=3D1413542202437533696 [junit4:junit4] 2> 49425 T1486 C100 P60077 REQ /get {distrib=3Dfalse&getU= pdates=3D1413542204974039040&qt=3D/get&wt=3Djavabin&version=3D2} status=3D0= QTime=3D0=20 [junit4:junit4] 2> 49468 T1446 oasc.AbstractFullDistribZkTestBase.waitFor= ThingsToLevelOut Wait for recoveries to finish - wait 15 for each attempt [junit4:junit4] 2> 49468 T1446 oasc.AbstractDistribZkTestBase.waitForReco= veriesToFinish Wait for recoveries to finish - collection: collection1 fail= OnTimeout:true timeout (sec):15 [junit4:junit4] 2> 49469 T1446 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 49471 T1458 C104 P26494 oasu.DirectUpdateHandler2.comm= it start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dtru= e,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 49505 T1458 C104 P26494 oasc.SolrDeletionPolicy.onComm= it SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/control/data/index,segFN=3Dsegments_2,= generation=3D2,filenames=3D[_0.tis, _0.nrm, _0.fnm, _0.tii, _0.frq, segment= s_2, _0.fdx, _0.si, _0.prx, _0.fdt] [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/control/data/index,segFN=3Dsegments_3,= generation=3D3,filenames=3D[_0.nrm, _0.tis, _0.fnm, _1.tis, _1.frq, _1.fnm,= _1.prx, _1.fdx, _0.tii, _1.fdt, _1.si, _0.frq, _1.tii, _0.fdx, _0.si, _0.p= rx, _1.nrm, segments_3, _0.fdt] [junit4:junit4] 2> 49505 T1458 C104 P26494 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 3 [junit4:junit4] 2> 49510 T1458 C104 P26494 oass.SolrIndexSearcher. = Opening Searcher@4ab36b28 main [junit4:junit4] 2> 49510 T1458 C104 P26494 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 49512 T1469 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@4ab36b28 main{StandardDirectoryReader(s= egments_3:5:nrt _0(4.0.0.2):C4 _1(4.0.0.2):C1)} [junit4:junit4] 2> 49512 T1458 C104 P26494 /update {waitSearcher=3Dtrue&w= t=3Djavabin&commit=3Dtrue&softCommit=3Dfalse&version=3D2} {commit=3D} 0 41 [junit4:junit4] 2> 49515 T1503 C102 P19335 oasu.DirectUpdateHandler2.comm= it start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dtru= e,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 49516 T1503 C102 P19335 oass.SolrIndexSearcher. = Opening Searcher@1672646a main [junit4:junit4] 2> 49517 T1503 C102 P19335 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 49518 T1507 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@1672646a main{StandardDirectoryReader(s= egments_4:6:nrt _0(4.0.0.2):C3 _1(4.0.0.2):C1)} [junit4:junit4] 2> 49519 T1503 C102 P19335 oasu.SolrCmdDistributor.distri= bCommit Distrib commit to:[StdNode: http://127.0.0.1:60077/solr/collection1= /, StdNode: http://127.0.0.1:41421/solr/collection1/] [junit4:junit4] 2> 49521 T1484 C100 P60077 oasu.DirectUpdateHandler2.comm= it start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dtru= e,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 49522 T1512 C103 P41421 oasu.DirectUpdateHandler2.comm= it start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dtru= e,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 49605 T1512 C103 P41421 oasc.SolrDeletionPolicy.onComm= it SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/jetty4/index,segFN=3Dsegments_3,genera= tion=3D3,filenames=3D[_0.tis, _0.nrm, _0.fnm, _0.tii, _0.frq, _0.fdx, _0.si= , _0.prx, _0.fdt, segments_3] [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/jetty4/index,segFN=3Dsegments_4,genera= tion=3D4,filenames=3D[_0.nrm, _0.tis, _0.fnm, _1.tis, _1.frq, _1.fnm, _1.pr= x, _1.fdx, _0.tii, _1.fdt, _1.si, _0.frq, _1.tii, _0.fdx, _0.si, _0.prx, _1= .nrm, _0.fdt, segments_4] [junit4:junit4] 2> 49606 T1512 C103 P41421 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 4 [junit4:junit4] 2> 49610 T1512 C103 P41421 oass.SolrIndexSearcher. = Opening Searcher@2d917ec main [junit4:junit4] 2> 49610 T1512 C103 P41421 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 49612 T1521 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@2d917ec main{StandardDirectoryReader(se= gments_4:6:nrt _0(4.0.0.2):C4 _1(4.0.0.2):C1)} [junit4:junit4] 2> 49612 T1512 C103 P41421 /update {waitSearcher=3Dtrue&c= ommit=3Dtrue&wt=3Djavabin&commit_end_point=3Dtrue&expungeDeletes=3Dfalse&so= ftCommit=3Dfalse&version=3D2} {commit=3D} 0 90 [junit4:junit4] 2> 49616 T1484 C100 P60077 oasc.SolrDeletionPolicy.onComm= it SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3D/usr/home/hudson/hudson-slave/works= pace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.so= lr.cloud.SyncSliceTest-1348058876740/jetty2/index,segFN=3Dsegments [...truncated too long message...] Log monkey: stop shard! 41421 [junit4:junit4] 2> 139525 T1446 oasc.CoreContainer.shutdown Shutting down= CoreContainer instance=3D70264423 [junit4:junit4] 2> 139525 T1446 oasc.SolrCore.close [collection1] CLOSIN= G SolrCore org.apache.solr.core.SolrCore@3cced2a6 [junit4:junit4] 2> 139539 T1446 oasc.SolrCore.closeSearcher [collection1]= Closing main searcher on request. [junit4:junit4] 2> 139539 T1446 oasu.DirectUpdateHandler2.close closing D= irectUpdateHandler2{commits=3D5,autocommits=3D0,soft autocommits=3D0,optimi= zes=3D0,rollbacks=3D0,expungeDeletes=3D0,docsPending=3D0,adds=3D0,deletesBy= Id=3D0,deletesByQuery=3D0,errors=3D0,cumulative_adds=3D5,cumulative_deletes= ById=3D0,cumulative_deletesByQuery=3D1,cumulative_errors=3D0} [junit4:junit4] 2> 139540 T1446 oasu.DefaultSolrCoreState.decref SolrCore= State ref count has reached 0 - closing IndexWriter [junit4:junit4] 2> 139541 T1446 oasu.DefaultSolrCoreState.decref Closing = SolrCoreState - canceling any ongoing recovery [junit4:junit4] 2> 140624 T1519 oaz.ClientCnxn$SendThread.startConnect Op= ening socket connection to server localhost/127.0.0.1:26491 [junit4:junit4] 2> 144576 T1520 oaz.ClientCnxn$EventThread.run EventThrea= d shut down [junit4:junit4] 2> 144576 T1446 oaz.ZooKeeper.close Session: 0x139de920b4= 80006 closed [junit4:junit4] 2> 144577 T1446 oejsh.ContextHandler.doStop stopped o.e.j= .s.ServletContextHandler{/solr,null} [junit4:junit4] 2> 144748 T1446 oas.SolrTestCaseJ4.tearDown ###Ending tes= tDistribSearch [junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=3DSyncSlice= Test -Dtests.method=3DtestDistribSearch -Dtests.seed=3D7FED73DFB5AF06E6 -Dt= ests.multiplier=3D3 -Dtests.slow=3Dtrue -Dtests.locale=3Dca -Dtests.timezon= e=3DAmerica/Guatemala -Dtests.file.encoding=3DUTF-8 [junit4:junit4] FAILURE 145s J1 | SyncSliceTest.testDistribSearch <<< [junit4:junit4] > Throwable #1: java.lang.AssertionError: There are stil= l nodes recoverying [junit4:junit4] > =09at __randomizedtesting.SeedInfo.seed([7FED73DFB5AF0= 6E6:FE0BFDC7C2F066DA]:0) [junit4:junit4] > =09at org.junit.Assert.fail(Assert.java:93) [junit4:junit4] > =09at org.apache.solr.cloud.AbstractDistribZkTestBase.= waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:154) [junit4:junit4] > =09at org.apache.solr.cloud.AbstractFullDistribZkTestB= ase.waitForRecoveriesToFinish(AbstractFullDistribZkTestBase.java:560) [junit4:junit4] > =09at org.apache.solr.cloud.AbstractFullDistribZkTestB= ase.waitForThingsToLevelOut(AbstractFullDistribZkTestBase.java:1135) [junit4:junit4] > =09at org.apache.solr.cloud.SyncSliceTest.doTest(SyncS= liceTest.java:162) [junit4:junit4] > =09at org.apache.solr.BaseDistributedSearchTestCase.te= stDistribSearch(BaseDistributedSearchTestCase.java:695) [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:616) [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:45) [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:48) [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:45) [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:679) [junit4:junit4] 2> 144906 T1446 oas.SolrTestCaseJ4.deleteCore ###deleteCo= re [junit4:junit4] 2> NOTE: test params are: codec=3DLucene3x, sim=3DRandomS= imilarityProvider(queryNorm=3Dfalse,coord=3Dno): {}, locale=3Dca, timezone= =3DAmerica/Guatemala [junit4:junit4] 2> NOTE: FreeBSD 9.0-RELEASE amd64/Sun Microsystems Inc. = 1.6.0_32 (64-bit)/cpus=3D16,threads=3D1,free=3D106235712,total=3D262078464 [junit4:junit4] 2> NOTE: All tests run in this JVM: [DistributedQueryElev= ationComponentTest, QueryEqualityTest, OpenExchangeRatesOrgProviderTest, Hi= ghlighterTest, TestPhraseSuggestions, RAMDirectoryFactoryTest, BasicDistrib= utedZk2Test, TestStressRecovery, MultiTermTest, ConvertedLegacyTest, SolrCo= reTest, PathHierarchyTokenizerFactoryTest, IndexReaderFactoryTest, IndexSch= emaRuntimeFieldTest, TestReload, TestCharFilters, SoftAutoCommitTest, Field= MutatingUpdateProcessorTest, TestSolrDeletionPolicy2, TestBinaryField, Test= StressLucene, LegacyHTMLStripCharFilterTest, TestCodecSupport, BadIndexSche= maTest, TestBM25SimilarityFactory, ReturnFieldsTest, ZkNodePropsTest, FullS= olrCloudDistribCmdsTest, TestReversedWildcardFilterFactory, TestSolrDeletio= nPolicy1, ClusterStateUpdateTest, TestFoldingMultitermQuery, DOMUtilTest, D= ocumentAnalysisRequestHandlerTest, PingRequestHandlerTest, TestSolrXMLSeria= lizer, FileUtilsTest, DisMaxRequestHandlerTest, TestPluginEnable, QueryPars= ingTest, RecoveryZkTest, OverseerTest, TestReplicationHandler, TestJmxInteg= ration, PrimUtilsTest, DocumentBuilderTest, SyncSliceTest] [junit4:junit4] Completed on J1 in 144.93s, 1 test, 1 failure <<< FAILURES! [...truncated 362 lines...] BUILD FAILED /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.x= ml:32: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/bu= ild.xml:146: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/= module-build.xml:63: The following error occurred while executing this line= : /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/= common-build.xml:1136: The following error occurred while executing this li= ne: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/= common-build.xml:810: There were test failures: 230 suites, 951 tests, 1 fa= ilure, 7 ignored (2 assumptions) Total time: 31 minutes 24 seconds Build step 'Invoke Ant' marked build as failure Recording test results Email was triggered for: Failure Sending email for trigger: Failure ------=_Part_443_2145800783.1348059221833 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_443_2145800783.1348059221833--