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 F2628E1F2 for ; Tue, 1 Jan 2013 01:40:07 +0000 (UTC) Received: (qmail 58958 invoked by uid 500); 1 Jan 2013 01:40:06 -0000 Delivered-To: apmail-lucene-dev-archive@lucene.apache.org Received: (qmail 58895 invoked by uid 500); 1 Jan 2013 01:40:06 -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 58888 invoked by uid 99); 1 Jan 2013 01:40:06 -0000 Received: from nike.apache.org (HELO nike.apache.org) (192.87.106.230) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 01 Jan 2013 01:40:06 +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; Tue, 01 Jan 2013 01:39:45 +0000 Received: from aegis.apache.org (localhost [127.0.0.1]) by aegis.apache.org (Postfix) with ESMTP id 1DBEFC00FE for ; Tue, 1 Jan 2013 01:39:23 +0000 (UTC) Date: Tue, 1 Jan 2013 01:38:55 +0000 (UTC) From: Apache Jenkins Server To: dev@lucene.apache.org Message-ID: <1291198605.3996.1357004363106.JavaMail.hudson@aegis> Subject: [JENKINS] Lucene-Solr-Tests-4.x-java7 - Build # 846 - Failure MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="----=_Part_3995_1850686708.1357004335591" X-Virus-Checked: Checked by ClamAV on apache.org ------=_Part_3995_1850686708.1357004335591 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-java7/846/ 3 tests failed. REGRESSION: org.apache.solr.cloud.BasicDistributedZkTest.testDistribSearch Error Message: Test abandoned because suite timeout was reached. Stack Trace: java.lang.Exception: Test abandoned because suite timeout was reached. =09at __randomizedtesting.SeedInfo.seed([A299B2FD956D8244]:0) FAILED: junit.framework.TestSuite.org.apache.solr.cloud.BasicDistributedZk= Test Error Message: Suite timeout exceeded (>=3D 7200000 msec). Stack Trace: java.lang.Exception: Suite timeout exceeded (>=3D 7200000 msec). =09at __randomizedtesting.SeedInfo.seed([A299B2FD956D8244]:0) REGRESSION: org.apache.solr.cloud.SyncSliceTest.testDistribSearch Error Message: shard1 should have just been set up to be inconsistent - but it's still con= sistent Stack Trace: java.lang.AssertionError: shard1 should have just been set up to be inconsi= stent - but it's still consistent =09at __randomizedtesting.SeedInfo.seed([A299B2FD956D8244:237F3CE5E232E278]= :0) =09at org.junit.Assert.fail(Assert.java:93) =09at org.junit.Assert.assertTrue(Assert.java:43) =09at org.junit.Assert.assertNotNull(Assert.java:526) =09at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:214) =09at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseD= istributedSearchTestCase.java:794) =09at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) =09at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.= java:57) =09at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces= sorImpl.java:43) =09at java.lang.reflect.Method.invoke(Method.java:601) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(Randomized= Runner.java:1559) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(Random= izedRunner.java:79) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(Random= izedRunner.java:737) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(Random= izedRunner.java:773) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(Random= izedRunner.java:787) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:53) =09at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRu= leSetupTeardownChained.java:50) =09at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFi= eldCacheSanity.java:51) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:46) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRul= e$1.evaluate(SystemPropertiesInvariantRule.java:55) =09at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleT= hreadAndTestName.java:49) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:70) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:48) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.= run(ThreadLeakControl.java:358) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTa= sk(ThreadLeakControl.java:782) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(Threa= dLeakControl.java:442) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(Ran= domizedRunner.java:746) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(Random= izedRunner.java:648) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(Random= izedRunner.java:682) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(Random= izedRunner.java:693) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:53) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:46) =09at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStor= eClassName.java:42) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRul= e$1.evaluate(SystemPropertiesInvariantRule.java:55) =09at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMeth= odsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) =09at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMeth= odsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRule= AssertionsRequired.java:43) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:48) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:70) =09at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIg= noreTestSuites.java:55) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.= run(ThreadLeakControl.java:358) =09at java.lang.Thread.run(Thread.java:722) Build Log: [...truncated 8801 lines...] [junit4:junit4] Suite: org.apache.solr.cloud.SyncSliceTest [junit4:junit4] 2> 1 T492 oas.BaseDistributedSearchTestCase.initHostConte= xt Setting hostContext system property: /rnq/ [junit4:junit4] 2> 7 T492 oas.SolrTestCaseJ4.setUp ###Starting testDistri= bSearch [junit4:junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/worksp= ace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./solrtest-Syn= cSliceTest-1356996946965 [junit4:junit4] 2> 9 T492 oasc.ZkTestServer.run STARTING ZK TEST SERVER [junit4:junit4] 2> 9 T493 oasc.ZkTestServer$ZKServerMain.runFromConfig St= arting server [junit4:junit4] 2> 12 T493 oazs.ZooKeeperServer.setTickTime tickTime set = to 1000 [junit4:junit4] 2> 12 T493 oazs.ZooKeeperServer.setMinSessionTimeout minS= essionTimeout set to -1 [junit4:junit4] 2> 12 T493 oazs.ZooKeeperServer.setMaxSessionTimeout maxS= essionTimeout set to -1 [junit4:junit4] 2> 12 T493 oazs.NIOServerCnxnFactory.configure binding to= port 0.0.0.0/0.0.0.0:0 [junit4:junit4] 2> 13 T493 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to= /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/b= uild/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-1356996946965/= zookeeper/server1/data/version-2/snapshot.0 [junit4:junit4] 2> 110 T492 oasc.ZkTestServer.run start zk server on port= :61919 [junit4:junit4] 2> 111 T492 oaz.ZooKeeper. Initiating client connec= tion, connectString=3D127.0.0.1:61919 sessionTimeout=3D10000 watcher=3Dorg.= apache.solr.common.cloud.ConnectionManager@20ba0da6 [junit4:junit4] 2> 112 T492 oascc.ConnectionManager.waitForConnected Wait= ing for client to connect to ZooKeeper [junit4:junit4] 2> 112 T498 oaz.ClientCnxn$SendThread.logStartConnect Ope= ning socket connection to server localhost/127.0.0.1:61919. Will not attemp= t to authenticate using SASL (access denied ("javax.security.auth.AuthPermi= ssion" "getLoginConfiguration")) [junit4:junit4] 2> 113 T498 oaz.ClientCnxn$SendThread.primeConnection Soc= ket connection established to localhost/127.0.0.1:61919, initiating session [junit4:junit4] 2> 113 T494 oazs.NIOServerCnxnFactory.run Accepted socket= connection from /140.211.11.196:61920 [junit4:junit4] 2> 113 T494 oazs.ZooKeeperServer.processConnectRequest Cl= ient attempting to establish new session at /140.211.11.196:61920 [junit4:junit4] 2> 114 T496 oazsp.FileTxnLog.append Creating new log file= : log.1 [junit4:junit4] 2> 116 T496 oazs.ZooKeeperServer.finishSessionInit Establ= ished session 0x13bf3522c1b0000 with negotiated timeout 10000 for client /1= 40.211.11.196:61920 [junit4:junit4] 2> 117 T498 oaz.ClientCnxn$SendThread.onConnected Session= establishment complete on server localhost/127.0.0.1:61919, sessionid =3D = 0x13bf3522c1b0000, negotiated timeout =3D 10000 [junit4:junit4] 2> 117 T499 oascc.ConnectionManager.process Watcher org.a= pache.solr.common.cloud.ConnectionManager@20ba0da6 name:ZooKeeperConnection= Watcher:127.0.0.1:61919 got event WatchedEvent state:SyncConnected type:No= ne path:null path:null type:None [junit4:junit4] 2> 117 T492 oascc.ConnectionManager.waitForConnected Clie= nt is connected to ZooKeeper [junit4:junit4] 2> 118 T492 oascc.SolrZkClient.makePath makePath: /solr [junit4:junit4] 2> 122 T497 oazs.PrepRequestProcessor.pRequest2Txn Proces= sed session termination for sessionid: 0x13bf3522c1b0000 [junit4:junit4] 2> 132 T499 oaz.ClientCnxn$EventThread.run EventThread sh= ut down [junit4:junit4] 2> 132 T492 oaz.ZooKeeper.close Session: 0x13bf3522c1b000= 0 closed [junit4:junit4] 2> 133 T494 oazs.NIOServerCnxn.closeSock Closed socket co= nnection for client /140.211.11.196:61920 which had sessionid 0x13bf3522c1b= 0000 [junit4:junit4] 2> 133 T492 oaz.ZooKeeper. Initiating client connec= tion, connectString=3D127.0.0.1:61919/solr sessionTimeout=3D10000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@aa9d70a [junit4:junit4] 2> 134 T492 oascc.ConnectionManager.waitForConnected Wait= ing for client to connect to ZooKeeper [junit4:junit4] 2> 135 T500 oaz.ClientCnxn$SendThread.logStartConnect Ope= ning socket connection to server localhost/127.0.0.1:61919. Will not attemp= t to authenticate using SASL (access denied ("javax.security.auth.AuthPermi= ssion" "getLoginConfiguration")) [junit4:junit4] 2> 135 T500 oaz.ClientCnxn$SendThread.primeConnection Soc= ket connection established to localhost/127.0.0.1:61919, initiating session [junit4:junit4] 2> 135 T494 oazs.NIOServerCnxnFactory.run Accepted socket= connection from /140.211.11.196:61921 [junit4:junit4] 2> 136 T494 oazs.ZooKeeperServer.processConnectRequest Cl= ient attempting to establish new session at /140.211.11.196:61921 [junit4:junit4] 2> 137 T496 oazs.ZooKeeperServer.finishSessionInit Establ= ished session 0x13bf3522c1b0001 with negotiated timeout 10000 for client /1= 40.211.11.196:61921 [junit4:junit4] 2> 137 T500 oaz.ClientCnxn$SendThread.onConnected Session= establishment complete on server localhost/127.0.0.1:61919, sessionid =3D = 0x13bf3522c1b0001, negotiated timeout =3D 10000 [junit4:junit4] 2> 138 T501 oascc.ConnectionManager.process Watcher org.a= pache.solr.common.cloud.ConnectionManager@aa9d70a name:ZooKeeperConnection = Watcher:127.0.0.1:61919/solr got event WatchedEvent state:SyncConnected typ= e:None path:null path:null type:None [junit4:junit4] 2> 138 T492 oascc.ConnectionManager.waitForConnected Clie= nt is connected to ZooKeeper [junit4:junit4] 2> 138 T492 oascc.SolrZkClient.makePath makePath: /collec= tions/collection1 [junit4:junit4] 2> 149 T492 oascc.SolrZkClient.makePath makePath: /collec= tions/collection1/shards [junit4:junit4] 2> 152 T492 oascc.SolrZkClient.makePath makePath: /collec= tions/control_collection [junit4:junit4] 2> 155 T492 oascc.SolrZkClient.makePath makePath: /collec= tions/control_collection/shards [junit4:junit4] 2> 159 T492 oasc.AbstractZkTestCase.putConfig put /usr/ho= me/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/sol= r-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf1/so= lrconfig.xml [junit4:junit4] 2> 160 T492 oascc.SolrZkClient.makePath makePath: /config= s/conf1/solrconfig.xml [junit4:junit4] 2> 174 T492 oasc.AbstractZkTestCase.putConfig put /usr/ho= me/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/sol= r-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema= .xml [junit4:junit4] 2> 175 T492 oascc.SolrZkClient.makePath makePath: /config= s/conf1/schema.xml [junit4:junit4] 2> 280 T492 oasc.AbstractZkTestCase.putConfig put /usr/ho= me/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/sol= r-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/sto= pwords.txt [junit4:junit4] 2> 281 T492 oascc.SolrZkClient.makePath makePath: /config= s/conf1/stopwords.txt [junit4:junit4] 2> 286 T492 oasc.AbstractZkTestCase.putConfig put /usr/ho= me/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/sol= r-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/pro= twords.txt [junit4:junit4] 2> 286 T492 oascc.SolrZkClient.makePath makePath: /config= s/conf1/protwords.txt [junit4:junit4] 2> 291 T492 oasc.AbstractZkTestCase.putConfig put /usr/ho= me/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/sol= r-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/curr= ency.xml [junit4:junit4] 2> 291 T492 oascc.SolrZkClient.makePath makePath: /config= s/conf1/currency.xml [junit4:junit4] 2> 296 T492 oasc.AbstractZkTestCase.putConfig put /usr/ho= me/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/sol= r-core/test-files/solr/collection1/conf/open-exchange-rates.json to /config= s/conf1/open-exchange-rates.json [junit4:junit4] 2> 296 T492 oascc.SolrZkClient.makePath makePath: /config= s/conf1/open-exchange-rates.json [junit4:junit4] 2> 301 T492 oasc.AbstractZkTestCase.putConfig put /usr/ho= me/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/sol= r-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /con= figs/conf1/mapping-ISOLatin1Accent.txt [junit4:junit4] 2> 302 T492 oascc.SolrZkClient.makePath makePath: /config= s/conf1/mapping-ISOLatin1Accent.txt [junit4:junit4] 2> 306 T492 oasc.AbstractZkTestCase.putConfig put /usr/ho= me/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/sol= r-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/= old_synonyms.txt [junit4:junit4] 2> 307 T492 oascc.SolrZkClient.makePath makePath: /config= s/conf1/old_synonyms.txt [junit4:junit4] 2> 311 T492 oasc.AbstractZkTestCase.putConfig put /usr/ho= me/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/sol= r-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/syno= nyms.txt [junit4:junit4] 2> 312 T492 oascc.SolrZkClient.makePath makePath: /config= s/conf1/synonyms.txt [junit4:junit4] 2> 316 T497 oazs.PrepRequestProcessor.pRequest2Txn Proces= sed session termination for sessionid: 0x13bf3522c1b0001 [junit4:junit4] 2> 317 T501 oaz.ClientCnxn$EventThread.run EventThread sh= ut down [junit4:junit4] 2> 317 T492 oaz.ZooKeeper.close Session: 0x13bf3522c1b000= 1 closed [junit4:junit4] 2> 317 T494 oazs.NIOServerCnxn.closeSock Closed socket co= nnection for client /140.211.11.196:61921 which had sessionid 0x13bf3522c1b= 0001 [junit4:junit4] 2> 485 T492 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 489 T492 oejs.AbstractConnector.doStart Started Socket= Connector@127.0.0.1:60709 [junit4:junit4] 2> 490 T492 oasc.SolrResourceLoader.locateSolrHome JNDI n= ot configured for solr (NoInitialContextEx) [junit4:junit4] 2> 491 T492 oasc.SolrResourceLoader.locateSolrHome using = system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Luc= ene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.clo= ud.SyncSliceTest-controljetty-1356996947275 [junit4:junit4] 2> 491 T492 oasc.SolrResourceLoader. new SolrResour= ceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cl= oud.SyncSliceTest-controljetty-1356996947275/' [junit4:junit4] 2> 536 T492 oass.SolrDispatchFilter.init SolrDispatchFilt= er.init() [junit4:junit4] 2> 537 T492 oasc.SolrResourceLoader.locateSolrHome JNDI n= ot configured for solr (NoInitialContextEx) [junit4:junit4] 2> 537 T492 oasc.SolrResourceLoader.locateSolrHome using = system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Luc= ene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.clo= ud.SyncSliceTest-controljetty-1356996947275 [junit4:junit4] 2> 538 T492 oasc.CoreContainer$Initializer.initialize loo= king for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Test= s-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceT= est-controljetty-1356996947275/solr.xml [junit4:junit4] 2> 538 T492 oasc.CoreContainer. New CoreContainer 1= 309600594 [junit4:junit4] 2> 539 T492 oasc.CoreContainer.load Loading CoreContainer= using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Test= s-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceT= est-controljetty-1356996947275/' [junit4:junit4] 2> 540 T492 oasc.SolrResourceLoader. new SolrResour= ceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.Sync= SliceTest-controljetty-1356996947275/' [junit4:junit4] 2> 569 T492 oashc.HttpShardHandlerFactory.getParameter Se= tting socketTimeout to: 30000 [junit4:junit4] 2> 570 T492 oashc.HttpShardHandlerFactory.getParameter Se= tting urlScheme to: http:// [junit4:junit4] 2> 570 T492 oashc.HttpShardHandlerFactory.getParameter Se= tting connTimeout to: 15000 [junit4:junit4] 2> 571 T492 oashc.HttpShardHandlerFactory.getParameter Se= tting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 571 T492 oashc.HttpShardHandlerFactory.getParameter Se= tting corePoolSize to: 0 [junit4:junit4] 2> 572 T492 oashc.HttpShardHandlerFactory.getParameter Se= tting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 572 T492 oashc.HttpShardHandlerFactory.getParameter Se= tting maxThreadIdleTime to: 5 [junit4:junit4] 2> 573 T492 oashc.HttpShardHandlerFactory.getParameter Se= tting sizeOfQueue to: -1 [junit4:junit4] 2> 573 T492 oashc.HttpShardHandlerFactory.getParameter Se= tting fairnessPolicy to: false [junit4:junit4] 2> 574 T492 oascsi.HttpClientUtil.createClient Creating n= ew http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000&so= cketTimeout=3D30000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 597 T492 oasc.CoreContainer.load Registering Log Liste= ner [junit4:junit4] 2> 617 T492 oasc.CoreContainer.initZooKeeper Zookeeper cl= ient=3D127.0.0.1:61919/solr [junit4:junit4] 2> 618 T492 oasc.ZkController.checkChrootPath zkHost incl= udes chroot [junit4:junit4] 2> 618 T492 oaz.ZooKeeper. Initiating client connec= tion, connectString=3D127.0.0.1:61919 sessionTimeout=3D60000 watcher=3Dorg.= apache.solr.common.cloud.ConnectionManager@1e0f477f [junit4:junit4] 2> 619 T492 oascc.ConnectionManager.waitForConnected Wait= ing for client to connect to ZooKeeper [junit4:junit4] 2> 620 T511 oaz.ClientCnxn$SendThread.logStartConnect Ope= ning socket connection to server localhost/127.0.0.1:61919. Will not attemp= t to authenticate using SASL (access denied ("javax.security.auth.AuthPermi= ssion" "getLoginConfiguration")) [junit4:junit4] 2> 621 T511 oaz.ClientCnxn$SendThread.primeConnection Soc= ket connection established to localhost/127.0.0.1:61919, initiating session [junit4:junit4] 2> 621 T494 oazs.NIOServerCnxnFactory.run Accepted socket= connection from /140.211.11.196:58397 [junit4:junit4] 2> 621 T494 oazs.ZooKeeperServer.processConnectRequest Cl= ient attempting to establish new session at /140.211.11.196:58397 [junit4:junit4] 2> 623 T496 oazs.ZooKeeperServer.finishSessionInit Establ= ished session 0x13bf3522c1b0002 with negotiated timeout 20000 for client /1= 40.211.11.196:58397 [junit4:junit4] 2> 623 T511 oaz.ClientCnxn$SendThread.onConnected Session= establishment complete on server localhost/127.0.0.1:61919, sessionid =3D = 0x13bf3522c1b0002, negotiated timeout =3D 20000 [junit4:junit4] 2> 623 T512 oascc.ConnectionManager.process Watcher org.a= pache.solr.common.cloud.ConnectionManager@1e0f477f name:ZooKeeperConnection= Watcher:127.0.0.1:61919 got event WatchedEvent state:SyncConnected type:No= ne path:null path:null type:None [junit4:junit4] 2> 623 T492 oascc.ConnectionManager.waitForConnected Clie= nt is connected to ZooKeeper [junit4:junit4] 2> 625 T497 oazs.PrepRequestProcessor.pRequest2Txn Proces= sed session termination for sessionid: 0x13bf3522c1b0002 [junit4:junit4] 2> 626 T512 oaz.ClientCnxn$EventThread.run EventThread sh= ut down [junit4:junit4] 2> 626 T494 oazs.NIOServerCnxn.closeSock Closed socket co= nnection for client /140.211.11.196:58397 which had sessionid 0x13bf3522c1b= 0002 [junit4:junit4] 2> 626 T492 oaz.ZooKeeper.close Session: 0x13bf3522c1b000= 2 closed [junit4:junit4] 2> 627 T492 oascsi.HttpClientUtil.createClient Creating n= ew http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&sock= etTimeout=3D15000&connTimeout=3D30000 [junit4:junit4] 2> 641 T492 oaz.ZooKeeper. Initiating client connec= tion, connectString=3D127.0.0.1:61919/solr sessionTimeout=3D30000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@4244cde1 [junit4:junit4] 2> 642 T513 oaz.ClientCnxn$SendThread.logStartConnect Ope= ning socket connection to server localhost/127.0.0.1:61919. Will not attemp= t to authenticate using SASL (access denied ("javax.security.auth.AuthPermi= ssion" "getLoginConfiguration")) [junit4:junit4] 2> 642 T492 oascc.ConnectionManager.waitForConnected Wait= ing for client to connect to ZooKeeper [junit4:junit4] 2> 642 T513 oaz.ClientCnxn$SendThread.primeConnection Soc= ket connection established to localhost/127.0.0.1:61919, initiating session [junit4:junit4] 2> 643 T494 oazs.NIOServerCnxnFactory.run Accepted socket= connection from /140.211.11.196:49836 [junit4:junit4] 2> 643 T494 oazs.ZooKeeperServer.processConnectRequest Cl= ient attempting to establish new session at /140.211.11.196:49836 [junit4:junit4] 2> 645 T496 oazs.ZooKeeperServer.finishSessionInit Establ= ished session 0x13bf3522c1b0003 with negotiated timeout 20000 for client /1= 40.211.11.196:49836 [junit4:junit4] 2> 645 T513 oaz.ClientCnxn$SendThread.onConnected Session= establishment complete on server localhost/127.0.0.1:61919, sessionid =3D = 0x13bf3522c1b0003, negotiated timeout =3D 20000 [junit4:junit4] 2> 645 T514 oascc.ConnectionManager.process Watcher org.a= pache.solr.common.cloud.ConnectionManager@4244cde1 name:ZooKeeperConnection= Watcher:127.0.0.1:61919/solr got event WatchedEvent state:SyncConnected ty= pe:None path:null path:null type:None [junit4:junit4] 2> 645 T492 oascc.ConnectionManager.waitForConnected Clie= nt is connected to ZooKeeper [junit4:junit4] 2> 648 T497 oazs.PrepRequestProcessor.pRequest Got user-l= evel KeeperException when processing sessionid:0x13bf3522c1b0003 type:creat= e cxid:0x2 zxid:0x1a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error= :KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 660 T492 oascc.SolrZkClient.makePath makePath: /live_n= odes [junit4:junit4] 2> 663 T492 oasc.ZkController.createEphemeralLiveNode Reg= ister node as live in ZooKeeper:/live_nodes/127.0.0.1:60709_rnq [junit4:junit4] 2> 664 T497 oazs.PrepRequestProcessor.pRequest Got user-l= evel KeeperException when processing sessionid:0x13bf3522c1b0003 type:delet= e cxid:0x7 zxid:0x1c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127= .0.0.1:60709_rnq Error:KeeperErrorCode =3D NoNode for /solr/live_nodes/127.= 0.0.1:60709_rnq [junit4:junit4] 2> 665 T492 oascc.SolrZkClient.makePath makePath: /live_n= odes/127.0.0.1:60709_rnq [junit4:junit4] 2> 675 T492 oascc.SolrZkClient.makePath makePath: /overse= er_elect/election [junit4:junit4] 2> 689 T497 oazs.PrepRequestProcessor.pRequest Got user-l= evel KeeperException when processing sessionid:0x13bf3522c1b0003 type:delet= e cxid:0x15 zxid:0x21 txntype:-1 reqpath:n/a Error Path:/solr/overseer_elec= t/leader Error:KeeperErrorCode =3D NoNode for /solr/overseer_elect/leader [junit4:junit4] 2> 690 T492 oascc.SolrZkClient.makePath makePath: /overse= er_elect/leader [junit4:junit4] 2> 693 T492 oasc.Overseer.start Overseer (id=3D8893215191= 6691459-127.0.0.1:60709_rnq-n_0000000000) starting [junit4:junit4] 2> 694 T497 oazs.PrepRequestProcessor.pRequest Got user-l= evel KeeperException when processing sessionid:0x13bf3522c1b0003 type:creat= e cxid:0x1a zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer Erro= r:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 700 T497 oazs.PrepRequestProcessor.pRequest Got user-l= evel KeeperException when processing sessionid:0x13bf3522c1b0003 type:creat= e cxid:0x1b zxid:0x24 txntype:-1 reqpath:n/a Error Path:/solr/overseer Erro= r:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 701 T497 oazs.PrepRequestProcessor.pRequest Got user-l= evel KeeperException when processing sessionid:0x13bf3522c1b0003 type:creat= e cxid:0x1c zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Erro= r:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 708 T497 oazs.PrepRequestProcessor.pRequest Got user-l= evel KeeperException when processing sessionid:0x13bf3522c1b0003 type:creat= e cxid:0x1d zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Erro= r:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 709 T516 oasc.OverseerCollectionProcessor.run Process = current queue of collection messages [junit4:junit4] 2> 710 T492 oascc.SolrZkClient.makePath makePath: /cluste= rstate.json [junit4:junit4] 2> 719 T492 oascc.ZkStateReader.createClusterStateWatcher= sAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 725 T517 oasc.CoreContainer.create Creating SolrCore '= collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Luc= ene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.clo= ud.SyncSliceTest-controljetty-1356996947275/collection1 [junit4:junit4] 2> 725 T515 oasc.Overseer$ClusterStateUpdater.run Startin= g to work on the main queue [junit4:junit4] 2> 725 T517 oasc.ZkController.createCollectionZkNode Chec= k for collection zkNode:control_collection [junit4:junit4] 2> 726 T517 oasc.ZkController.createCollectionZkNode Coll= ection zkNode exists [junit4:junit4] 2> 727 T517 oasc.ZkController.readConfigName Load collect= ion config from:/collections/control_collection [junit4:junit4] 2> 729 T517 oasc.SolrResourceLoader. new SolrResour= ceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.Sync= SliceTest-controljetty-1356996947275/collection1/' [junit4:junit4] 2> 730 T517 oasc.SolrResourceLoader.replaceClassLoader Ad= ding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-ja= va7/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-contro= ljetty-1356996947275/collection1/lib/README' to classloader [junit4:junit4] 2> 731 T517 oasc.SolrResourceLoader.replaceClassLoader Ad= ding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-ja= va7/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-contro= ljetty-1356996947275/collection1/lib/classes/' to classloader [junit4:junit4] 2> 786 T517 oasc.SolrConfig. Using Lucene MatchVers= ion: LUCENE_41 [junit4:junit4] 2> 858 T517 oasc.SolrConfig. Loaded SolrConfig: sol= rconfig.xml [junit4:junit4] 2> 959 T517 oass.IndexSchema.readSchema Reading Solr Sche= ma [junit4:junit4] 2> 966 T517 oass.IndexSchema.readSchema Schema name=3Dtes= t [junit4:junit4] 2> 1655 T517 oass.OpenExchangeRatesOrgProvider.init Initi= alized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 1667 T517 oass.IndexSchema.readSchema default search f= ield in schema is text [junit4:junit4] 2> 1672 T517 oass.IndexSchema.readSchema unique key field= : id [junit4:junit4] 2> 1694 T517 oass.FileExchangeRateProvider.reload Reloadi= ng exchange rates from file currency.xml [junit4:junit4] 2> 1699 T517 oass.FileExchangeRateProvider.reload Reloadi= ng exchange rates from file currency.xml [junit4:junit4] 2> 1705 T517 oass.OpenExchangeRatesOrgProvider.reload Rel= oading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 1707 T517 oass.OpenExchangeRatesOrgProvider.reload Rel= oading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 1708 T517 oasc.SolrCore. [collection1] Opening n= ew SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.= x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-= controljetty-1356996947275/collection1/, dataDir=3D./org.apache.solr.cloud.= SyncSliceTest-1356996946965/control/data/ [junit4:junit4] 2> 1709 T517 oasc.JmxMonitoredMap. JMX monitoring i= s enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBe= anServer@4ea17876 [junit4:junit4] 2> 1709 T517 oasc.SolrCore.initDirectoryFactory solr.NRTC= achingDirectoryFactory [junit4:junit4] 2> 1751 T517 oasc.CachingDirectoryFactory.get return new = directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x= -java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-1= 356996946965/control/data forceNew:false [junit4:junit4] 2> 1752 T517 oasc.CachingDirectoryFactory.close Releasing= directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-ja= va7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-1356= 996946965/control/data [junit4:junit4] 2> 1752 T517 oasc.SolrCore.getNewIndexDir New index direc= tory detected: old=3Dnull new=3D./org.apache.solr.cloud.SyncSliceTest-13569= 96946965/control/data/index/ [junit4:junit4] 2> 1753 T517 oasc.SolrCore.initIndex WARNING [collection1= ] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1356996946965= /control/data/index' doesn't exist. Creating new index... [junit4:junit4] 2> 1754 T517 oasc.CachingDirectoryFactory.get return new = directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x= -java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-1= 356996946965/control/data/index forceNew:false [junit4:junit4] 2> 1762 T517 oasc.SolrDeletionPolicy.onCommit SolrDeletio= nPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/o= rg.apache.solr.cloud.SyncSliceTest-1356996946965/control/data/index lockFac= tory=3Dorg.apache.lucene.store.NativeFSLockFactory@b161c9b; maxCacheMB=3D48= .0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_1,generation=3D1,filenames=3D[se= gments_1] [junit4:junit4] 2> 1762 T517 oasc.SolrDeletionPolicy.updateCommits newest= commit =3D 1[segments_1] [junit4:junit4] 2> 1763 T517 oasc.CachingDirectoryFactory.close Releasing= directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-ja= va7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-1356= 996946965/control/data/index [junit4:junit4] 2> 1764 T517 oasc.SolrCore.initWriters created xml: solr.= XMLResponseWriter [junit4:junit4] 2> 1766 T517 oasup.UpdateRequestProcessorChain.init inser= ting DistributedUpdateProcessorFactory into updateRequestProcessorChain "de= dupe" [junit4:junit4] 2> 1766 T517 oasup.UpdateRequestProcessorChain.init inser= ting DistributedUpdateProcessorFactory into updateRequestProcessorChain "de= dupe-allfields" [junit4:junit4] 2> 1767 T517 oasup.UpdateRequestProcessorChain.init inser= ting DistributedUpdateProcessorFactory into updateRequestProcessorChain "st= ored_sig" [junit4:junit4] 2> 1767 T517 oasup.UpdateRequestProcessorChain.init inser= ting DistributedUpdateProcessorFactory into updateRequestProcessorChain "un= iq-fields" [junit4:junit4] 2> 1768 T517 oasup.UpdateRequestProcessorChain.init inser= ting DistributedUpdateProcessorFactory into updateRequestProcessorChain "di= strib-dup-test-chain-implicit" [junit4:junit4] 2> 1768 T517 oasc.RequestHandlers.initHandlersFromConfig = adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 1768 T517 oasc.RequestHandlers.initHandlersFromConfig = created /replication: solr.ReplicationHandler [junit4:junit4] 2> 1769 T517 oasc.RequestHandlers.initHandlersFromConfig = created standard: solr.StandardRequestHandler [junit4:junit4] 2> 1769 T517 oasc.RequestHandlers.initHandlersFromConfig = created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 1770 T517 oasc.RequestHandlers.initHandlersFromConfig = created dismax: solr.SearchHandler [junit4:junit4] 2> 1770 T517 oasc.RequestHandlers.initHandlersFromConfig = created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler [junit4:junit4] 2> 1771 T517 oasc.RequestHandlers.initHandlersFromConfig = created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 1771 T517 oasc.RequestHandlers.initHandlersFromConfig = created defaults: solr.StandardRequestHandler [junit4:junit4] 2> 1772 T517 oasc.RequestHandlers.initHandlersFromConfig = adding lazy requestHandler: solr.StandardRequestHandler [junit4:junit4] 2> 1772 T517 oasc.RequestHandlers.initHandlersFromConfig = created lazy: solr.StandardRequestHandler [junit4:junit4] 2> 1772 T517 oasc.RequestHandlers.initHandlersFromConfig = created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 1773 T517 oasc.RequestHandlers.initHandlersFromConfig = created /terms: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 1773 T517 oasc.RequestHandlers.initHandlersFromConfig = created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 1774 T517 oasc.RequestHandlers.initHandlersFromConfig = created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHa= ndler [junit4:junit4] 2> 1774 T517 oasc.RequestHandlers.initHandlersFromConfig = created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHa= ndler [junit4:junit4] 2> 1775 T517 oasc.RequestHandlers.initHandlersFromConfig = created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.S= earchHandler [junit4:junit4] 2> 1775 T517 oasc.RequestHandlers.initHandlersFromConfig = created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 1776 T517 oasc.RequestHandlers.initHandlersFromConfig = created mltrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 1776 T517 oasc.RequestHandlers.initHandlersFromConfig = created tvrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 1777 T517 oasc.RequestHandlers.initHandlersFromConfig = created /mlt: solr.MoreLikeThisHandler [junit4:junit4] 2> 1777 T517 oasc.RequestHandlers.initHandlersFromConfig = created /debug/dump: solr.DumpRequestHandler [junit4:junit4] 2> 1790 T517 oashl.XMLLoader.init xsltCacheLifetimeSecond= s=3D60 [junit4:junit4] 2> 1795 T517 oasc.SolrCore.initDeprecatedSupport WARNING = solrconfig.xml uses deprecated , Please update your co= nfig to use the ShowFileRequestHandler. [junit4:junit4] 2> 1796 T517 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> 1799 T517 oasc.CachingDirectoryFactory.close Releasing= directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-ja= va7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-1356= 996946965/control/data [junit4:junit4] 2> 1801 T517 oass.SolrIndexSearcher. Opening Search= er@73f4117b main [junit4:junit4] 2> 1802 T517 oasu.CommitTracker. Hard AutoCommit: d= isabled [junit4:junit4] 2> 1802 T517 oasu.CommitTracker. Soft AutoCommit: d= isabled [junit4:junit4] 2> 1803 T517 oashc.SpellCheckComponent.inform Initializin= g spell checkers [junit4:junit4] 2> 1810 T517 oass.DirectSolrSpellChecker.init init: {name= =3Ddirect,classname=3DDirectSolrSpellChecker,field=3Dlowerfilt,minQueryLeng= th=3D3} [junit4:junit4] 2> 1863 T518 oasc.SolrCore.registerSearcher [collection1]= Registered new searcher Searcher@73f4117b main{StandardDirectoryReader(seg= ments_1:1)} [junit4:junit4] 2> 1868 T517 oasc.ZkController.publish publishing core=3D= collection1 state=3Ddown [junit4:junit4] 2> 1868 T517 oasc.ZkController.publish numShards not foun= d on descriptor - reading it from system property [junit4:junit4] 2> 1869 T497 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13bf3522c1b0003 type:crea= te cxid:0x50 zxid:0x29 txntype:-1 reqpath:n/a Error Path:/solr/overseer/que= ue Error:KeeperErrorCode =3D NoNode for /solr/overseer/queue [junit4:junit4] 2> 2232 T515 oascc.ZkStateReader.updateClusterState Updat= ing cloud state from ZooKeeper...=20 [junit4:junit4] 2> 2233 T515 oasc.Overseer$ClusterStateUpdater.updateStat= e Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "shard":null, [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"down", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"control_collection", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:60709_rnq", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:60709/rnq"} [junit4:junit4] 2> 2233 T515 oasc.Overseer$ClusterStateUpdater.createColl= ection Create collection control_collection with numShards 1 [junit4:junit4] 2> 2249 T515 oasc.Overseer$ClusterStateUpdater.updateStat= e Assigning new node to shard shard=3Dshard1 [junit4:junit4] 2> 2249 T497 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13bf3522c1b0003 type:crea= te cxid:0x58 zxid:0x2c txntype:-1 reqpath:n/a Error Path:/solr/overseer/que= ue-work Error:KeeperErrorCode =3D NoNode for /solr/overseer/queue-work [junit4:junit4] 2> 2268 T514 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clust= erstate.json, has occurred - updating... (live nodes size: 1) [junit4:junit4] 2> 2882 T517 oasc.CoreContainer.registerCore registering = core: collection1 [junit4:junit4] 2> 2882 T517 oasc.ZkController.register Register replica = - core:collection1 address:http://127.0.0.1:60709/rnq collection:control_co= llection shard:shard1 [junit4:junit4] 2> 2883 T517 oascc.SolrZkClient.makePath makePath: /colle= ctions/control_collection/leader_elect/shard1/election [junit4:junit4] 2> 2916 T497 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13bf3522c1b0003 type:dele= te cxid:0x72 zxid:0x36 txntype:-1 reqpath:n/a Error Path:/solr/collections/= control_collection/leaders Error:KeeperErrorCode =3D NoNode for /solr/colle= ctions/control_collection/leaders [junit4:junit4] 2> 2917 T517 oasc.ShardLeaderElectionContext.runLeaderPro= cess Running the leader process. [junit4:junit4] 2> 2918 T497 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13bf3522c1b0003 type:crea= te cxid:0x73 zxid:0x37 txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 2927 T517 oasc.ShardLeaderElectionContext.waitForRepli= casToComeUp Enough replicas found to continue. [junit4:junit4] 2> 2927 T517 oasc.ShardLeaderElectionContext.runLeaderPro= cess I may be the new leader - try and sync [junit4:junit4] 2> 2928 T517 oasc.SyncStrategy.sync Sync replicas to http= ://127.0.0.1:60709/rnq/collection1/ [junit4:junit4] 2> 2928 T517 oasc.SyncStrategy.syncReplicas Sync Success = - now sync replicas to me [junit4:junit4] 2> 2928 T517 oasc.SyncStrategy.syncToMe http://127.0.0.1:= 60709/rnq/collection1/ has no replicas [junit4:junit4] 2> 2928 T517 oasc.ShardLeaderElectionContext.runLeaderPro= cess I am the new leader: http://127.0.0.1:60709/rnq/collection1/ [junit4:junit4] 2> 2929 T517 oascc.SolrZkClient.makePath makePath: /colle= ctions/control_collection/leaders/shard1 [junit4:junit4] 2> 2933 T497 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13bf3522c1b0003 type:crea= te cxid:0x7d zxid:0x3b txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 3774 T515 oascc.ZkStateReader.updateClusterState Updat= ing cloud state from ZooKeeper...=20 [junit4:junit4] 2> 3843 T514 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clust= erstate.json, has occurred - updating... (live nodes size: 1) [junit4:junit4] 2> 3861 T517 oasc.ZkController.register We are http://127= .0.0.1:60709/rnq/collection1/ and leader is http://127.0.0.1:60709/rnq/coll= ection1/ [junit4:junit4] 2> 3861 T517 oasc.ZkController.register No LogReplay need= ed for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:60709/rnq [junit4:junit4] 2> 3861 T517 oasc.ZkController.checkRecovery I am the lea= der, no recovery necessary [junit4:junit4] 2> 3862 T517 oasc.ZkController.publish publishing core=3D= collection1 state=3Dactive [junit4:junit4] 2> 3862 T517 oasc.ZkController.publish numShards not foun= d on descriptor - reading it from system property [junit4:junit4] 2> 3864 T517 oascc.ZkStateReader.updateClusterState Updat= ing cloud state from ZooKeeper...=20 [junit4:junit4] 2> 3865 T492 oass.SolrDispatchFilter.init user.dir=3D/usr= /home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/= solr-core/test/J0 [junit4:junit4] 2> 3866 T492 oass.SolrDispatchFilter.init SolrDispatchFil= ter.init() done [junit4:junit4] 2> 3867 T492 oascsi.HttpClientUtil.createClient Creating = new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&fol= lowRedirects=3Dfalse [junit4:junit4] 2> 3886 T492 oascsi.HttpClientUtil.createClient Creating = new http client, config: [junit4:junit4] 2> 3905 T492 oaz.ZooKeeper. Initiating client conne= ction, connectString=3D127.0.0.1:61919/solr sessionTimeout=3D10000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@4421cbc6 [junit4:junit4] 2> 3906 T492 oascc.ConnectionManager.waitForConnected Wai= ting for client to connect to ZooKeeper [junit4:junit4] 2> 3906 T519 oaz.ClientCnxn$SendThread.logStartConnect Op= ening socket connection to server localhost/127.0.0.1:61919. Will not attem= pt to authenticate using SASL (access denied ("javax.security.auth.AuthPerm= ission" "getLoginConfiguration")) [junit4:junit4] 2> 3907 T519 oaz.ClientCnxn$SendThread.primeConnection So= cket connection established to localhost/127.0.0.1:61919, initiating sessio= n [junit4:junit4] 2> 3907 T494 oazs.NIOServerCnxnFactory.run Accepted socke= t connection from /140.211.11.196:50588 [junit4:junit4] 2> 3908 T494 oazs.ZooKeeperServer.processConnectRequest C= lient attempting to establish new session at /140.211.11.196:50588 [junit4:junit4] 2> 3912 T496 oazs.ZooKeeperServer.finishSessionInit Estab= lished session 0x13bf3522c1b0004 with negotiated timeout 10000 for client /= 140.211.11.196:50588 [junit4:junit4] 2> 3912 T519 oaz.ClientCnxn$SendThread.onConnected Sessio= n establishment complete on server localhost/127.0.0.1:61919, sessionid =3D= 0x13bf3522c1b0004, negotiated timeout =3D 10000 [junit4:junit4] 2> 3912 T520 oascc.ConnectionManager.process Watcher org.= apache.solr.common.cloud.ConnectionManager@4421cbc6 name:ZooKeeperConnectio= n Watcher:127.0.0.1:61919/solr got event WatchedEvent state:SyncConnected t= ype:None path:null path:null type:None [junit4:junit4] 2> 3913 T492 oascc.ConnectionManager.waitForConnected Cli= ent is connected to ZooKeeper [junit4:junit4] 2> 3914 T492 oascc.ZkStateReader.createClusterStateWatche= rsAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 3919 T492 oasc.ChaosMonkey.monkeyLog monkey: init - ex= pire sessions:true cause connection loss:true [junit4:junit4] 2> 4090 T492 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 4093 T492 oejs.AbstractConnector.doStart Started Socke= tConnector@127.0.0.1:15606 [junit4:junit4] 2> 4095 T492 oasc.SolrResourceLoader.locateSolrHome JNDI = not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 4095 T492 oasc.SolrResourceLoader.locateSolrHome using= system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cl= oud.SyncSliceTest-jetty1-1356996950877 [junit4:junit4] 2> 4096 T492 oasc.SolrResourceLoader. new SolrResou= rceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.c= loud.SyncSliceTest-jetty1-1356996950877/' [junit4:junit4] 2> 4138 T492 oass.SolrDispatchFilter.init SolrDispatchFil= ter.init() [junit4:junit4] 2> 4139 T492 oasc.SolrResourceLoader.locateSolrHome JNDI = not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 4139 T492 oasc.SolrResourceLoader.locateSolrHome using= system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cl= oud.SyncSliceTest-jetty1-1356996950877 [junit4:junit4] 2> 4140 T492 oasc.CoreContainer$Initializer.initialize lo= oking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tes= ts-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSlice= Test-jetty1-1356996950877/solr.xml [junit4:junit4] 2> 4140 T492 oasc.CoreContainer. New CoreContainer = 622396559 [junit4:junit4] 2> 4141 T492 oasc.CoreContainer.load Loading CoreContaine= r using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tes= ts-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSlice= Test-jetty1-1356996950877/' [junit4:junit4] 2> 4142 T492 oasc.SolrResourceLoader. new SolrResou= rceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-So= lr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.Syn= cSliceTest-jetty1-1356996950877/' [junit4:junit4] 2> 4173 T492 oashc.HttpShardHandlerFactory.getParameter S= etting socketTimeout to: 30000 [junit4:junit4] 2> 4174 T492 oashc.HttpShardHandlerFactory.getParameter S= etting urlScheme to: http:// [junit4:junit4] 2> 4175 T492 oashc.HttpShardHandlerFactory.getParameter S= etting connTimeout to: 15000 [junit4:junit4] 2> 4175 T492 oashc.HttpShardHandlerFactory.getParameter S= etting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 4175 T492 oashc.HttpShardHandlerFactory.getParameter S= etting corePoolSize to: 0 [junit4:junit4] 2> 4176 T492 oashc.HttpShardHandlerFactory.getParameter S= etting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 4176 T492 oashc.HttpShardHandlerFactory.getParameter S= etting maxThreadIdleTime to: 5 [junit4:junit4] 2> 4177 T492 oashc.HttpShardHandlerFactory.getParameter S= etting sizeOfQueue to: -1 [junit4:junit4] 2> 4177 T492 oashc.HttpShardHandlerFactory.getParameter S= etting fairnessPolicy to: false [junit4:junit4] 2> 4178 T492 oascsi.HttpClientUtil.createClient Creating = new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000&s= ocketTimeout=3D30000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 4202 T492 oasc.CoreContainer.load Registering Log List= ener [junit4:junit4] 2> 4222 T492 oasc.CoreContainer.initZooKeeper Zookeeper c= lient=3D127.0.0.1:61919/solr [junit4:junit4] 2> 4223 T492 oasc.ZkController.checkChrootPath zkHost inc= ludes chroot [junit4:junit4] 2> 4223 T492 oaz.ZooKeeper. Initiating client conne= ction, connectString=3D127.0.0.1:61919 sessionTimeout=3D60000 watcher=3Dorg= .apache.solr.common.cloud.ConnectionManager@4ddeb89b [junit4:junit4] 2> 4224 T492 oascc.ConnectionManager.waitForConnected Wai= ting for client to connect to ZooKeeper [junit4:junit4] 2> 4225 T530 oaz.ClientCnxn$SendThread.logStartConnect Op= ening socket connection to server localhost/127.0.0.1:61919. Will not attem= pt to authenticate using SASL (access denied ("javax.security.auth.AuthPerm= ission" "getLoginConfiguration")) [junit4:junit4] 2> 4226 T530 oaz.ClientCnxn$SendThread.primeConnection So= cket connection established to localhost/127.0.0.1:61919, initiating sessio= n [junit4:junit4] 2> 4226 T494 oazs.NIOServerCnxnFactory.run Accepted socke= t connection from /140.211.11.196:13436 [junit4:junit4] 2> 4226 T494 oazs.ZooKeeperServer.processConnectRequest C= lient attempting to establish new session at /140.211.11.196:13436 [junit4:junit4] 2> 4228 T496 oazs.ZooKeeperServer.finishSessionInit Estab= lished session 0x13bf3522c1b0005 with negotiated timeout 20000 for client /= 140.211.11.196:13436 [junit4:junit4] 2> 4228 T530 oaz.ClientCnxn$SendThread.onConnected Sessio= n establishment complete on server localhost/127.0.0.1:61919, sessionid =3D= 0x13bf3522c1b0005, negotiated timeout =3D 20000 [junit4:junit4] 2> 4229 T531 oascc.ConnectionManager.process Watcher org.= apache.solr.common.cloud.ConnectionManager@4ddeb89b name:ZooKeeperConnectio= n Watcher:127.0.0.1:61919 got event WatchedEvent state:SyncConnected type:N= one path:null path:null type:None [junit4:junit4] 2> 4229 T492 oascc.ConnectionManager.waitForConnected Cli= ent is connected to ZooKeeper [junit4:junit4] 2> 4231 T497 oazs.PrepRequestProcessor.pRequest2Txn Proce= ssed session termination for sessionid: 0x13bf3522c1b0005 [junit4:junit4] 2> 4232 T531 oaz.ClientCnxn$EventThread.run EventThread s= hut down [junit4:junit4] 2> 4232 T494 oazs.NIOServerCnxn.closeSock Closed socket c= onnection for client /140.211.11.196:13436 which had sessionid 0x13bf3522c1= b0005 [junit4:junit4] 2> 4232 T492 oaz.ZooKeeper.close Session: 0x13bf3522c1b00= 05 closed [junit4:junit4] 2> 4233 T492 oascsi.HttpClientUtil.createClient Creating = new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&soc= ketTimeout=3D15000&connTimeout=3D30000 [junit4:junit4] 2> 4248 T492 oaz.ZooKeeper. Initiating client conne= ction, connectString=3D127.0.0.1:61919/solr sessionTimeout=3D30000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@ccecf3 [junit4:junit4] 2> 4249 T492 oascc.ConnectionManager.waitForConnected Wai= ting for client to connect to ZooKeeper [junit4:junit4] 2> 4250 T532 oaz.ClientCnxn$SendThread.logStartConnect Op= ening socket connection to server localhost/127.0.0.1:61919. Will not attem= pt to authenticate using SASL (access denied ("javax.security.auth.AuthPerm= ission" "getLoginConfiguration")) [junit4:junit4] 2> 4250 T532 oaz.ClientCnxn$SendThread.primeConnection So= cket connection established to localhost/127.0.0.1:61919, initiating sessio= n [junit4:junit4] 2> 4251 T494 oazs.NIOServerCnxnFactory.run Accepted socke= t connection from /140.211.11.196:13437 [junit4:junit4] 2> 4251 T494 oazs.ZooKeeperServer.processConnectRequest C= lient attempting to establish new session at /140.211.11.196:13437 [junit4:junit4] 2> 4253 T496 oazs.ZooKeeperServer.finishSessionInit Estab= lished session 0x13bf3522c1b0006 with negotiated timeout 20000 for client /= 140.211.11.196:13437 [junit4:junit4] 2> 4253 T532 oaz.ClientCnxn$SendThread.onConnected Sessio= n establishment complete on server localhost/127.0.0.1:61919, sessionid =3D= 0x13bf3522c1b0006, negotiated timeout =3D 20000 [junit4:junit4] 2> 4254 T533 oascc.ConnectionManager.process Watcher org.= apache.solr.common.cloud.ConnectionManager@ccecf3 name:ZooKeeperConnection = Watcher:127.0.0.1:61919/solr got event WatchedEvent state:SyncConnected typ= e:None path:null path:null type:None [junit4:junit4] 2> 4254 T492 oascc.ConnectionManager.waitForConnected Cli= ent is connected to ZooKeeper [junit4:junit4] 2> 4256 T497 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13bf3522c1b0006 type:crea= te cxid:0x1 zxid:0x49 txntype:-1 reqpath:n/a Error Path:/solr/overseer Erro= r:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 4263 T497 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13bf3522c1b0006 type:crea= te cxid:0x2 zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/overseer Erro= r:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 4266 T492 oasc.ZkController.createEphemeralLiveNode Re= gister node as live in ZooKeeper:/live_nodes/127.0.0.1:15606_rnq [junit4:junit4] 2> 4267 T497 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13bf3522c1b0006 type:dele= te cxid:0x4 zxid:0x4b txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/12= 7.0.0.1:15606_rnq Error:KeeperErrorCode =3D NoNode for /solr/live_nodes/127= .0.0.1:15606_rnq [junit4:junit4] 2> 4268 T492 oascc.SolrZkClient.makePath makePath: /live_= nodes/127.0.0.1:15606_rnq [junit4:junit4] 2> 4280 T514 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/l= ive_nodes, has occurred - updating... (live nodes size: 1) [junit4:junit4] 2> 4281 T520 oascc.ZkStateReader$3.process Updating live = nodes... (2) [junit4:junit4] 2> 4289 T514 oascc.ZkStateReader$3.process Updating live = nodes... (2) [junit4:junit4] 2> 4292 T492 oascc.ZkStateReader.createClusterStateWatche= rsAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 4299 T534 oasc.CoreContainer.create Creating SolrCore = 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cl= oud.SyncSliceTest-jetty1-1356996950877/collection1 [junit4:junit4] 2> 4299 T534 oasc.ZkController.createCollectionZkNode Che= ck for collection zkNode:collection1 [junit4:junit4] 2> 4300 T534 oasc.ZkController.createCollectionZkNode Col= lection zkNode exists [junit4:junit4] 2> 4301 T534 oasc.ZkController.readConfigName Load collec= tion config from:/collections/collection1 [junit4:junit4] 2> 4303 T534 oasc.SolrResourceLoader. new SolrResou= rceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-So= lr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.Syn= cSliceTest-jetty1-1356996950877/collection1/' [junit4:junit4] 2> 4304 T534 oasc.SolrResourceLoader.replaceClassLoader A= dding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-j= ava7/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty= 1-1356996950877/collection1/lib/README' to classloader [junit4:junit4] 2> 4305 T534 oasc.SolrResourceLoader.replaceClassLoader A= dding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-j= ava7/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty= 1-1356996950877/collection1/lib/classes/' to classloader [junit4:junit4] 2> 4361 T534 oasc.SolrConfig. Using Lucene MatchVer= sion: LUCENE_41 [junit4:junit4] 2> 4431 T534 oasc.SolrConfig. Loaded SolrConfig: so= lrconfig.xml [junit4:junit4] 2> 4532 T534 oass.IndexSchema.readSchema Reading Solr Sch= ema [junit4:junit4] 2> 4539 T534 oass.IndexSchema.readSchema Schema name=3Dte= st [junit4:junit4] 2> 5159 T534 oass.OpenExchangeRatesOrgProvider.init Initi= alized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 5170 T534 oass.IndexSchema.readSchema default search f= ield in schema is text [junit4:junit4] 2> 5175 T534 oass.IndexSchema.readSchema unique key field= : id [junit4:junit4] 2> 5193 T534 oass.FileExchangeRateProvider.reload Reloadi= ng exchange rates from file currency.xml [junit4:junit4] 2> 5208 T534 oass.FileExchangeRateProvider.reload Reloadi= ng exchange rates from file currency.xml [junit4:junit4] 2> 5214 T534 oass.OpenExchangeRatesOrgProvider.reload Rel= oading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 5215 T534 oass.OpenExchangeRatesOrgProvider.reload Rel= oading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 5217 T534 oasc.SolrCore. [collection1] Opening n= ew SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.= x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-= jetty1-1356996950877/collection1/, dataDir=3D./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty1/ [junit4:junit4] 2> 5217 T534 oasc.JmxMonitoredMap. JMX monitoring i= s enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBe= anServer@4ea17876 [junit4:junit4] 2> 5218 T534 oasc.SolrCore.initDirectoryFactory solr.NRTC= achingDirectoryFactory [junit4:junit4] 2> 5219 T534 oasc.CachingDirectoryFactory.get return new = directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x= -java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-1= 356996946965/jetty1 forceNew:false [junit4:junit4] 2> 5220 T534 oasc.CachingDirectoryFactory.close Releasing= directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-ja= va7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-1356= 996946965/jetty1 [junit4:junit4] 2> 5220 T534 oasc.SolrCore.getNewIndexDir New index direc= tory detected: old=3Dnull new=3D./org.apache.solr.cloud.SyncSliceTest-13569= 96946965/jetty1/index/ [junit4:junit4] 2> 5221 T534 oasc.SolrCore.initIndex WARNING [collection1= ] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1356996946965= /jetty1/index' doesn't exist. Creating new index... [junit4:junit4] 2> 5222 T534 oasc.CachingDirectoryFactory.get return new = directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x= -java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-1= 356996946965/jetty1/index forceNew:false [junit4:junit4] 2> 5228 T534 oasc.SolrDeletionPolicy.onCommit SolrDeletio= nPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/o= rg.apache.solr.cloud.SyncSliceTest-1356996946965/jetty1/index lockFactory= =3Dorg.apache.lucene.store.NativeFSLockFactory@34c8ae05; maxCacheMB=3D48.0 = maxMergeSizeMB=3D4.0)),segFN=3Dsegments_1,generation=3D1,filenames=3D[segme= nts_1] [junit4:junit4] 2> 5228 T534 oasc.SolrDeletionPolicy.updateCommits newest= commit =3D 1[segments_1] [junit4:junit4] 2> 5229 T534 oasc.CachingDirectoryFactory.close Releasing= directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-ja= va7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-1356= 996946965/jetty1/index [junit4:junit4] 2> 5229 T534 oasc.SolrCore.initWriters created xml: solr.= XMLResponseWriter [junit4:junit4] 2> 5232 T534 oasup.UpdateRequestProcessorChain.init inser= ting DistributedUpdateProcessorFactory into updateRequestProcessorChain "de= dupe" [junit4:junit4] 2> 5232 T534 oasup.UpdateRequestProcessorChain.init inser= ting DistributedUpdateProcessorFactory into updateRequestProcessorChain "de= dupe-allfields" [junit4:junit4] 2> 5233 T534 oasup.UpdateRequestProcessorChain.init inser= ting DistributedUpdateProcessorFactory into updateRequestProcessorChain "st= ored_sig" [junit4:junit4] 2> 5233 T534 oasup.UpdateRequestProcessorChain.init inser= ting DistributedUpdateProcessorFactory into updateRequestProcessorChain "un= iq-fields" [junit4:junit4] 2> 5234 T534 oasup.UpdateRequestProcessorChain.init inser= ting DistributedUpdateProcessorFactory into updateRequestProcessorChain "di= strib-dup-test-chain-implicit" [junit4:junit4] 2> 5234 T534 oasc.RequestHandlers.initHandlersFromConfig = adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 5234 T534 oasc.RequestHandlers.initHandlersFromConfig = created /replication: solr.ReplicationHandler [junit4:junit4] 2> 5235 T534 oasc.RequestHandlers.initHandlersFromConfig = created standard: solr.StandardRequestHandler [junit4:junit4] 2> 5236 T534 oasc.RequestHandlers.initHandlersFromConfig = created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 5236 T534 oasc.RequestHandlers.initHandlersFromConfig = created dismax: solr.SearchHandler [junit4:junit4] 2> 5237 T534 oasc.RequestHandlers.initHandlersFromConfig = created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler [junit4:junit4] 2> 5237 T534 oasc.RequestHandlers.initHandlersFromConfig = created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 5238 T534 oasc.RequestHandlers.initHandlersFromConfig = created defaults: solr.StandardRequestHandler [junit4:junit4] 2> 5238 T534 oasc.RequestHandlers.initHandlersFromConfig = adding lazy requestHandler: solr.StandardRequestHandler [junit4:junit4] 2> 5239 T534 oasc.RequestHandlers.initHandlersFromConfig = created lazy: solr.StandardRequestHandler [junit4:junit4] 2> 5239 T534 oasc.RequestHandlers.initHandlersFromConfig = created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 5240 T534 oasc.RequestHandlers.initHandlersFromConfig = created /terms: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 5240 T534 oasc.RequestHandlers.initHandlersFromConfig = created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 5241 T534 oasc.RequestHandlers.initHandlersFromConfig = created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHa= ndler [junit4:junit4] 2> 5241 T534 oasc.RequestHandlers.initHandlersFromConfig = created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHa= ndler [junit4:junit4] 2> 5242 T534 oasc.RequestHandlers.initHandlersFromConfig = created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.S= earchHandler [junit4:junit4] 2> 5243 T534 oasc.RequestHandlers.initHandlersFromConfig = created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 5243 T534 oasc.RequestHandlers.initHandlersFromConfig = created mltrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 5244 T534 oasc.RequestHandlers.initHandlersFromConfig = created tvrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 5244 T534 oasc.RequestHandlers.initHandlersFromConfig = created /mlt: solr.MoreLikeThisHandler [junit4:junit4] 2> 5245 T534 oasc.RequestHandlers.initHandlersFromConfig = created /debug/dump: solr.DumpRequestHandler [junit4:junit4] 2> 5258 T534 oashl.XMLLoader.init xsltCacheLifetimeSecond= s=3D60 [junit4:junit4] 2> 5262 T534 oasc.SolrCore.initDeprecatedSupport WARNING = solrconfig.xml uses deprecated , Please update your co= nfig to use the ShowFileRequestHandler. [junit4:junit4] 2> 5264 T534 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> 5268 T534 oasc.CachingDirectoryFactory.close Releasing= directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-ja= va7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-1356= 996946965/jetty1 [junit4:junit4] 2> 5269 T534 oass.SolrIndexSearcher. Opening Search= er@5544f245 main [junit4:junit4] 2> 5271 T534 oasu.CommitTracker. Hard AutoCommit: d= isabled [junit4:junit4] 2> 5271 T534 oasu.CommitTracker. Soft AutoCommit: d= isabled [junit4:junit4] 2> 5272 T534 oashc.SpellCheckComponent.inform Initializin= g spell checkers [junit4:junit4] 2> 5278 T534 oass.DirectSolrSpellChecker.init init: {name= =3Ddirect,classname=3DDirectSolrSpellChecker,field=3Dlowerfilt,minQueryLeng= th=3D3} [junit4:junit4] 2> 5333 T535 oasc.SolrCore.registerSearcher [collection1]= Registered new searcher Searcher@5544f245 main{StandardDirectoryReader(seg= ments_1:1)} [junit4:junit4] 2> 5338 T534 oasc.ZkController.publish publishing core=3D= collection1 state=3Ddown [junit4:junit4] 2> 5339 T534 oasc.ZkController.publish numShards not foun= d on descriptor - reading it from system property [junit4:junit4] 2> 5358 T515 oascc.ZkStateReader.updateClusterState Updat= ing cloud state from ZooKeeper...=20 [junit4:junit4] 2> 5359 T515 oasc.Overseer$ClusterStateUpdater.updateStat= e Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "shard":"shard1", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"active", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"control_collection", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:60709_rnq", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:60709/rnq"} [junit4:junit4] 2> 5371 T515 oasc.Overseer$ClusterStateUpdater.updateStat= e Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "shard":null, [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"down", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:15606_rnq", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:15606/rnq"} [junit4:junit4] 2> 5371 T515 oasc.Overseer$ClusterStateUpdater.createColl= ection Create collection collection1 with numShards 1 [junit4:junit4] 2> 5372 T515 oasc.Overseer$ClusterStateUpdater.updateStat= e Assigning new node to shard shard=3Dshard1 [junit4:junit4] 2> 5386 T514 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clust= erstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 5386 T520 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clust= erstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 5386 T533 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clust= erstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 6341 T534 oasc.CoreContainer.registerCore registering = core: collection1 [junit4:junit4] 2> 6341 T534 oasc.ZkController.register Register replica = - core:collection1 address:http://127.0.0.1:15606/rnq collection:collection= 1 shard:shard1 [junit4:junit4] 2> 6342 T534 oascc.SolrZkClient.makePath makePath: /colle= ctions/collection1/leader_elect/shard1/election [junit4:junit4] 2> 6359 T497 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13bf3522c1b0006 type:dele= te cxid:0x43 zxid:0x5a txntype:-1 reqpath:n/a Error Path:/solr/collections/= collection1/leaders Error:KeeperErrorCode =3D NoNode for /solr/collections/= collection1/leaders [junit4:junit4] 2> 6360 T534 oasc.ShardLeaderElectionContext.runLeaderPro= cess Running the leader process. [junit4:junit4] 2> 6361 T497 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13bf3522c1b0006 type:crea= te cxid:0x44 zxid:0x5b txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 6363 T534 oasc.ShardLeaderElectionContext.waitForRepli= casToComeUp Enough replicas found to continue. [junit4:junit4] 2> 6363 T534 oasc.ShardLeaderElectionContext.runLeaderPro= cess I may be the new leader - try and sync [junit4:junit4] 2> 6364 T534 oasc.SyncStrategy.sync Sync replicas to http= ://127.0.0.1:15606/rnq/collection1/ [junit4:junit4] 2> 6364 T534 oasc.SyncStrategy.syncReplicas Sync Success = - now sync replicas to me [junit4:junit4] 2> 6364 T534 oasc.SyncStrategy.syncToMe http://127.0.0.1:= 15606/rnq/collection1/ has no replicas [junit4:junit4] 2> 6364 T534 oasc.ShardLeaderElectionContext.runLeaderPro= cess I am the new leader: http://127.0.0.1:15606/rnq/collection1/ [junit4:junit4] 2> 6365 T534 oascc.SolrZkClient.makePath makePath: /colle= ctions/collection1/leaders/shard1 [junit4:junit4] 2> 6370 T497 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13bf3522c1b0006 type:crea= te cxid:0x4e zxid:0x5f txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 6895 T515 oascc.ZkStateReader.updateClusterState Updat= ing cloud state from ZooKeeper...=20 [junit4:junit4] 2> 6914 T514 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clust= erstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 6914 T520 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clust= erstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 6914 T533 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clust= erstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 6937 T534 oasc.ZkController.register We are http://127= .0.0.1:15606/rnq/collection1/ and leader is http://127.0.0.1:15606/rnq/coll= ection1/ [junit4:junit4] 2> 6937 T534 oasc.ZkController.register No LogReplay need= ed for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:15606/rnq [junit4:junit4] 2> 6937 T534 oasc.ZkController.checkRecovery I am the lea= der, no recovery necessary [junit4:junit4] 2> 6937 T534 oasc.ZkController.publish publishing core=3D= collection1 state=3Dactive [junit4:junit4] 2> 6938 T534 oasc.ZkController.publish numShards not foun= d on descriptor - reading it from system property [junit4:junit4] 2> 6940 T534 oascc.ZkStateReader.updateClusterState Updat= ing cloud state from ZooKeeper...=20 [junit4:junit4] 2> 6941 T492 oass.SolrDispatchFilter.init user.dir=3D/usr= /home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/= solr-core/test/J0 [junit4:junit4] 2> 6942 T492 oass.SolrDispatchFilter.init SolrDispatchFil= ter.init() done [junit4:junit4] 2> 6943 T492 oascsi.HttpClientUtil.createClient Creating = new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&fol= lowRedirects=3Dfalse [junit4:junit4] 2> 7124 T492 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 7128 T492 oejs.AbstractConnector.doStart Started Socke= tConnector@127.0.0.1:13439 [junit4:junit4] 2> 7129 T492 oasc.SolrResourceLoader.locateSolrHome JNDI = not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 7129 T492 oasc.SolrResourceLoader.locateSolrHome using= system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cl= oud.SyncSliceTest-jetty2-1356996953915 [junit4:junit4] 2> 7130 T492 oasc.SolrResourceLoader. new SolrResou= rceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.c= loud.SyncSliceTest-jetty2-1356996953915/' [junit4:junit4] 2> 7172 T492 oass.SolrDispatchFilter.init SolrDispatchFil= ter.init() [junit4:junit4] 2> 7173 T492 oasc.SolrResourceLoader.locateSolrHome JNDI = not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 7174 T492 oasc.SolrResourceLoader.locateSolrHome using= system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cl= oud.SyncSliceTest-jetty2-1356996953915 [junit4:junit4] 2> 7174 T492 oasc.CoreContainer$Initializer.initialize lo= oking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tes= ts-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSlice= Test-jetty2-1356996953915/solr.xml [junit4:junit4] 2> 7175 T492 oasc.CoreContainer. New CoreContainer = 1028596880 [junit4:junit4] 2> 7175 T492 oasc.CoreContainer.load Loading CoreContaine= r using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tes= ts-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSlice= Test-jetty2-1356996953915/' [junit4:junit4] 2> 7176 T492 oasc.SolrResourceLoader. new SolrResou= rceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-So= lr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.Syn= cSliceTest-jetty2-1356996953915/' [junit4:junit4] 2> 7207 T492 oashc.HttpShardHandlerFactory.getParameter S= etting socketTimeout to: 30000 [junit4:junit4] 2> 7208 T492 oashc.HttpShardHandlerFactory.getParameter S= etting urlScheme to: http:// [junit4:junit4] 2> 7208 T492 oashc.HttpShardHandlerFactory.getParameter S= etting connTimeout to: 15000 [junit4:junit4] 2> 7209 T492 oashc.HttpShardHandlerFactory.getParameter S= etting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 7209 T492 oashc.HttpShardHandlerFactory.getParameter S= etting corePoolSize to: 0 [junit4:junit4] 2> 7210 T492 oashc.HttpShardHandlerFactory.getParameter S= etting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 7210 T492 oashc.HttpShardHandlerFactory.getParameter S= etting maxThreadIdleTime to: 5 [junit4:junit4] 2> 7211 T492 oashc.HttpShardHandlerFactory.getParameter S= etting sizeOfQueue to: -1 [junit4:junit4] 2> 7211 T492 oashc.HttpShardHandlerFactory.getParameter S= etting fairnessPolicy to: false [junit4:junit4] 2> 7212 T492 oascsi.HttpClientUtil.createClient Creating = new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000&s= ocketTimeout=3D30000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 7234 T492 oasc.CoreContainer.load Registering Log List= ener [junit4:junit4] 2> 7254 T492 oasc.CoreContainer.initZooKeeper Zookeeper c= lient=3D127.0.0.1:61919/solr [junit4:junit4] 2> 7254 T492 oasc.ZkController.checkChrootPath zkHost inc= ludes chroot [junit4:junit4] 2> 7255 T492 oaz.ZooKeeper. Initiating client conne= ction, connectString=3D127.0.0.1:61919 sessionTimeout=3D60000 watcher=3Dorg= .apache.solr.common.cloud.ConnectionManager@28c2d08a [junit4:junit4] 2> 7256 T492 oascc.ConnectionManager.waitForConnected Wai= ting for client to connect to ZooKeeper [junit4:junit4] 2> 7257 T545 oaz.ClientCnxn$SendThread.logStartConnect Op= ening socket connection to server localhost/127.0.0.1:61919. Will not attem= pt to authenticate using SASL (access denied ("javax.security.auth.AuthPerm= ission" "getLoginConfiguration")) [junit4:junit4] 2> 7258 T545 oaz.ClientCnxn$SendThread.primeConnection So= cket connection established to localhost/127.0.0.1:61919, initiating sessio= n [junit4:junit4] 2> 7258 T494 oazs.NIOServerCnxnFactory.run Accepted socke= t connection from /140.211.11.196:13442 [junit4:junit4] 2> 7258 T494 oazs.ZooKeeperServer.processConnectRequest C= lient attempting to establish new session at /140.211.11.196:13442 [junit4:junit4] 2> 7261 T496 oazs.ZooKeeperServer.finishSessionInit Estab= lished session 0x13bf3522c1b0007 with negotiated timeout 20000 for client /= 140.211.11.196:13442 [junit4:junit4] 2> 7261 T545 oaz.ClientCnxn$SendThread.onConnected Sessio= n establishment complete on server localhost/127.0.0.1:61919, sessionid =3D= 0x13bf3522c1b0007, negotiated timeout =3D 20000 [junit4:junit4] 2> 7261 T546 oascc.ConnectionManager.process Watcher org.= apache.solr.common.cloud.ConnectionManager@28c2d08a name:ZooKeeperConnectio= n Watcher:127.0.0.1:61919 got event WatchedEvent state:SyncConnected type:N= one path:null path:null type:None [junit4:junit4] 2> 7261 T492 oascc.ConnectionManager.waitForConnected Cli= ent is connected to ZooKeeper [junit4:junit4] 2> 7263 T497 oazs.PrepRequestProcessor.pRequest2Txn Proce= ssed session termination for sessionid: 0x13bf3522c1b0007 [junit4:junit4] 2> 7271 T546 oaz.ClientCnxn$EventThread.run EventThread s= hut down [junit4:junit4] 2> 7271 T494 oazs.NIOServerCnxn.closeSock Closed socket c= onnection for client /140.211.11.196:13442 which had sessionid 0x13bf3522c1= b0007 [junit4:junit4] 2> 7271 T492 oaz.ZooKeeper.close Session: 0x13bf3522c1b00= 07 closed [junit4:junit4] 2> 7272 T492 oascsi.HttpClientUtil.createClient Creating = new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&soc= ketTimeout=3D15000&connTimeout=3D30000 [junit4:junit4] 2> 7284 T492 oaz.ZooKeeper. Initiating client conne= ction, connectString=3D127.0.0.1:61919/solr sessionTimeout=3D30000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@5aeecf0a [junit4:junit4] 2> 7285 T492 oascc.ConnectionManager.waitForConnected Wai= ting for client to connect to ZooKeeper [junit4:junit4] 2> 7285 T547 oaz.ClientCnxn$SendThread.logStartConnect Op= ening socket connection to server localhost/127.0.0.1:61919. Will not attem= pt to authenticate using SASL (access denied ("javax.security.auth.AuthPerm= ission" "getLoginConfiguration")) [junit4:junit4] 2> 7286 T547 oaz.ClientCnxn$SendThread.primeConnection So= cket connection established to localhost/127.0.0.1:61919, initiating sessio= n [junit4:junit4] 2> 7286 T494 oazs.NIOServerCnxnFactory.run Accepted socke= t connection from /140.211.11.196:13444 [junit4:junit4] 2> 7287 T494 oazs.ZooKeeperServer.processConnectRequest C= lient attempting to establish new session at /140.211.11.196:13444 [junit4:junit4] 2> 7292 T496 oazs.ZooKeeperServer.finishSessionInit Estab= lished session 0x13bf3522c1b0008 with negotiated timeout 20000 for client /= 140.211.11.196:13444 [junit4:junit4] 2> 7292 T547 oaz.ClientCnxn$SendThread.onConnected Sessio= n establishment complete on server localhost/127.0.0.1:61919, sessionid =3D= 0x13bf3522c1b0008, negotiated timeout =3D 20000 [junit4:junit4] 2> 7293 T548 oascc.ConnectionManager.process Watcher org.= apache.solr.common.cloud.ConnectionManager@5aeecf0a name:ZooKeeperConnectio= n Watcher:127.0.0.1:61919/solr got event WatchedEvent state:SyncConnected t= ype:None path:null path:null type:None [junit4:junit4] 2> 7293 T492 oascc.ConnectionManager.waitForConnected Cli= ent is connected to ZooKeeper [junit4:junit4] 2> 7294 T497 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13bf3522c1b0008 type:crea= te cxid:0x1 zxid:0x6c txntype:-1 reqpath:n/a Error Path:/solr/overseer Erro= r:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 7296 T497 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13bf3522c1b0008 type:crea= te cxid:0x2 zxid:0x6d txntype:-1 reqpath:n/a Error Path:/solr/overseer Erro= r:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 7298 T492 oasc.ZkController.createEphemeralLiveNode Re= gister node as live in ZooKeeper:/live_nodes/127.0.0.1:13439_rnq [junit4:junit4] 2> 7299 T497 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13bf3522c1b0008 type:dele= te cxid:0x4 zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/12= 7.0.0.1:13439_rnq Error:KeeperErrorCode =3D NoNode for /solr/live_nodes/127= .0.0.1:13439_rnq [junit4:junit4] 2> 7310 T492 oascc.SolrZkClient.makePath makePath: /live_= nodes/127.0.0.1:13439_rnq [junit4:junit4] 2> 7319 T520 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/l= ive_nodes, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 7319 T533 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/l= ive_nodes, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 7319 T514 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/l= ive_nodes, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 7321 T520 oascc.ZkStateReader$3.process Updating live = nodes... (3) [junit4:junit4] 2> 7322 T514 oascc.ZkStateReader$3.process Updating live = nodes... (3) [junit4:junit4] 2> 7322 T533 oascc.ZkStateReader$3.process Updating live = nodes... (3) [junit4:junit4] 2> 7325 T492 oascc.ZkStateReader.createClusterStateWatche= rsAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 7333 T549 oasc.CoreContainer.create Creating SolrCore = 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cl= oud.SyncSliceTest-jetty2-1356996953915/collection1 [junit4:junit4] 2> 7333 T549 oasc.ZkController.createCollectionZkNode Che= ck for collection zkNode:collection1 [junit4:junit4] 2> 7334 T549 oasc.ZkController.createCollectionZkNode Col= lection zkNode exists [junit4:junit4] 2> 7334 T549 oasc.ZkController.readConfigName Load collec= tion config from:/collections/collection1 [junit4:junit4] 2> 7336 T549 oasc.SolrResourceLoader. new SolrResou= rceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-So= lr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.Syn= cSliceTest-jetty2-1356996953915/collection1/' [junit4:junit4] 2> 7337 T549 oasc.SolrResourceLoader.replaceClassLoader A= dding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-j= ava7/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty= 2-1356996953915/collection1/lib/classes/' to classloader [junit4:junit4] 2> 7338 T549 oasc.SolrResourceLoader.replaceClassLoader A= dding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-j= ava7/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty= 2-1356996953915/collection1/lib/README' to classloader [junit4:junit4] 2> 7392 T549 oasc.SolrConfig. Using Lucene MatchVer= sion: LUCENE_41 [junit4:junit4] 2> 7463 T549 oasc.SolrConfig. Loaded SolrConfig: so= lrconfig.xml [junit4:junit4] 2> 7564 T549 oass.IndexSchema.readSchema Reading Solr Sch= ema [junit4:junit4] 2> 7571 T549 oass.IndexSchema.readSchema Schema name=3Dte= st [junit4:junit4] 2> 8190 T549 oass.OpenExchangeRatesOrgProvider.init Initi= alized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 8201 T549 oass.IndexSchema.readSchema default search f= ield in schema is text [junit4:junit4] 2> 8205 T549 oass.IndexSchema.readSchema unique key field= : id [junit4:junit4] 2> 8224 T549 oass.FileExchangeRateProvider.reload Reloadi= ng exchange rates from file currency.xml [junit4:junit4] 2> 8229 T549 oass.FileExchangeRateProvider.reload Reloadi= ng exchange rates from file currency.xml [junit4:junit4] 2> 8234 T549 oass.OpenExchangeRatesOrgProvider.reload Rel= oading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 8236 T549 oass.OpenExchangeRatesOrgProvider.reload Rel= oading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 8237 T549 oasc.SolrCore. [collection1] Opening n= ew SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.= x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-= jetty2-1356996953915/collection1/, dataDir=3D./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty2/ [junit4:junit4] 2> 8237 T549 oasc.JmxMonitoredMap. JMX monitoring i= s enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBe= anServer@4ea17876 [junit4:junit4] 2> 8238 T549 oasc.SolrCore.initDirectoryFactory solr.NRTC= achingDirectoryFactory [junit4:junit4] 2> 8239 T549 oasc.CachingDirectoryFactory.get return new = directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x= -java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-1= 356996946965/jetty2 forceNew:false [junit4:junit4] 2> 8240 T549 oasc.CachingDirectoryFactory.close Releasing= directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-ja= va7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-1356= 996946965/jetty2 [junit4:junit4] 2> 8240 T549 oasc.SolrCore.getNewIndexDir New index direc= tory detected: old=3Dnull new=3D./org.apache.solr.cloud.SyncSliceTest-13569= 96946965/jetty2/index/ [junit4:junit4] 2> 8241 T549 oasc.SolrCore.initIndex WARNING [collection1= ] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1356996946965= /jetty2/index' doesn't exist. Creating new index... [junit4:junit4] 2> 8242 T549 oasc.CachingDirectoryFactory.get return new = directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x= -java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-1= 356996946965/jetty2/index forceNew:false [junit4:junit4] 2> 8274 T549 oasc.SolrDeletionPolicy.onCommit SolrDeletio= nPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/o= rg.apache.solr.cloud.SyncSliceTest-1356996946965/jetty2/index lockFactory= =3Dorg.apache.lucene.store.NativeFSLockFactory@f189a9f; maxCacheMB=3D48.0 m= axMergeSizeMB=3D4.0)),segFN=3Dsegments_1,generation=3D1,filenames=3D[segmen= ts_1] [junit4:junit4] 2> 8274 T549 oasc.SolrDeletionPolicy.updateCommits newest= commit =3D 1[segments_1] [junit4:junit4] 2> 8275 T549 oasc.CachingDirectoryFactory.close Releasing= directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-ja= va7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-1356= 996946965/jetty2/index [junit4:junit4] 2> 8276 T549 oasc.SolrCore.initWriters created xml: solr.= XMLResponseWriter [junit4:junit4] 2> 8278 T549 oasup.UpdateRequestProcessorChain.init inser= ting DistributedUpdateProcessorFactory into updateRequestProcessorChain "de= dupe" [junit4:junit4] 2> 8278 T549 oasup.UpdateRequestProcessorChain.init inser= ting DistributedUpdateProcessorFactory into updateRequestProcessorChain "de= dupe-allfields" [junit4:junit4] 2> 8279 T549 oasup.UpdateRequestProcessorChain.init inser= ting DistributedUpdateProcessorFactory into updateRequestProcessorChain "st= ored_sig" [junit4:junit4] 2> 8279 T549 oasup.UpdateRequestProcessorChain.init inser= ting DistributedUpdateProcessorFactory into updateRequestProcessorChain "un= iq-fields" [junit4:junit4] 2> 8280 T549 oasup.UpdateRequestProcessorChain.init inser= ting DistributedUpdateProcessorFactory into updateRequestProcessorChain "di= strib-dup-test-chain-implicit" [junit4:junit4] 2> 8280 T549 oasc.RequestHandlers.initHandlersFromConfig = adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 8281 T549 oasc.RequestHandlers.initHandlersFromConfig = created /replication: solr.ReplicationHandler [junit4:junit4] 2> 8281 T549 oasc.RequestHandlers.initHandlersFromConfig = created standard: solr.StandardRequestHandler [junit4:junit4] 2> 8282 T549 oasc.RequestHandlers.initHandlersFromConfig = created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 8282 T549 oasc.RequestHandlers.initHandlersFromConfig = created dismax: solr.SearchHandler [junit4:junit4] 2> 8283 T549 oasc.RequestHandlers.initHandlersFromConfig = created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler [junit4:junit4] 2> 8284 T549 oasc.RequestHandlers.initHandlersFromConfig = created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 8284 T549 oasc.RequestHandlers.initHandlersFromConfig = created defaults: solr.StandardRequestHandler [junit4:junit4] 2> 8284 T549 oasc.RequestHandlers.initHandlersFromConfig = adding lazy requestHandler: solr.StandardRequestHandler [junit4:junit4] 2> 8285 T549 oasc.RequestHandlers.initHandlersFromConfig = created lazy: solr.StandardRequestHandler [junit4:junit4] 2> 8285 T549 oasc.RequestHandlers.initHandlersFromConfig = created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 8286 T549 oasc.RequestHandlers.initHandlersFromConfig = created /terms: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 8286 T549 oasc.RequestHandlers.initHandlersFromConfig = created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 8287 T549 oasc.RequestHandlers.initHandlersFromConfig = created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHa= ndler [junit4:junit4] 2> 8288 T549 oasc.RequestHandlers.initHandlersFromConfig = created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHa= ndler [junit4:junit4] 2> 8288 T549 oasc.RequestHandlers.initHandlersFromConfig = created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.S= earchHandler [junit4:junit4] 2> 8289 T549 oasc.RequestHandlers.initHandlersFromConfig = created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 8289 T549 oasc.RequestHandlers.initHandlersFromConfig = created mltrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 8290 T549 oasc.RequestHandlers.initHandlersFromConfig = created tvrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 8290 T549 oasc.RequestHandlers.initHandlersFromConfig = created /mlt: solr.MoreLikeThisHandler [junit4:junit4] 2> 8291 T549 oasc.RequestHandlers.initHandlersFromConfig = created /debug/dump: solr.DumpRequestHandler [junit4:junit4] 2> 8304 T549 oashl.XMLLoader.init xsltCacheLifetimeSecond= s=3D60 [junit4:junit4] 2> 8308 T549 oasc.SolrCore.initDeprecatedSupport WARNING = solrconfig.xml uses deprecated , Please update your co= nfig to use the ShowFileRequestHandler. [junit4:junit4] 2> 8310 T549 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> 8313 T549 oasc.CachingDirectoryFactory.close Releasing= directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-ja= va7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-1356= 996946965/jetty2 [junit4:junit4] 2> 8314 T549 oass.SolrIndexSearcher. Opening Search= er@7f127e0 main [junit4:junit4] 2> 8315 T549 oasu.CommitTracker. Hard AutoCommit: d= isabled [junit4:junit4] 2> 8316 T549 oasu.CommitTracker. Soft AutoCommit: d= isabled [junit4:junit4] 2> 8316 T549 oashc.SpellCheckComponent.inform Initializin= g spell checkers [junit4:junit4] 2> 8323 T549 oass.DirectSolrSpellChecker.init init: {name= =3Ddirect,classname=3DDirectSolrSpellChecker,field=3Dlowerfilt,minQueryLeng= th=3D3} [junit4:junit4] 2> 8380 T550 oasc.SolrCore.registerSearcher [collection1]= Registered new searcher Searcher@7f127e0 main{StandardDirectoryReader(segm= ents_1:1)} [junit4:junit4] 2> 8386 T549 oasc.ZkController.publish publishing core=3D= collection1 state=3Ddown [junit4:junit4] 2> 8387 T549 oasc.ZkController.publish numShards not foun= d on descriptor - reading it from system property [junit4:junit4] 2> 8428 T515 oascc.ZkStateReader.updateClusterState Updat= ing cloud state from ZooKeeper...=20 [junit4:junit4] 2> 8429 T515 oasc.Overseer$ClusterStateUpdater.updateStat= e Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "shard":"shard1", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"active", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:15606_rnq", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:15606/rnq"} [junit4:junit4] 2> 8433 T515 oasc.Overseer$ClusterStateUpdater.updateStat= e Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "shard":null, [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"down", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:13439_rnq", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:13439/rnq"} [junit4:junit4] 2> 8434 T515 oasc.Overseer$ClusterStateUpdater.updateStat= e Collection already exists with numShards=3D1 [junit4:junit4] 2> 8434 T515 oasc.Overseer$ClusterStateUpdater.updateStat= e Assigning new node to shard shard=3Dshard1 [junit4:junit4] 2> 8444 T548 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clust= erstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 8444 T520 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clust= erstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 8444 T533 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clust= erstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 8444 T514 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clust= erstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 9389 T549 oasc.CoreContainer.registerCore registering = core: collection1 [junit4:junit4] 2> 9389 T549 oasc.ZkController.register Register replica = - core:collection1 address:http://127.0.0.1:13439/rnq collection:collection= 1 shard:shard1 [junit4:junit4] 2> 9393 T549 oasc.ZkController.register We are http://127= .0.0.1:13439/rnq/collection1/ and leader is http://127.0.0.1:15606/rnq/coll= ection1/ [junit4:junit4] 2> 9394 T549 oasc.ZkController.register No LogReplay need= ed for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:13439/rnq [junit4:junit4] 2> 9394 T549 oasc.ZkController.checkRecovery Core needs t= o recover:collection1 [junit4:junit4] 2> 9394 T549 oasu.DefaultSolrCoreState.doRecovery Running= recovery - first canceling any ongoing recovery [junit4:junit4] 2> ASYNC NEW_CORE C37 name=3Dcollection1 org.apache.solr= .core.SolrCore@70b9a158 url=3Dhttp://127.0.0.1:13439/rnq/collection1 node= =3D127.0.0.1:13439_rnq C37_STATE=3Dcoll:collection1 core:collection1 props:= {shard=3Dnull, roles=3Dnull, state=3Ddown, core=3Dcollection1, collection= =3Dcollection1, node_name=3D127.0.0.1:13439_rnq, base_url=3Dhttp://127.0.0.= 1:13439/rnq} [junit4:junit4] 2> 9401 T551 C37 P13439 oasc.RecoveryStrategy.run Startin= g recovery process. core=3Dcollection1 recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 9402 T549 oascc.ZkStateReader.updateClusterState Updat= ing cloud state from ZooKeeper...=20 [junit4:junit4] 2> 9402 T551 C37 P13439 oasc.RecoveryStrategy.doRecovery = ###### startupVersions=3D[] [junit4:junit4] 2> 9403 T551 C37 P13439 oasc.ZkController.publish publish= ing core=3Dcollection1 state=3Drecovering [junit4:junit4] 2> 9403 T551 C37 P13439 oasc.ZkController.publish numShar= ds not found on descriptor - reading it from system property [junit4:junit4] 2> 9403 T492 oass.SolrDispatchFilter.init user.dir=3D/usr= /home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/= solr-core/test/J0 [junit4:junit4] 2> 9404 T492 oass.SolrDispatchFilter.init SolrDispatchFil= ter.init() done [junit4:junit4] 2> 9405 T492 oascsi.HttpClientUtil.createClient Creating = new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&fol= lowRedirects=3Dfalse [junit4:junit4] 2> 9405 T551 C37 P13439 oascsi.HttpClientUtil.createClien= t Creating new http client, config:maxConnections=3D128&maxConnectionsPerHo= st=3D32&followRedirects=3Dfalse [junit4:junit4] 2> 9593 T492 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 9596 T492 oejs.AbstractConnector.doStart Started Socke= tConnector@127.0.0.1:13446 [junit4:junit4] 2> 9597 T492 oasc.SolrResourceLoader.locateSolrHome JNDI = not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 9598 T492 oasc.SolrResourceLoader.locateSolrHome using= system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cl= oud.SyncSliceTest-jetty3-1356996956380 [junit4:junit4] 2> 9598 T492 oasc.SolrResourceLoader. new SolrResou= rceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.c= loud.SyncSliceTest-jetty3-1356996956380/' [junit4:junit4] 2> 9641 T492 oass.SolrDispatchFilter.init SolrDispatchFil= ter.init() [junit4:junit4] 2> 9641 T492 oasc.SolrResourceLoader.locateSolrHome JNDI = not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 9642 T492 oasc.SolrResourceLoader.locateSolrHome using= system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cl= oud.SyncSliceTest-jetty3-1356996956380 [junit4:junit4] 2> 9642 T492 oasc.CoreContainer$Initializer.initialize lo= oking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tes= ts-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSlice= Test-jetty3-1356996956380/solr.xml [junit4:junit4] 2> 9643 T492 oasc.CoreContainer. New CoreContainer = 1246516315 [junit4:junit4] 2> 9644 T492 oasc.CoreContainer.load Loading CoreContaine= r using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tes= ts-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSlice= Test-jetty3-1356996956380/' [junit4:junit4] 2> 9644 T492 oasc.SolrResourceLoader. new SolrResou= rceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-So= lr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.Syn= cSliceTest-jetty3-1356996956380/' [junit4:junit4] 2> 9674 T492 oashc.HttpShardHandlerFactory.getParameter S= etting socketTimeout to: 30000 [junit4:junit4] 2> 9675 T492 oashc.HttpShardHandlerFactory.getParameter S= etting urlScheme to: http:// [junit4:junit4] 2> 9675 T492 oashc.HttpShardHandlerFactory.getParameter S= etting connTimeout to: 15000 [junit4:junit4] 2> 9676 T492 oashc.HttpShardHandlerFactory.getParameter S= etting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 9676 T492 oashc.HttpShardHandlerFactory.getParameter S= etting corePoolSize to: 0 [junit4:junit4] 2> 9677 T492 oashc.HttpShardHandlerFactory.getParameter S= etting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 9677 T492 oashc.HttpShardHandlerFactory.getParameter S= etting maxThreadIdleTime to: 5 [junit4:junit4] 2> 9678 T492 oashc.HttpShardHandlerFactory.getParameter S= etting sizeOfQueue to: -1 [junit4:junit4] 2> 9678 T492 oashc.HttpShardHandlerFactory.getParameter S= etting fairnessPolicy to: false [junit4:junit4] 2> 9679 T492 oascsi.HttpClientUtil.createClient Creating = new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000&s= ocketTimeout=3D30000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 9700 T492 oasc.CoreContainer.load Registering Log List= ener [junit4:junit4] 2> 9721 T492 oasc.CoreContainer.initZooKeeper Zookeeper c= lient=3D127.0.0.1:61919/solr [junit4:junit4] 2> 9722 T492 oasc.ZkController.checkChrootPath zkHost inc= ludes chroot [junit4:junit4] 2> 9722 T492 oaz.ZooKeeper. Initiating client conne= ction, connectString=3D127.0.0.1:61919 sessionTimeout=3D60000 watcher=3Dorg= .apache.solr.common.cloud.ConnectionManager@bd11830 [junit4:junit4] 2> 9723 T492 oascc.ConnectionManager.waitForConnected Wai= ting for client to connect to ZooKeeper [junit4:junit4] 2> 9724 T561 oaz.ClientCnxn$SendThread.logStartConnect Op= ening socket connection to server localhost/127.0.0.1:61919. Will not attem= pt to authenticate using SASL (access denied ("javax.security.auth.AuthPerm= ission" "getLoginConfiguration")) [junit4:junit4] 2> 9724 T561 oaz.ClientCnxn$SendThread.primeConnection So= cket connection established to localhost/127.0.0.1:61919, initiating sessio= n [junit4:junit4] 2> 9725 T494 oazs.NIOServerCnxnFactory.run Accepted socke= t connection from /140.211.11.196:13447 [junit4:junit4] 2> 9725 T494 oazs.ZooKeeperServer.processConnectRequest C= lient attempting to establish new session at /140.211.11.196:13447 [junit4:junit4] 2> 9727 T496 oazs.ZooKeeperServer.finishSessionInit Estab= lished session 0x13bf3522c1b0009 with negotiated timeout 20000 for client /= 140.211.11.196:13447 [junit4:junit4] 2> 9727 T561 oaz.ClientCnxn$SendThread.onConnected Sessio= n establishment complete on server localhost/127.0.0.1:61919, sessionid =3D= 0x13bf3522c1b0009, negotiated timeout =3D 20000 [junit4:junit4] 2> 9728 T562 oascc.ConnectionManager.process Watcher org.= apache.solr.common.cloud.ConnectionManager@bd11830 name:ZooKeeperConnection= Watcher:127.0.0.1:61919 got event WatchedEvent state:SyncConnected type:No= ne path:null path:null type:None [junit4:junit4] 2> 9728 T492 oascc.ConnectionManager.waitForConnected Cli= ent is connected to ZooKeeper [junit4:junit4] 2> 9730 T497 oazs.PrepRequestProcessor.pRequest2Txn Proce= ssed session termination for sessionid: 0x13bf3522c1b0009 [junit4:junit4] 2> 9741 T562 oaz.ClientCnxn$EventThread.run EventThread s= hut down [junit4:junit4] 2> 9741 T494 oazs.NIOServerCnxn.closeSock Closed socket c= onnection for client /140.211.11.196:13447 which had sessionid 0x13bf3522c1= b0009 [junit4:junit4] 2> 9741 T492 oaz.ZooKeeper.close Session: 0x13bf3522c1b00= 09 closed [junit4:junit4] 2> 9742 T492 oascsi.HttpClientUtil.createClient Creating = new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&soc= ketTimeout=3D15000&connTimeout=3D30000 [junit4:junit4] 2> 9753 T492 oaz.ZooKeeper. Initiating client conne= ction, connectString=3D127.0.0.1:61919/solr sessionTimeout=3D30000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@42f0ffda [junit4:junit4] 2> 9754 T492 oascc.ConnectionManager.waitForConnected Wai= ting for client to connect to ZooKeeper [junit4:junit4] 2> 9754 T563 oaz.ClientCnxn$SendThread.logStartConnect Op= ening socket connection to server localhost/127.0.0.1:61919. Will not attem= pt to authenticate using SASL (access denied ("javax.security.auth.AuthPerm= ission" "getLoginConfiguration")) [junit4:junit4] 2> 9755 T563 oaz.ClientCnxn$SendThread.primeConnection So= cket connection established to localhost/127.0.0.1:61919, initiating sessio= n [junit4:junit4] 2> 9755 T494 oazs.NIOServerCnxnFactory.run Accepted socke= t connection from /140.211.11.196:13448 [junit4:junit4] 2> 9756 T494 oazs.ZooKeeperServer.processConnectRequest C= lient attempting to establish new session at /140.211.11.196:13448 [junit4:junit4] 2> 9757 T496 oazs.ZooKeeperServer.finishSessionInit Estab= lished session 0x13bf3522c1b000a with negotiated timeout 20000 for client /= 140.211.11.196:13448 [junit4:junit4] 2> 9757 T563 oaz.ClientCnxn$SendThread.onConnected Sessio= n establishment complete on server localhost/127.0.0.1:61919, sessionid =3D= 0x13bf3522c1b000a, negotiated timeout =3D 20000 [junit4:junit4] 2> 9758 T564 oascc.ConnectionManager.process Watcher org.= apache.solr.common.cloud.ConnectionManager@42f0ffda name:ZooKeeperConnectio= n Watcher:127.0.0.1:61919/solr got event WatchedEvent state:SyncConnected t= ype:None path:null path:null type:None [junit4:junit4] 2> 9758 T492 oascc.ConnectionManager.waitForConnected Cli= ent is connected to ZooKeeper [junit4:junit4] 2> 9759 T497 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13bf3522c1b000a type:crea= te cxid:0x1 zxid:0x7e txntype:-1 reqpath:n/a Error Path:/solr/overseer Erro= r:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 9761 T497 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13bf3522c1b000a type:crea= te cxid:0x2 zxid:0x7f txntype:-1 reqpath:n/a Error Path:/solr/overseer Erro= r:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 9768 T492 oasc.ZkController.createEphemeralLiveNode Re= gister node as live in ZooKeeper:/live_nodes/127.0.0.1:13446_rnq [junit4:junit4] 2> 9769 T497 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13bf3522c1b000a type:dele= te cxid:0x4 zxid:0x80 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/12= 7.0.0.1:13446_rnq Error:KeeperErrorCode =3D NoNode for /solr/live_nodes/127= .0.0.1:13446_rnq [junit4:junit4] 2> 9770 T492 oascc.SolrZkClient.makePath makePath: /live_= nodes/127.0.0.1:13446_rnq [junit4:junit4] 2> 9773 T514 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/l= ive_nodes, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 9773 T533 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/l= ive_nodes, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 9773 T520 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/l= ive_nodes, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 9774 T548 oascc.ZkStateReader$3.process Updating live = nodes... (4) [junit4:junit4] 2> 9774 T548 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/l= ive_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 9777 T514 oascc.ZkStateReader$3.process Updating live = nodes... (4) [junit4:junit4] 2> 9777 T533 oascc.ZkStateReader$3.process Updating live = nodes... (4) [junit4:junit4] 2> 9777 T520 oascc.ZkStateReader$3.process Updating live = nodes... (4) [junit4:junit4] 2> 9778 T492 oascc.ZkStateReader.createClusterStateWatche= rsAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 9786 T565 oasc.CoreContainer.create Creating SolrCore = 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cl= oud.SyncSliceTest-jetty3-1356996956380/collection1 [junit4:junit4] 2> 9787 T565 oasc.ZkController.createCollectionZkNode Che= ck for collection zkNode:collection1 [junit4:junit4] 2> 9787 T565 oasc.ZkController.createCollectionZkNode Col= lection zkNode exists [junit4:junit4] 2> 9788 T565 oasc.ZkController.readConfigName Load collec= tion config from:/collections/collection1 [junit4:junit4] 2> 9789 T565 oasc.SolrResourceLoader. new SolrResou= rceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-So= lr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.Syn= cSliceTest-jetty3-1356996956380/collection1/' [junit4:junit4] 2> 9790 T565 oasc.SolrResourceLoader.replaceClassLoader A= dding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-j= ava7/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty= 3-1356996956380/collection1/lib/README' to classloader [junit4:junit4] 2> 9791 T565 oasc.SolrResourceLoader.replaceClassLoader A= dding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-j= ava7/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty= 3-1356996956380/collection1/lib/classes/' to classloader [junit4:junit4] 2> 9846 T565 oasc.SolrConfig. Using Lucene MatchVer= sion: LUCENE_41 [junit4:junit4] 2> 9920 T565 oasc.SolrConfig. Loaded SolrConfig: so= lrconfig.xml [junit4:junit4] 2> 9956 T515 oascc.ZkStateReader.updateClusterState Updat= ing cloud state from ZooKeeper...=20 [junit4:junit4] 2> 9957 T515 oasc.Overseer$ClusterStateUpdater.updateStat= e Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "shard":"shard1", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"recovering", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:13439_rnq", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:13439/rnq"} [junit4:junit4] 2> 9970 T548 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clust= erstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 9970 T533 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clust= erstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 9970 T514 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clust= erstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 9970 T520 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clust= erstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 10021 T565 oass.IndexSchema.readSchema Reading Solr Sc= hema [junit4:junit4] 2> 10021 T564 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 10029 T565 oass.IndexSchema.readSchema Schema name=3Dt= est [junit4:junit4] 2> 10690 T565 oass.OpenExchangeRatesOrgProvider.init Init= ialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 10701 T565 oass.IndexSchema.readSchema default search = field in schema is text [junit4:junit4] 2> 10705 T565 oass.IndexSchema.readSchema unique key fiel= d: id [junit4:junit4] 2> 10723 T565 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 10728 T565 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 10733 T565 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 10734 T565 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 10736 T565 oasc.SolrCore. [collection1] Opening = new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4= .x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest= -jetty3-1356996956380/collection1/, dataDir=3D./org.apache.solr.cloud.SyncS= liceTest-1356996946965/jetty3/ [junit4:junit4] 2> 10736 T565 oasc.JmxMonitoredMap. JMX monitoring = is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMB= eanServer@4ea17876 [junit4:junit4] 2> 10737 T565 oasc.SolrCore.initDirectoryFactory solr.NRT= CachingDirectoryFactory [junit4:junit4] 2> 10738 T565 oasc.CachingDirectoryFactory.get return new= directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.= x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-= 1356996946965/jetty3 forceNew:false [junit4:junit4] 2> 10738 T565 oasc.CachingDirectoryFactory.close Releasin= g directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-j= ava7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-135= 6996946965/jetty3 [junit4:junit4] 2> 10739 T565 oasc.SolrCore.getNewIndexDir New index dire= ctory detected: old=3Dnull new=3D./org.apache.solr.cloud.SyncSliceTest-1356= 996946965/jetty3/index/ [junit4:junit4] 2> 10739 T565 oasc.SolrCore.initIndex WARNING [collection= 1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-135699694696= 5/jetty3/index' doesn't exist. Creating new index... [junit4:junit4] 2> 10741 T565 oasc.CachingDirectoryFactory.get return new= directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.= x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-= 1356996946965/jetty3/index forceNew:false [junit4:junit4] 2> 10747 T565 oasc.SolrDeletionPolicy.onCommit SolrDeleti= onPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/o= rg.apache.solr.cloud.SyncSliceTest-1356996946965/jetty3/index lockFactory= =3Dorg.apache.lucene.store.NativeFSLockFactory@77fdab5f; maxCacheMB=3D48.0 = maxMergeSizeMB=3D4.0)),segFN=3Dsegments_1,generation=3D1,filenames=3D[segme= nts_1] [junit4:junit4] 2> 10747 T565 oasc.SolrDeletionPolicy.updateCommits newes= t commit =3D 1[segments_1] [junit4:junit4] 2> 10748 T565 oasc.CachingDirectoryFactory.close Releasin= g directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-j= ava7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-135= 6996946965/jetty3/index [junit4:junit4] 2> 10749 T565 oasc.SolrCore.initWriters created xml: solr= .XMLResponseWriter [junit4:junit4] 2> 10751 T565 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe" [junit4:junit4] 2> 10752 T565 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe-allfields" [junit4:junit4] 2> 10752 T565 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "s= tored_sig" [junit4:junit4] 2> 10752 T565 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "u= niq-fields" [junit4:junit4] 2> 10753 T565 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= istrib-dup-test-chain-implicit" [junit4:junit4] 2> 10753 T565 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 10754 T565 oasc.RequestHandlers.initHandlersFromConfig= created /replication: solr.ReplicationHandler [junit4:junit4] 2> 10754 T565 oasc.RequestHandlers.initHandlersFromConfig= created standard: solr.StandardRequestHandler [junit4:junit4] 2> 10755 T565 oasc.RequestHandlers.initHandlersFromConfig= created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 10756 T565 oasc.RequestHandlers.initHandlersFromConfig= created dismax: solr.SearchHandler [junit4:junit4] 2> 10756 T565 oasc.RequestHandlers.initHandlersFromConfig= created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler [junit4:junit4] 2> 10757 T565 oasc.RequestHandlers.initHandlersFromConfig= created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 10757 T565 oasc.RequestHandlers.initHandlersFromConfig= created defaults: solr.StandardRequestHandler [junit4:junit4] 2> 10758 T565 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.StandardRequestHandler [junit4:junit4] 2> 10758 T565 oasc.RequestHandlers.initHandlersFromConfig= created lazy: solr.StandardRequestHandler [junit4:junit4] 2> 10759 T565 oasc.RequestHandlers.initHandlersFromConfig= created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 10759 T565 oasc.RequestHandlers.initHandlersFromConfig= created /terms: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 10760 T565 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 10760 T565 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchH= andler [junit4:junit4] 2> 10761 T565 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchH= andler [junit4:junit4] 2> 10761 T565 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.= SearchHandler [junit4:junit4] 2> 10762 T565 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 10763 T565 oasc.RequestHandlers.initHandlersFromConfig= created mltrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 10763 T565 oasc.RequestHandlers.initHandlersFromConfig= created tvrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 10764 T565 oasc.RequestHandlers.initHandlersFromConfig= created /mlt: solr.MoreLikeThisHandler [junit4:junit4] 2> 10764 T565 oasc.RequestHandlers.initHandlersFromConfig= created /debug/dump: solr.DumpRequestHandler [junit4:junit4] 2> 10777 T565 oashl.XMLLoader.init xsltCacheLifetimeSecon= ds=3D60 [junit4:junit4] 2> 10782 T565 oasc.SolrCore.initDeprecatedSupport WARNING= solrconfig.xml uses deprecated , Please update your c= onfig to use the ShowFileRequestHandler. [junit4:junit4] 2> 10783 T565 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> 10786 T565 oasc.CachingDirectoryFactory.close Releasin= g directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-j= ava7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-135= 6996946965/jetty3 [junit4:junit4] 2> 10788 T565 oass.SolrIndexSearcher. Opening Searc= her@7a85722a main [junit4:junit4] 2> 10789 T565 oasu.CommitTracker. Hard AutoCommit: = disabled [junit4:junit4] 2> 10789 T565 oasu.CommitTracker. Soft AutoCommit: = disabled [junit4:junit4] 2> 10790 T565 oashc.SpellCheckComponent.inform Initializi= ng spell checkers [junit4:junit4] 2> 10797 T565 oass.DirectSolrSpellChecker.init init: {nam= e=3Ddirect,classname=3DDirectSolrSpellChecker,field=3Dlowerfilt,minQueryLen= gth=3D3} [junit4:junit4] 2> 10852 T566 oasc.SolrCore.registerSearcher [collection1= ] Registered new searcher Searcher@7a85722a main{StandardDirectoryReader(se= gments_1:1)} [junit4:junit4] 2> 10857 T565 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Ddown [junit4:junit4] 2> 10857 T565 oasc.ZkController.publish numShards not fou= nd on descriptor - reading it from system property [junit4:junit4] 2> 11476 T515 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 11477 T515 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "shard":null, [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"down", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:13446_rnq", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:13446/rnq"} [junit4:junit4] 2> 11477 T515 oasc.Overseer$ClusterStateUpdater.updateSta= te Collection already exists with numShards=3D1 [junit4:junit4] 2> 11477 T515 oasc.Overseer$ClusterStateUpdater.updateSta= te Assigning new node to shard shard=3Dshard1 [junit4:junit4] 2> 11518 T520 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 11518 T533 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 11518 T564 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 11518 T514 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 11518 T548 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 11860 T565 oasc.CoreContainer.registerCore registering= core: collection1 [junit4:junit4] 2> 11860 T565 oasc.ZkController.register Register replica= - core:collection1 address:http://127.0.0.1:13446/rnq collection:collectio= n1 shard:shard1 [junit4:junit4] 2> 11864 T565 oasc.ZkController.register We are http://12= 7.0.0.1:13446/rnq/collection1/ and leader is http://127.0.0.1:15606/rnq/col= lection1/ [junit4:junit4] 2> 11865 T565 oasc.ZkController.register No LogReplay nee= ded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:13446/rnq [junit4:junit4] 2> 11865 T565 oasc.ZkController.checkRecovery Core needs = to recover:collection1 [junit4:junit4] 2> 11865 T565 oasu.DefaultSolrCoreState.doRecovery Runnin= g recovery - first canceling any ongoing recovery [junit4:junit4] 2> ASYNC NEW_CORE C38 name=3Dcollection1 org.apache.solr= .core.SolrCore@51f02c34 url=3Dhttp://127.0.0.1:13446/rnq/collection1 node= =3D127.0.0.1:13446_rnq C38_STATE=3Dcoll:collection1 core:collection1 props:= {shard=3Dnull, roles=3Dnull, state=3Ddown, core=3Dcollection1, collection= =3Dcollection1, node_name=3D127.0.0.1:13446_rnq, base_url=3Dhttp://127.0.0.= 1:13446/rnq} [junit4:junit4] 2> 11866 T567 C38 P13446 oasc.RecoveryStrategy.run Starti= ng recovery process. core=3Dcollection1 recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 11867 T567 C38 P13446 oasc.RecoveryStrategy.doRecovery= ###### startupVersions=3D[] [junit4:junit4] 2> 11867 T565 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 11867 T567 C38 P13446 oasc.ZkController.publish publis= hing core=3Dcollection1 state=3Drecovering [junit4:junit4] 2> 11867 T567 C38 P13446 oasc.ZkController.publish numSha= rds not found on descriptor - reading it from system property [junit4:junit4] 2> 11868 T492 oass.SolrDispatchFilter.init user.dir=3D/us= r/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build= /solr-core/test/J0 [junit4:junit4] 2> 11869 T492 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() done [junit4:junit4] 2> 11869 T567 C38 P13446 oascsi.HttpClientUtil.createClie= nt Creating new http client, config:maxConnections=3D128&maxConnectionsPerH= ost=3D32&followRedirects=3Dfalse [junit4:junit4] 2> 11869 T492 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&fo= llowRedirects=3Dfalse [junit4:junit4] 2> 12063 T492 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 12066 T492 oejs.AbstractConnector.doStart Started Sock= etConnector@127.0.0.1:13455 [junit4:junit4] 2> 12067 T492 oasc.SolrResourceLoader.locateSolrHome JNDI= not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 12067 T492 oasc.SolrResourceLoader.locateSolrHome usin= g system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.c= loud.SyncSliceTest-jetty4-1356996958853 [junit4:junit4] 2> 12068 T492 oasc.SolrResourceLoader. new SolrReso= urceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/= Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.= cloud.SyncSliceTest-jetty4-1356996958853/' [junit4:junit4] 2> 12110 T492 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() [junit4:junit4] 2> 12111 T492 oasc.SolrResourceLoader.locateSolrHome JNDI= not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 12111 T492 oasc.SolrResourceLoader.locateSolrHome usin= g system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.c= loud.SyncSliceTest-jetty4-1356996958853 [junit4:junit4] 2> 12112 T492 oasc.CoreContainer$Initializer.initialize l= ooking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSlic= eTest-jetty4-1356996958853/solr.xml [junit4:junit4] 2> 12112 T492 oasc.CoreContainer. New CoreContainer= 538240734 [junit4:junit4] 2> 12113 T492 oasc.CoreContainer.load Loading CoreContain= er using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSlic= eTest-jetty4-1356996958853/' [junit4:junit4] 2> 12114 T492 oasc.SolrResourceLoader. new SolrReso= urceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-S= olr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.Sy= ncSliceTest-jetty4-1356996958853/' [junit4:junit4] 2> 12143 T492 oashc.HttpShardHandlerFactory.getParameter = Setting socketTimeout to: 30000 [junit4:junit4] 2> 12144 T492 oashc.HttpShardHandlerFactory.getParameter = Setting urlScheme to: http:// [junit4:junit4] 2> 12144 T492 oashc.HttpShardHandlerFactory.getParameter = Setting connTimeout to: 15000 [junit4:junit4] 2> 12145 T492 oashc.HttpShardHandlerFactory.getParameter = Setting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 12145 T492 oashc.HttpShardHandlerFactory.getParameter = Setting corePoolSize to: 0 [junit4:junit4] 2> 12146 T492 oashc.HttpShardHandlerFactory.getParameter = Setting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 12146 T492 oashc.HttpShardHandlerFactory.getParameter = Setting maxThreadIdleTime to: 5 [junit4:junit4] 2> 12147 T492 oashc.HttpShardHandlerFactory.getParameter = Setting sizeOfQueue to: -1 [junit4:junit4] 2> 12147 T492 oashc.HttpShardHandlerFactory.getParameter = Setting fairnessPolicy to: false [junit4:junit4] 2> 12148 T492 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000&= socketTimeout=3D30000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 12171 T492 oasc.CoreContainer.load Registering Log Lis= tener [junit4:junit4] 2> 12191 T492 oasc.CoreContainer.initZooKeeper Zookeeper = client=3D127.0.0.1:61919/solr [junit4:junit4] 2> 12192 T492 oasc.ZkController.checkChrootPath zkHost in= cludes chroot [junit4:junit4] 2> 12192 T492 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:61919 sessionTimeout=3D60000 watcher=3Dor= g.apache.solr.common.cloud.ConnectionManager@32c8ec33 [junit4:junit4] 2> 12194 T492 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 12194 T577 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost/127.0.0.1:61919. Will not atte= mpt to authenticate using SASL (access denied ("javax.security.auth.AuthPer= mission" "getLoginConfiguration")) [junit4:junit4] 2> 12195 T577 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost/127.0.0.1:61919, initiating sessi= on [junit4:junit4] 2> 12195 T494 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /140.211.11.196:13456 [junit4:junit4] 2> 12196 T494 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /140.211.11.196:13456 [junit4:junit4] 2> 12198 T496 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13bf3522c1b000b with negotiated timeout 20000 for client = /140.211.11.196:13456 [junit4:junit4] 2> 12198 T577 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost/127.0.0.1:61919, sessionid = =3D 0x13bf3522c1b000b, negotiated timeout =3D 20000 [junit4:junit4] 2> 12198 T578 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@32c8ec33 name:ZooKeeperConnecti= on Watcher:127.0.0.1:61919 got event WatchedEvent state:SyncConnected type:= None path:null path:null type:None [junit4:junit4] 2> 12198 T492 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 12200 T497 oazs.PrepRequestProcessor.pRequest2Txn Proc= essed session termination for sessionid: 0x13bf3522c1b000b [junit4:junit4] 2> 12212 T578 oaz.ClientCnxn$EventThread.run EventThread = shut down [junit4:junit4] 2> 12212 T494 oazs.NIOServerCnxn.closeSock Closed socket = connection for client /140.211.11.196:13456 which had sessionid 0x13bf3522c= 1b000b [junit4:junit4] 2> 12212 T492 oaz.ZooKeeper.close Session: 0x13bf3522c1b0= 00b closed [junit4:junit4] 2> 12213 T492 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&so= cketTimeout=3D15000&connTimeout=3D30000 [junit4:junit4] 2> 12226 T492 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:61919/solr sessionTimeout=3D30000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@2ab59e2c [junit4:junit4] 2> 12227 T492 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 12228 T579 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost/127.0.0.1:61919. Will not atte= mpt to authenticate using SASL (access denied ("javax.security.auth.AuthPer= mission" "getLoginConfiguration")) [junit4:junit4] 2> 12228 T579 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost/127.0.0.1:61919, initiating sessi= on [junit4:junit4] 2> 12228 T494 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /140.211.11.196:13457 [junit4:junit4] 2> 12229 T494 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /140.211.11.196:13457 [junit4:junit4] 2> 12231 T496 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13bf3522c1b000c with negotiated timeout 20000 for client = /140.211.11.196:13457 [junit4:junit4] 2> 12231 T579 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost/127.0.0.1:61919, sessionid = =3D 0x13bf3522c1b000c, negotiated timeout =3D 20000 [junit4:junit4] 2> 12231 T580 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@2ab59e2c name:ZooKeeperConnecti= on Watcher:127.0.0.1:61919/solr got event WatchedEvent state:SyncConnected = type:None path:null path:null type:None [junit4:junit4] 2> 12231 T492 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 12232 T497 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13bf3522c1b000c type:cre= ate cxid:0x1 zxid:0x91 txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 12234 T497 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13bf3522c1b000c type:cre= ate cxid:0x2 zxid:0x92 txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 12236 T492 oasc.ZkController.createEphemeralLiveNode R= egister node as live in ZooKeeper:/live_nodes/127.0.0.1:13455_rnq [junit4:junit4] 2> 12237 T497 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13bf3522c1b000c type:del= ete cxid:0x4 zxid:0x93 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/1= 27.0.0.1:13455_rnq Error:KeeperErrorCode =3D NoNode for /solr/live_nodes/12= 7.0.0.1:13455_rnq [junit4:junit4] 2> 12244 T492 oascc.SolrZkClient.makePath makePath: /live= _nodes/127.0.0.1:13455_rnq [junit4:junit4] 2> 12247 T520 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/= live_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 12247 T514 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/= live_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 12247 T533 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/= live_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 12248 T564 oascc.ZkStateReader$3.process Updating live= nodes... (5) [junit4:junit4] 2> 12248 T548 oascc.ZkStateReader$3.process Updating live= nodes... (5) [junit4:junit4] 2> 12248 T564 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/= live_nodes, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 12248 T548 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/= live_nodes, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 12250 T520 oascc.ZkStateReader$3.process Updating live= nodes... (5) [junit4:junit4] 2> 12250 T514 oascc.ZkStateReader$3.process Updating live= nodes... (5) [junit4:junit4] 2> 12252 T533 oascc.ZkStateReader$3.process Updating live= nodes... (5) [junit4:junit4] 2> 12253 T492 oascc.ZkStateReader.createClusterStateWatch= ersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 12261 T581 oasc.CoreContainer.create Creating SolrCore= 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.c= loud.SyncSliceTest-jetty4-1356996958853/collection1 [junit4:junit4] 2> 12261 T581 oasc.ZkController.createCollectionZkNode Ch= eck for collection zkNode:collection1 [junit4:junit4] 2> 12262 T581 oasc.ZkController.createCollectionZkNode Co= llection zkNode exists [junit4:junit4] 2> 12262 T581 oasc.ZkController.readConfigName Load colle= ction config from:/collections/collection1 [junit4:junit4] 2> 12264 T581 oasc.SolrResourceLoader. new SolrReso= urceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-S= olr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.Sy= ncSliceTest-jetty4-1356996958853/collection1/' [junit4:junit4] 2> 12265 T581 oasc.SolrResourceLoader.replaceClassLoader = Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-= java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jett= y4-1356996958853/collection1/lib/classes/' to classloader [junit4:junit4] 2> 12266 T581 oasc.SolrResourceLoader.replaceClassLoader = Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-= java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jett= y4-1356996958853/collection1/lib/README' to classloader [junit4:junit4] 2> 12320 T581 oasc.SolrConfig. Using Lucene MatchVe= rsion: LUCENE_41 [junit4:junit4] 2> 12403 T581 oasc.SolrConfig. Loaded SolrConfig: s= olrconfig.xml [junit4:junit4] 2> C37_STATE=3Dcoll:collection1 core:collection1 props:{= shard=3Dshard1, roles=3Dnull, state=3Drecovering, core=3Dcollection1, colle= ction=3Dcollection1, node_name=3D127.0.0.1:13439_rnq, base_url=3Dhttp://127= .0.0.1:13439/rnq} [junit4:junit4] 2> 12434 T551 C37 P13439 oasc.RecoveryStrategy.doRecovery= Attempting to PeerSync from http://127.0.0.1:15606/rnq/collection1/ core= =3Dcollection1 - recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 12444 T551 C37 P13439 oascsi.HttpClientUtil.createClie= nt Creating new http client, config:maxConnectionsPerHost=3D20&maxConnectio= ns=3D10000&connTimeout=3D30000&socketTimeout=3D30000&retry=3Dfalse [junit4:junit4] 2> 12462 T551 C37 P13439 oasu.PeerSync.sync PeerSync: cor= e=3Dcollection1 url=3Dhttp://127.0.0.1:13439/rnq START replicas=3D[http://1= 27.0.0.1:15606/rnq/collection1/] nUpdates=3D100 [junit4:junit4] 2> 12462 T551 C37 P13439 oasu.PeerSync.sync WARNING no fr= ame of reference to tell of we've missed updates [junit4:junit4] 2> 12463 T551 C37 P13439 oasc.RecoveryStrategy.doRecovery= PeerSync Recovery was not successful - trying replication. core=3Dcollecti= on1 [junit4:junit4] 2> 12464 T551 C37 P13439 oasc.RecoveryStrategy.doRecovery= Starting Replication Recovery. core=3Dcollection1 [junit4:junit4] 2> 12464 T551 C37 P13439 oasc.RecoveryStrategy.doRecovery= Begin buffering updates. core=3Dcollection1 [junit4:junit4] 2> 12464 T551 C37 P13439 oasu.UpdateLog.bufferUpdates Sta= rting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog=3Dnull} [junit4:junit4] 2> 12464 T551 C37 P13439 oasc.RecoveryStrategy.replicate = Attempting to replicate from http://127.0.0.1:15606/rnq/collection1/. core= =3Dcollection1 [junit4:junit4] 2> 12465 T551 C37 P13439 oascsi.HttpClientUtil.createClie= nt Creating new http client, config:maxConnections=3D128&maxConnectionsPerH= ost=3D32&followRedirects=3Dfalse [junit4:junit4] 2> ASYNC NEW_CORE C39 name=3Dcollection1 org.apache.solr= .core.SolrCore@3f5efda5 url=3Dhttp://127.0.0.1:15606/rnq/collection1 node= =3D127.0.0.1:15606_rnq C39_STATE=3Dcoll:collection1 core:collection1 props:= {shard=3Dshard1, roles=3Dnull, state=3Dactive, core=3Dcollection1, collecti= on=3Dcollection1, node_name=3D127.0.0.1:15606_rnq, base_url=3Dhttp://127.0.= 0.1:15606/rnq, leader=3Dtrue} [junit4:junit4] 2> 12470 T525 C39 P15606 REQ /get {distrib=3Dfalse&qt=3D/= get&wt=3Djavabin&version=3D2&getVersions=3D100} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 12477 T526 C39 P15606 oasu.DirectUpdateHandler2.commit= start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dfalse= ,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 12479 T526 C39 P15606 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty1 [junit4:junit4] 2> 12483 T526 C39 P15606 oasc.SolrDeletionPolicy.onInit S= olrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/o= rg.apache.solr.cloud.SyncSliceTest-1356996946965/jetty1/index lockFactory= =3Dorg.apache.lucene.store.NativeFSLockFactory@34c8ae05; maxCacheMB=3D48.0 = maxMergeSizeMB=3D4.0)),segFN=3Dsegments_1,generation=3D1,filenames=3D[segme= nts_1] [junit4:junit4] 2> 12484 T526 C39 P15606 oasc.SolrDeletionPolicy.updateCo= mmits newest commit =3D 1[segments_1] [junit4:junit4] 2> 12488 T526 C39 P15606 oasc.SolrDeletionPolicy.onCommit= SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/o= rg.apache.solr.cloud.SyncSliceTest-1356996946965/jetty1/index lockFactory= =3Dorg.apache.lucene.store.NativeFSLockFactory@34c8ae05; maxCacheMB=3D48.0 = maxMergeSizeMB=3D4.0)),segFN=3Dsegments_1,generation=3D1,filenames=3D[segme= nts_1] [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/o= rg.apache.solr.cloud.SyncSliceTest-1356996946965/jetty1/index lockFactory= =3Dorg.apache.lucene.store.NativeFSLockFactory@34c8ae05; maxCacheMB=3D48.0 = maxMergeSizeMB=3D4.0)),segFN=3Dsegments_2,generation=3D2,filenames=3D[segme= nts_2] [junit4:junit4] 2> 12489 T526 C39 P15606 oasc.SolrDeletionPolicy.updateCo= mmits newest commit =3D 2[segments_2] [junit4:junit4] 2> 12490 T526 C39 P15606 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty1 [junit4:junit4] 2> 12490 T526 C39 P15606 oass.SolrIndexSearcher. Op= ening Searcher@7f8b3bc8 realtime [junit4:junit4] 2> 12491 T526 C39 P15606 oasu.DirectUpdateHandler2.commit= end_commit_flush [junit4:junit4] 2> 12491 T526 C39 P15606 /update {waitSearcher=3Dtrue&ope= nSearcher=3Dfalse&commit=3Dtrue&commit_end_point=3Dtrue&wt=3Djavabin&softCo= mmit=3Dfalse&version=3D2} {commit=3D} 0 14 [junit4:junit4] 2> 12504 T581 oass.IndexSchema.readSchema Reading Solr Sc= hema [junit4:junit4] 2> 12528 T581 oass.IndexSchema.readSchema Schema name=3Dt= est [junit4:junit4] 2> 12561 T551 C37 P13439 oash.ReplicationHandler.inform C= ommits will be reserved for 10000 [junit4:junit4] 2> 12561 T551 C37 P13439 oascsi.HttpClientUtil.createClie= nt Creating new http client, config:connTimeout=3D5000&socketTimeout=3D2000= 0&allowCompression=3Dfalse&maxConnections=3D10000&maxConnectionsPerHost=3D1= 0000 [junit4:junit4] 2> 12590 T551 C37 P13439 oash.SnapPuller. No value= set for 'pollInterval'. Timer Task not started. [junit4:junit4] 2> 12593 T527 C39 P15606 oash.ReplicationHandler.inform C= ommits will be reserved for 10000 [junit4:junit4] 2> 12594 T527 C39 P15606 REQ /replication {command=3Dinde= xversion&wt=3Djavabin&qt=3D/replication&version=3D2} status=3D0 QTime=3D2= =20 [junit4:junit4] 2> 12595 T551 C37 P13439 oash.SnapPuller.fetchLatestIndex= Master's generation: 2 [junit4:junit4] 2> 12595 T551 C37 P13439 oash.SnapPuller.fetchLatestIndex= Slave's generation: 1 [junit4:junit4] 2> 12595 T551 C37 P13439 oash.SnapPuller.fetchLatestIndex= Starting replication process [junit4:junit4] 2> 12599 T527 C39 P15606 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty1 [junit4:junit4] 2> 12600 T527 C39 P15606 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty1/index [junit4:junit4] 2> 12600 T527 C39 P15606 REQ /replication {command=3Dfile= list&generation=3D2&wt=3Djavabin&qt=3D/replication&version=3D2} status=3D0 = QTime=3D2=20 [junit4:junit4] 2> 12601 T551 C37 P13439 oash.SnapPuller.fetchLatestIndex= Number of files in latest index in master: 1 [junit4:junit4] 2> 12603 T551 C37 P13439 oasc.CachingDirectoryFactory.get= return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-So= lr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.Syn= cSliceTest-1356996946965/jetty2/index.20121231183559559 forceNew:false [junit4:junit4] 2> 12603 T551 C37 P13439 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty2 [junit4:junit4] 2> 12604 T551 C37 P13439 oash.SnapPuller.fetchLatestIndex= Starting download to RateLimitedDirectoryWrapper(NRTCachingDirectory(org.a= pache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.clo= ud.SyncSliceTest-1356996946965/jetty2/index.20121231183559559 lockFactory= =3Dorg.apache.lucene.store.NativeFSLockFactory@434ff3e5; maxCacheMB=3D48.0 = maxMergeSizeMB=3D4.0)) fullCopy=3Dtrue [junit4:junit4] 2> 12619 T527 C39 P15606 REQ /replication {file=3Dsegment= s_2&command=3Dfilecontent&checksum=3Dtrue&generation=3D2&qt=3D/replication&= wt=3Dfilestream} status=3D0 QTime=3D6=20 [junit4:junit4] 2> 12634 T551 C37 P13439 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty2/index [junit4:junit4] 2> 12634 T551 C37 P13439 oash.SnapPuller.fetchLatestIndex= Total time taken for download : 0 secs [junit4:junit4] 2> 12635 T551 C37 P13439 oash.SnapPuller.modifyIndexProps= New index installed. Updating index properties... index=3Dindex.2012123118= 3559559 [junit4:junit4] 2> 12637 T551 C37 P13439 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty2 [junit4:junit4] 2> 12638 T551 C37 P13439 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty2 [junit4:junit4] 2> 12638 T551 C37 P13439 oasc.SolrCore.getNewIndexDir New= index directory detected: old=3D./org.apache.solr.cloud.SyncSliceTest-1356= 996946965/jetty2/index/ new=3D./org.apache.solr.cloud.SyncSliceTest-1356996= 946965/jetty2/index.20121231183559559 [junit4:junit4] 2> 12642 T551 C37 P13439 oasc.SolrDeletionPolicy.onInit S= olrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/o= rg.apache.solr.cloud.SyncSliceTest-1356996946965/jetty2/index.2012123118355= 9559 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@434ff3e5; ma= xCacheMB=3D48.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_2,generation=3D2,fi= lenames=3D[segments_2] [junit4:junit4] 2> 12642 T551 C37 P13439 oasc.SolrDeletionPolicy.updateCo= mmits newest commit =3D 2[segments_2] [junit4:junit4] 2> 12644 T551 C37 P13439 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty2 [junit4:junit4] 2> 12649 T551 C37 P13439 oasu.DefaultSolrCoreState.newInd= exWriter Creating new IndexWriter... [junit4:junit4] 2> 12649 T551 C37 P13439 oasu.DefaultSolrCoreState.newInd= exWriter Waiting until IndexWriter is unused... core=3Dcollection1 [junit4:junit4] 2> 12650 T551 C37 P13439 oasu.DefaultSolrCoreState.newInd= exWriter Rollback old IndexWriter... core=3Dcollection1 [junit4:junit4] 2> 12651 T551 C37 P13439 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty2/index.20121231183559559 [junit4:junit4] 2> 12652 T551 C37 P13439 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty2 [junit4:junit4] 2> 12656 T551 C37 P13439 oasc.SolrDeletionPolicy.onInit S= olrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/o= rg.apache.solr.cloud.SyncSliceTest-1356996946965/jetty2/index.2012123118355= 9559 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@434ff3e5; ma= xCacheMB=3D48.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_2,generation=3D2,fi= lenames=3D[segments_2] [junit4:junit4] 2> 12656 T551 C37 P13439 oasc.SolrDeletionPolicy.updateCo= mmits newest commit =3D 2[segments_2] [junit4:junit4] 2> 12656 T551 C37 P13439 oasu.DefaultSolrCoreState.newInd= exWriter New IndexWriter is ready to be used. [junit4:junit4] 2> 12657 T551 C37 P13439 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty2 [junit4:junit4] 2> 12657 T551 C37 P13439 oass.SolrIndexSearcher. Op= ening Searcher@55e898b4 main [junit4:junit4] 2> 12659 T550 oasc.SolrCore.registerSearcher [collection1= ] Registered new searcher Searcher@55e898b4 main{StandardDirectoryReader(se= gments_2:1:nrt)} [junit4:junit4] 2> 12660 T550 oasc.CachingDirectoryFactory.close Releasin= g directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-j= ava7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-135= 6996946965/jetty2/index [junit4:junit4] 2> 12660 T551 C37 P13439 oasu.DirectUpdateHandler2.commit= start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dfalse= ,waitSearcher=3Dfalse,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 12664 T551 C37 P13439 oasc.SolrDeletionPolicy.onCommit= SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/o= rg.apache.solr.cloud.SyncSliceTest-1356996946965/jetty2/index.2012123118355= 9559 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@434ff3e5; ma= xCacheMB=3D48.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_2,generation=3D2,fi= lenames=3D[segments_2] [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/o= rg.apache.solr.cloud.SyncSliceTest-1356996946965/jetty2/index.2012123118355= 9559 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@434ff3e5; ma= xCacheMB=3D48.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_3,generation=3D3,fi= lenames=3D[segments_3] [junit4:junit4] 2> 12664 T551 C37 P13439 oasc.SolrDeletionPolicy.updateCo= mmits newest commit =3D 3[segments_3] [junit4:junit4] 2> 12666 T551 C37 P13439 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty2 [junit4:junit4] 2> 12666 T551 C37 P13439 oasu.DirectUpdateHandler2.commit= end_commit_flush [junit4:junit4] 2> 12666 T551 C37 P13439 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty2/index.20121231183559559 [junit4:junit4] 2> 12667 T551 C37 P13439 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty2/index [junit4:junit4] 2> 12667 T551 C37 P13439 oasc.RecoveryStrategy.replay No = replay needed. core=3Dcollection1 [junit4:junit4] 2> 12667 T551 C37 P13439 oasc.RecoveryStrategy.doRecovery= Replication Recovery was successful - registering as Active. core=3Dcollec= tion1 [junit4:junit4] 2> 12667 T551 C37 P13439 oasc.ZkController.publish publis= hing core=3Dcollection1 state=3Dactive [junit4:junit4] 2> 12668 T551 C37 P13439 oasc.ZkController.publish numSha= rds not found on descriptor - reading it from system property [junit4:junit4] 2> 12670 T551 C37 P13439 oasc.RecoveryStrategy.doRecovery= Finished recovery process. core=3Dcollection1 [junit4:junit4] 2> 13024 T515 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 13025 T515 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "shard":"shard1", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"recovering", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:13446_rnq", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:13446/rnq"} [junit4:junit4] 2> 13031 T515 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "shard":"shard1", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"active", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:13439_rnq", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:13439/rnq"} [junit4:junit4] 2> 13042 T548 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 13042 T564 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 13042 T580 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 13042 T533 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 13042 T514 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 13042 T520 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 13168 T581 oass.OpenExchangeRatesOrgProvider.init Init= ialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 13180 T581 oass.IndexSchema.readSchema default search = field in schema is text [junit4:junit4] 2> 13184 T581 oass.IndexSchema.readSchema unique key fiel= d: id [junit4:junit4] 2> 13202 T581 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 13218 T581 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 13223 T581 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 13224 T581 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 13226 T581 oasc.SolrCore. [collection1] Opening = new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4= .x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest= -jetty4-1356996958853/collection1/, dataDir=3D./org.apache.solr.cloud.SyncS= liceTest-1356996946965/jetty4/ [junit4:junit4] 2> 13226 T581 oasc.JmxMonitoredMap. JMX monitoring = is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMB= eanServer@4ea17876 [junit4:junit4] 2> 13227 T581 oasc.SolrCore.initDirectoryFactory solr.NRT= CachingDirectoryFactory [junit4:junit4] 2> 13228 T581 oasc.CachingDirectoryFactory.get return new= directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.= x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-= 1356996946965/jetty4 forceNew:false [junit4:junit4] 2> 13228 T581 oasc.CachingDirectoryFactory.close Releasin= g directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-j= ava7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-135= 6996946965/jetty4 [junit4:junit4] 2> 13229 T581 oasc.SolrCore.getNewIndexDir New index dire= ctory detected: old=3Dnull new=3D./org.apache.solr.cloud.SyncSliceTest-1356= 996946965/jetty4/index/ [junit4:junit4] 2> 13229 T581 oasc.SolrCore.initIndex WARNING [collection= 1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-135699694696= 5/jetty4/index' doesn't exist. Creating new index... [junit4:junit4] 2> 13230 T581 oasc.CachingDirectoryFactory.get return new= directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.= x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-= 1356996946965/jetty4/index forceNew:false [junit4:junit4] 2> 13236 T581 oasc.SolrDeletionPolicy.onCommit SolrDeleti= onPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/o= rg.apache.solr.cloud.SyncSliceTest-1356996946965/jetty4/index lockFactory= =3Dorg.apache.lucene.store.NativeFSLockFactory@265bb60; maxCacheMB=3D48.0 m= axMergeSizeMB=3D4.0)),segFN=3Dsegments_1,generation=3D1,filenames=3D[segmen= ts_1] [junit4:junit4] 2> 13237 T581 oasc.SolrDeletionPolicy.updateCommits newes= t commit =3D 1[segments_1] [junit4:junit4] 2> 13238 T581 oasc.CachingDirectoryFactory.close Releasin= g directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-j= ava7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-135= 6996946965/jetty4/index [junit4:junit4] 2> 13238 T581 oasc.SolrCore.initWriters created xml: solr= .XMLResponseWriter [junit4:junit4] 2> 13240 T581 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe" [junit4:junit4] 2> 13241 T581 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe-allfields" [junit4:junit4] 2> 13241 T581 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "s= tored_sig" [junit4:junit4] 2> 13242 T581 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "u= niq-fields" [junit4:junit4] 2> 13242 T581 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= istrib-dup-test-chain-implicit" [junit4:junit4] 2> 13243 T581 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 13243 T581 oasc.RequestHandlers.initHandlersFromConfig= created /replication: solr.ReplicationHandler [junit4:junit4] 2> 13244 T581 oasc.RequestHandlers.initHandlersFromConfig= created standard: solr.StandardRequestHandler [junit4:junit4] 2> 13244 T581 oasc.RequestHandlers.initHandlersFromConfig= created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 13245 T581 oasc.RequestHandlers.initHandlersFromConfig= created dismax: solr.SearchHandler [junit4:junit4] 2> 13245 T581 oasc.RequestHandlers.initHandlersFromConfig= created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler [junit4:junit4] 2> 13246 T581 oasc.RequestHandlers.initHandlersFromConfig= created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 13247 T581 oasc.RequestHandlers.initHandlersFromConfig= created defaults: solr.StandardRequestHandler [junit4:junit4] 2> 13247 T581 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.StandardRequestHandler [junit4:junit4] 2> 13247 T581 oasc.RequestHandlers.initHandlersFromConfig= created lazy: solr.StandardRequestHandler [junit4:junit4] 2> 13248 T581 oasc.RequestHandlers.initHandlersFromConfig= created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 13248 T581 oasc.RequestHandlers.initHandlersFromConfig= created /terms: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 13249 T581 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 13250 T581 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchH= andler [junit4:junit4] 2> 13250 T581 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchH= andler [junit4:junit4] 2> 13251 T581 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.= SearchHandler [junit4:junit4] 2> 13251 T581 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 13252 T581 oasc.RequestHandlers.initHandlersFromConfig= created mltrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 13252 T581 oasc.RequestHandlers.initHandlersFromConfig= created tvrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 13253 T581 oasc.RequestHandlers.initHandlersFromConfig= created /mlt: solr.MoreLikeThisHandler [junit4:junit4] 2> 13253 T581 oasc.RequestHandlers.initHandlersFromConfig= created /debug/dump: solr.DumpRequestHandler [junit4:junit4] 2> 13266 T581 oashl.XMLLoader.init xsltCacheLifetimeSecon= ds=3D60 [junit4:junit4] 2> 13271 T581 oasc.SolrCore.initDeprecatedSupport WARNING= solrconfig.xml uses deprecated , Please update your c= onfig to use the ShowFileRequestHandler. [junit4:junit4] 2> 13272 T581 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> 13275 T581 oasc.CachingDirectoryFactory.close Releasin= g directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-j= ava7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-135= 6996946965/jetty4 [junit4:junit4] 2> 13277 T581 oass.SolrIndexSearcher. Opening Searc= her@15092239 main [junit4:junit4] 2> 13278 T581 oasu.CommitTracker. Hard AutoCommit: = disabled [junit4:junit4] 2> 13278 T581 oasu.CommitTracker. Soft AutoCommit: = disabled [junit4:junit4] 2> 13279 T581 oashc.SpellCheckComponent.inform Initializi= ng spell checkers [junit4:junit4] 2> 13286 T581 oass.DirectSolrSpellChecker.init init: {nam= e=3Ddirect,classname=3DDirectSolrSpellChecker,field=3Dlowerfilt,minQueryLen= gth=3D3} [junit4:junit4] 2> 13343 T584 oasc.SolrCore.registerSearcher [collection1= ] Registered new searcher Searcher@15092239 main{StandardDirectoryReader(se= gments_1:1)} [junit4:junit4] 2> 13348 T581 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Ddown [junit4:junit4] 2> 13349 T581 oasc.ZkController.publish numShards not fou= nd on descriptor - reading it from system property [junit4:junit4] 2> 14568 T515 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 14569 T515 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "shard":null, [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"down", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:13455_rnq", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:13455/rnq"} [junit4:junit4] 2> 14569 T515 oasc.Overseer$ClusterStateUpdater.updateSta= te Collection already exists with numShards=3D1 [junit4:junit4] 2> 14570 T515 oasc.Overseer$ClusterStateUpdater.updateSta= te Assigning new node to shard shard=3Dshard1 [junit4:junit4] 2> 14587 T548 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 14587 T580 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 14587 T564 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 14587 T514 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 14587 T533 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 14587 T520 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 15352 T581 oasc.CoreContainer.registerCore registering= core: collection1 [junit4:junit4] 2> 15352 T581 oasc.ZkController.register Register replica= - core:collection1 address:http://127.0.0.1:13455/rnq collection:collectio= n1 shard:shard1 [junit4:junit4] 2> 15367 T581 oasc.ZkController.register We are http://12= 7.0.0.1:13455/rnq/collection1/ and leader is http://127.0.0.1:15606/rnq/col= lection1/ [junit4:junit4] 2> 15367 T581 oasc.ZkController.register No LogReplay nee= ded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:13455/rnq [junit4:junit4] 2> 15367 T581 oasc.ZkController.checkRecovery Core needs = to recover:collection1 [junit4:junit4] 2> 15368 T581 oasu.DefaultSolrCoreState.doRecovery Runnin= g recovery - first canceling any ongoing recovery [junit4:junit4] 2> ASYNC NEW_CORE C40 name=3Dcollection1 org.apache.solr= .core.SolrCore@563f9162 url=3Dhttp://127.0.0.1:13455/rnq/collection1 node= =3D127.0.0.1:13455_rnq C40_STATE=3Dcoll:collection1 core:collection1 props:= {shard=3Dnull, roles=3Dnull, state=3Ddown, core=3Dcollection1, collection= =3Dcollection1, node_name=3D127.0.0.1:13455_rnq, base_url=3Dhttp://127.0.0.= 1:13455/rnq} [junit4:junit4] 2> 15369 T585 C40 P13455 oasc.RecoveryStrategy.run Starti= ng recovery process. core=3Dcollection1 recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 15369 T585 C40 P13455 oasc.RecoveryStrategy.doRecovery= ###### startupVersions=3D[] [junit4:junit4] 2> 15369 T581 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 15369 T585 C40 P13455 oasc.ZkController.publish publis= hing core=3Dcollection1 state=3Drecovering [junit4:junit4] 2> 15370 T585 C40 P13455 oasc.ZkController.publish numSha= rds not found on descriptor - reading it from system property [junit4:junit4] 2> 15370 T492 oass.SolrDispatchFilter.init user.dir=3D/us= r/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build= /solr-core/test/J0 [junit4:junit4] 2> 15371 T585 C40 P13455 oascsi.HttpClientUtil.createClie= nt Creating new http client, config:maxConnections=3D128&maxConnectionsPerH= ost=3D32&followRedirects=3Dfalse [junit4:junit4] 2> 15371 T492 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() done [junit4:junit4] 2> 15372 T492 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&fo= llowRedirects=3Dfalse [junit4:junit4] 2> 15390 T492 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 15392 T492 oasc.AbstractFullDistribZkTestBase.waitForT= hingsToLevelOut Wait for recoveries to finish - wait 15 for each attempt [junit4:junit4] 2> 15393 T492 oasc.AbstractDistribZkTestBase.waitForRecov= eriesToFinish Wait for recoveries to finish - collection: collection1 failO= nTimeout:true timeout (sec):15 [junit4:junit4] 2> 15394 T492 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> C38_STATE=3Dcoll:collection1 core:collection1 props:{= shard=3Dshard1, roles=3Dnull, state=3Drecovering, core=3Dcollection1, colle= ction=3Dcollection1, node_name=3D127.0.0.1:13446_rnq, base_url=3Dhttp://127= .0.0.1:13446/rnq} [junit4:junit4] 2> 15901 T567 C38 P13446 oasc.RecoveryStrategy.doRecovery= Attempting to PeerSync from http://127.0.0.1:15606/rnq/collection1/ core= =3Dcollection1 - recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 15901 T567 C38 P13446 oasu.PeerSync.sync PeerSync: cor= e=3Dcollection1 url=3Dhttp://127.0.0.1:13446/rnq START replicas=3D[http://1= 27.0.0.1:15606/rnq/collection1/] nUpdates=3D100 [junit4:junit4] 2> 15902 T567 C38 P13446 oasu.PeerSync.sync WARNING no fr= ame of reference to tell of we've missed updates [junit4:junit4] 2> 15902 T567 C38 P13446 oasc.RecoveryStrategy.doRecovery= PeerSync Recovery was not successful - trying replication. core=3Dcollecti= on1 [junit4:junit4] 2> 15902 T567 C38 P13446 oasc.RecoveryStrategy.doRecovery= Starting Replication Recovery. core=3Dcollection1 [junit4:junit4] 2> 15902 T567 C38 P13446 oasc.RecoveryStrategy.doRecovery= Begin buffering updates. core=3Dcollection1 [junit4:junit4] 2> 15902 T567 C38 P13446 oasu.UpdateLog.bufferUpdates Sta= rting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog=3Dnull} [junit4:junit4] 2> 15903 T567 C38 P13446 oasc.RecoveryStrategy.replicate = Attempting to replicate from http://127.0.0.1:15606/rnq/collection1/. core= =3Dcollection1 [junit4:junit4] 2> 15903 T567 C38 P13446 oascsi.HttpClientUtil.createClie= nt Creating new http client, config:maxConnections=3D128&maxConnectionsPerH= ost=3D32&followRedirects=3Dfalse [junit4:junit4] 2> 15905 T525 C39 P15606 REQ /get {distrib=3Dfalse&qt=3D/= get&wt=3Djavabin&version=3D2&getVersions=3D100} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 15916 T529 C39 P15606 oasu.DirectUpdateHandler2.commit= start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dfalse= ,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 15925 T529 C39 P15606 oasc.SolrDeletionPolicy.onCommit= SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/o= rg.apache.solr.cloud.SyncSliceTest-1356996946965/jetty1/index lockFactory= =3Dorg.apache.lucene.store.NativeFSLockFactory@34c8ae05; maxCacheMB=3D48.0 = maxMergeSizeMB=3D4.0)),segFN=3Dsegments_2,generation=3D2,filenames=3D[segme= nts_2] [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/o= rg.apache.solr.cloud.SyncSliceTest-1356996946965/jetty1/index lockFactory= =3Dorg.apache.lucene.store.NativeFSLockFactory@34c8ae05; maxCacheMB=3D48.0 = maxMergeSizeMB=3D4.0)),segFN=3Dsegments_3,generation=3D3,filenames=3D[segme= nts_3] [junit4:junit4] 2> 15926 T529 C39 P15606 oasc.SolrDeletionPolicy.updateCo= mmits newest commit =3D 3[segments_3] [junit4:junit4] 2> 15927 T529 C39 P15606 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty1 [junit4:junit4] 2> 15927 T529 C39 P15606 oasu.DirectUpdateHandler2.commit= end_commit_flush [junit4:junit4] 2> 15928 T529 C39 P15606 /update {waitSearcher=3Dtrue&ope= nSearcher=3Dfalse&commit=3Dtrue&commit_end_point=3Dtrue&wt=3Djavabin&softCo= mmit=3Dfalse&version=3D2} {commit=3D} 0 12 [junit4:junit4] 2> 15929 T567 C38 P13446 oash.ReplicationHandler.inform C= ommits will be reserved for 10000 [junit4:junit4] 2> 15929 T567 C38 P13446 oash.SnapPuller. No value= set for 'pollInterval'. Timer Task not started. [junit4:junit4] 2> 15932 T527 C39 P15606 REQ /replication {command=3Dinde= xversion&wt=3Djavabin&qt=3D/replication&version=3D2} status=3D0 QTime=3D0= =20 [junit4:junit4] 2> 15933 T567 C38 P13446 oash.SnapPuller.fetchLatestIndex= Master's generation: 3 [junit4:junit4] 2> 15934 T567 C38 P13446 oash.SnapPuller.fetchLatestIndex= Slave's generation: 1 [junit4:junit4] 2> 15934 T567 C38 P13446 oash.SnapPuller.fetchLatestIndex= Starting replication process [junit4:junit4] 2> 15936 T527 C39 P15606 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty1 [junit4:junit4] 2> 15937 T527 C39 P15606 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty1/index [junit4:junit4] 2> 15938 T527 C39 P15606 REQ /replication {command=3Dfile= list&generation=3D3&wt=3Djavabin&qt=3D/replication&version=3D2} status=3D0 = QTime=3D2=20 [junit4:junit4] 2> 15939 T567 C38 P13446 oash.SnapPuller.fetchLatestIndex= Number of files in latest index in master: 1 [junit4:junit4] 2> 15940 T567 C38 P13446 oasc.CachingDirectoryFactory.get= return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-So= lr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.Syn= cSliceTest-1356996946965/jetty3/index.20121231183602896 forceNew:false [junit4:junit4] 2> 15940 T567 C38 P13446 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty3 [junit4:junit4] 2> 15941 T567 C38 P13446 oash.SnapPuller.fetchLatestIndex= Starting download to RateLimitedDirectoryWrapper(NRTCachingDirectory(org.a= pache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.clo= ud.SyncSliceTest-1356996946965/jetty3/index.20121231183602896 lockFactory= =3Dorg.apache.lucene.store.NativeFSLockFactory@1f873b13; maxCacheMB=3D48.0 = maxMergeSizeMB=3D4.0)) fullCopy=3Dtrue [junit4:junit4] 2> 15945 T527 C39 P15606 REQ /replication {file=3Dsegment= s_3&command=3Dfilecontent&checksum=3Dtrue&generation=3D3&qt=3D/replication&= wt=3Dfilestream} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 15947 T567 C38 P13446 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty3/index [junit4:junit4] 2> 15947 T567 C38 P13446 oash.SnapPuller.fetchLatestIndex= Total time taken for download : 0 secs [junit4:junit4] 2> 15948 T567 C38 P13446 oash.SnapPuller.modifyIndexProps= New index installed. Updating index properties... index=3Dindex.2012123118= 3602896 [junit4:junit4] 2> 15949 T567 C38 P13446 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty3 [junit4:junit4] 2> 15950 T567 C38 P13446 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty3 [junit4:junit4] 2> 15950 T567 C38 P13446 oasc.SolrCore.getNewIndexDir New= index directory detected: old=3D./org.apache.solr.cloud.SyncSliceTest-1356= 996946965/jetty3/index/ new=3D./org.apache.solr.cloud.SyncSliceTest-1356996= 946965/jetty3/index.20121231183602896 [junit4:junit4] 2> 15954 T567 C38 P13446 oasc.SolrDeletionPolicy.onInit S= olrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/o= rg.apache.solr.cloud.SyncSliceTest-1356996946965/jetty3/index.2012123118360= 2896 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@1f873b13; ma= xCacheMB=3D48.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_3,generation=3D3,fi= lenames=3D[segments_3] [junit4:junit4] 2> 15954 T567 C38 P13446 oasc.SolrDeletionPolicy.updateCo= mmits newest commit =3D 3[segments_3] [junit4:junit4] 2> 15956 T567 C38 P13446 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty3 [junit4:junit4] 2> 15956 T567 C38 P13446 oasu.DefaultSolrCoreState.newInd= exWriter Creating new IndexWriter... [junit4:junit4] 2> 15956 T567 C38 P13446 oasu.DefaultSolrCoreState.newInd= exWriter Waiting until IndexWriter is unused... core=3Dcollection1 [junit4:junit4] 2> 15957 T567 C38 P13446 oasu.DefaultSolrCoreState.newInd= exWriter Rollback old IndexWriter... core=3Dcollection1 [junit4:junit4] 2> 15957 T567 C38 P13446 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty3/index.20121231183602896 [junit4:junit4] 2> 15958 T567 C38 P13446 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty3 [junit4:junit4] 2> 15962 T567 C38 P13446 oasc.SolrDeletionPolicy.onInit S= olrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/o= rg.apache.solr.cloud.SyncSliceTest-1356996946965/jetty3/index.2012123118360= 2896 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@1f873b13; ma= xCacheMB=3D48.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_3,generation=3D3,fi= lenames=3D[segments_3] [junit4:junit4] 2> 15962 T567 C38 P13446 oasc.SolrDeletionPolicy.updateCo= mmits newest commit =3D 3[segments_3] [junit4:junit4] 2> 15962 T567 C38 P13446 oasu.DefaultSolrCoreState.newInd= exWriter New IndexWriter is ready to be used. [junit4:junit4] 2> 15963 T567 C38 P13446 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty3 [junit4:junit4] 2> 15963 T567 C38 P13446 oass.SolrIndexSearcher. Op= ening Searcher@37b91744 main [junit4:junit4] 2> 15966 T566 oasc.SolrCore.registerSearcher [collection1= ] Registered new searcher Searcher@37b91744 main{StandardDirectoryReader(se= gments_3:1:nrt)} [junit4:junit4] 2> 15966 T566 oasc.CachingDirectoryFactory.close Releasin= g directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-j= ava7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-135= 6996946965/jetty3/index [junit4:junit4] 2> 15966 T567 C38 P13446 oasu.DirectUpdateHandler2.commit= start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dfalse= ,waitSearcher=3Dfalse,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 15970 T567 C38 P13446 oasc.SolrDeletionPolicy.onCommit= SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/o= rg.apache.solr.cloud.SyncSliceTest-1356996946965/jetty3/index.2012123118360= 2896 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@1f873b13; ma= xCacheMB=3D48.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_3,generation=3D3,fi= lenames=3D[segments_3] [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/o= rg.apache.solr.cloud.SyncSliceTest-1356996946965/jetty3/index.2012123118360= 2896 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@1f873b13; ma= xCacheMB=3D48.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_4,generation=3D4,fi= lenames=3D[segments_4] [junit4:junit4] 2> 15970 T567 C38 P13446 oasc.SolrDeletionPolicy.updateCo= mmits newest commit =3D 4[segments_4] [junit4:junit4] 2> 15971 T567 C38 P13446 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty3 [junit4:junit4] 2> 15971 T567 C38 P13446 oasu.DirectUpdateHandler2.commit= end_commit_flush [junit4:junit4] 2> 15972 T567 C38 P13446 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty3/index.20121231183602896 [junit4:junit4] 2> 15972 T567 C38 P13446 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty3/index [junit4:junit4] 2> 15972 T567 C38 P13446 oasc.RecoveryStrategy.replay No = replay needed. core=3Dcollection1 [junit4:junit4] 2> 15972 T567 C38 P13446 oasc.RecoveryStrategy.doRecovery= Replication Recovery was successful - registering as Active. core=3Dcollec= tion1 [junit4:junit4] 2> 15973 T567 C38 P13446 oasc.ZkController.publish publis= hing core=3Dcollection1 state=3Dactive [junit4:junit4] 2> 15973 T567 C38 P13446 oasc.ZkController.publish numSha= rds not found on descriptor - reading it from system property [junit4:junit4] 2> 15975 T567 C38 P13446 oasc.RecoveryStrategy.doRecovery= Finished recovery process. core=3Dcollection1 [junit4:junit4] 2> 16094 T515 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 16095 T515 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "shard":"shard1", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"recovering", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:13455_rnq", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:13455/rnq"} [junit4:junit4] 2> 16099 T515 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "shard":"shard1", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"active", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:13446_rnq", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:13446/rnq"} [junit4:junit4] 2> 16112 T548 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 16112 T580 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 16112 T533 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 16112 T514 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 16112 T520 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 16112 T564 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 16396 T492 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 17399 T492 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> C40_STATE=3Dcoll:collection1 core:collection1 props:{= shard=3Dshard1, roles=3Dnull, state=3Drecovering, core=3Dcollection1, colle= ction=3Dcollection1, node_name=3D127.0.0.1:13455_rnq, base_url=3Dhttp://127= .0.0.1:13455/rnq} [junit4:junit4] 2> 18393 T585 C40 P13455 oasc.RecoveryStrategy.doRecovery= Attempting to PeerSync from http://127.0.0.1:15606/rnq/collection1/ core= =3Dcollection1 - recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 18393 T585 C40 P13455 oasu.PeerSync.sync PeerSync: cor= e=3Dcollection1 url=3Dhttp://127.0.0.1:13455/rnq START replicas=3D[http://1= 27.0.0.1:15606/rnq/collection1/] nUpdates=3D100 [junit4:junit4] 2> 18394 T585 C40 P13455 oasu.PeerSync.sync WARNING no fr= ame of reference to tell of we've missed updates [junit4:junit4] 2> 18394 T585 C40 P13455 oasc.RecoveryStrategy.doRecovery= PeerSync Recovery was not successful - trying replication. core=3Dcollecti= on1 [junit4:junit4] 2> 18394 T585 C40 P13455 oasc.RecoveryStrategy.doRecovery= Starting Replication Recovery. core=3Dcollection1 [junit4:junit4] 2> 18395 T585 C40 P13455 oasc.RecoveryStrategy.doRecovery= Begin buffering updates. core=3Dcollection1 [junit4:junit4] 2> 18395 T585 C40 P13455 oasu.UpdateLog.bufferUpdates Sta= rting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog=3Dnull} [junit4:junit4] 2> 18395 T585 C40 P13455 oasc.RecoveryStrategy.replicate = Attempting to replicate from http://127.0.0.1:15606/rnq/collection1/. core= =3Dcollection1 [junit4:junit4] 2> 18395 T585 C40 P13455 oascsi.HttpClientUtil.createClie= nt Creating new http client, config:maxConnections=3D128&maxConnectionsPerH= ost=3D32&followRedirects=3Dfalse [junit4:junit4] 2> 18397 T525 C39 P15606 REQ /get {distrib=3Dfalse&qt=3D/= get&wt=3Djavabin&version=3D2&getVersions=3D100} status=3D0 QTime=3D1=20 [junit4:junit4] 2> 18402 T492 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 18413 T523 C39 P15606 oasu.DirectUpdateHandler2.commit= start commit{flags=3D0,_version_=3D0,optimize=3Dfalse,openSearcher=3Dfalse= ,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 18417 T523 C39 P15606 oasc.SolrDeletionPolicy.onCommit= SolrDeletionPolicy.onCommit: commits:num=3D3 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/o= rg.apache.solr.cloud.SyncSliceTest-1356996946965/jetty1/index lockFactory= =3Dorg.apache.lucene.store.NativeFSLockFactory@34c8ae05; maxCacheMB=3D48.0 = maxMergeSizeMB=3D4.0)),segFN=3Dsegments_2,generation=3D2,filenames=3D[segme= nts_2] [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/o= rg.apache.solr.cloud.SyncSliceTest-1356996946965/jetty1/index lockFactory= =3Dorg.apache.lucene.store.NativeFSLockFactory@34c8ae05; maxCacheMB=3D48.0 = maxMergeSizeMB=3D4.0)),segFN=3Dsegments_3,generation=3D3,filenames=3D[segme= nts_3] [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson= -slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/o= rg.apache.solr.cloud.SyncSliceTest-1356996946965/jetty1/index lockFactory= =3Dorg.apache.lucene.store.NativeFSLockFactory@34c8ae05; maxCacheMB=3D48.0 = maxMergeSizeMB=3D4.0)),segFN=3Dsegments_4,generation=3D4,filenames=3D[segme= nts_4] [junit4:junit4] 2> 18417 T523 C39 P15606 oasc.SolrDeletionPolicy.updateCo= mmits newest commit =3D 4[segments_4] [junit4:junit4] 2> 18418 T523 C39 P15606 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty1 [junit4:junit4] 2> 18419 T523 C39 P15606 oasu.DirectUpdateHandler2.commit= end_commit_flush [junit4:junit4] 2> 18419 T523 C39 P15606 /update {waitSearcher=3Dtrue&ope= nSearcher=3Dfalse&commit=3Dtrue&commit_end_point=3Dtrue&wt=3Djavabin&softCo= mmit=3Dfalse&version=3D2} {commit=3D} 0 7 [junit4:junit4] 2> 18420 T585 C40 P13455 oash.ReplicationHandler.inform C= ommits will be reserved for 10000 [junit4:junit4] 2> 18420 T585 C40 P13455 oash.SnapPuller. No value= set for 'pollInterval'. Timer Task not started. [junit4:junit4] 2> 18423 T527 C39 P15606 REQ /replication {command=3Dinde= xversion&wt=3Djavabin&qt=3D/replication&version=3D2} status=3D0 QTime=3D0= =20 [junit4:junit4] 2> 18424 T585 C40 P13455 oash.SnapPuller.fetchLatestIndex= Master's generation: 4 [junit4:junit4] 2> 18425 T585 C40 P13455 oash.SnapPuller.fetchLatestIndex= Slave's generation: 1 [junit4:junit4] 2> 18425 T585 C40 P13455 oash.SnapPuller.fetchLatestIndex= Starting replication process [junit4:junit4] 2> 18427 T527 C39 P15606 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty1 [junit4:junit4] 2> 18428 T527 C39 P15606 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty1/index [junit4:junit4] 2> 18429 T527 C39 P15606 REQ /replication {command=3Dfile= list&generation=3D4&wt=3Djavabin&qt=3D/replication&version=3D2} status=3D0 = QTime=3D2=20 [junit4:junit4] 2> 18429 T585 C40 P13455 oash.SnapPuller.fetchLatestIndex= Number of files in latest index in master: 1 [junit4:junit4] 2> 18431 T585 C40 P13455 oasc.CachingDirectoryFactory.get= return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-So= lr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.Syn= cSliceTest-1356996946965/jetty4/index.20121231183605387 forceNew:false [junit4:junit4] 2> 18431 T585 C40 P13455 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty4 [junit4:junit4] 2> 18432 T585 C40 P13455 oash.SnapPuller.fetchLatestIndex= Starting download to RateLimitedDirectoryWrapper(NRTCachingDirectory(org.a= pache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.clo= ud.SyncSliceTest-1356996946965/jetty4/index.20121231183605387 lockFactory= =3Dorg.apache.lucene.store.NativeFSLockFactory@434d4889; maxCacheMB=3D48.0 = maxMergeSizeMB=3D4.0)) fullCopy=3Dtrue [junit4:junit4] 2> 18436 T527 C39 P15606 REQ /replication {file=3Dsegment= s_4&command=3Dfilecontent&checksum=3Dtrue&generation=3D4&qt=3D/replication&= wt=3Dfilestream} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 18438 T585 C40 P13455 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty4/index [junit4:junit4] 2> 18438 T585 C40 P13455 oash.SnapPuller.fetchLatestIndex= Total time taken for download : 0 secs [junit4:junit4] 2> 18439 T585 C40 P13455 oash.SnapPuller.modifyIndexProps= New index installed. Updating index properties... index=3Dindex.2012123118= 3605387 [junit4:junit4] 2> 18440 T585 C40 P13455 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty4 [junit4:junit4] 2> 18441 T585 C40 P13455 oasc.CachingDirectoryFactory.clo= se Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-= Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSl= iceTest-1356996946965/jetty4 [junit4:junit4] 2> 18441 T585 C40 P13455 oasc.SolrCore.getNewIndexDir New= index directory detected: old=3D./org.apache.solr.cloud.SyncSliceTest-1356= 996946965/jetty4/index/ new=3D./org.apache.solr.cloud.SyncSliceTest-1356996= 946965/jetty4/index.20121231183605387 [junit4:junit4] 2> 18445 T585 C40 P13455 oasc.SolrDeletionPolicy.onInit S= olrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NR [...truncated too long message...] me=3Dqtp712712740-1279 Acceptor0 SocketConnector@127.0.0.1:39441, state=3DR= UNNABLE, group=3DTGRP-BasicDistributedZkTest] [junit4:junit4] 2> =09 at java.net.PlainSocketImpl.socketAccept(Na= tive Method) [junit4:junit4] 2> =09 at java.net.AbstractPlainSocketImpl.accept(= AbstractPlainSocketImpl.java:398) [junit4:junit4] 2> =09 at java.net.ServerSocket.implAccept(ServerS= ocket.java:522) [junit4:junit4] 2> =09 at java.net.ServerSocket.accept(ServerSocke= t.java:490) [junit4:junit4] 2> =09 at org.eclipse.jetty.server.bio.SocketConne= ctor.accept(SocketConnector.java:117) [junit4:junit4] 2> =09 at org.eclipse.jetty.server.AbstractConnect= or$Acceptor.run(AbstractConnector.java:938) [junit4:junit4] 2> =09 at org.eclipse.jetty.util.thread.QueuedThre= adPool.runJob(QueuedThreadPool.java:608) [junit4:junit4] 2> =09 at org.eclipse.jetty.util.thread.QueuedThre= adPool$3.run(QueuedThreadPool.java:543) [junit4:junit4] 2> =09 at java.lang.Thread.run(Thread.java:722) [junit4:junit4] 2> =09 37) Thread[id=3D1432, name=3DsearcherExecutor-841= -thread-1, state=3DWAITING, group=3DTGRP-BasicDistributedZkTest] [junit4:junit4] 2> =09 at sun.misc.Unsafe.park(Native Method) [junit4:junit4] 2> =09 at java.util.concurrent.locks.LockSupport.p= ark(LockSupport.java:186) [junit4:junit4] 2> =09 at java.util.concurrent.locks.AbstractQueue= dSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) [junit4:junit4] 2> =09 at java.util.concurrent.LinkedBlockingQueue= .take(LinkedBlockingQueue.java:442) [junit4:junit4] 2> =09 at java.util.concurrent.ThreadPoolExecutor.= getTask(ThreadPoolExecutor.java:1043) [junit4:junit4] 2> =09 at java.util.concurrent.ThreadPoolExecutor.= runWorker(ThreadPoolExecutor.java:1103) [junit4:junit4] 2> =09 at java.util.concurrent.ThreadPoolExecutor$= Worker.run(ThreadPoolExecutor.java:603) [junit4:junit4] 2> =09 at java.lang.Thread.run(Thread.java:722) [junit4:junit4] 2> =09 38) Thread[id=3D1394, name=3DsearcherExecutor-795= -thread-1, state=3DWAITING, group=3DTGRP-BasicDistributedZkTest] [junit4:junit4] 2> =09 at sun.misc.Unsafe.park(Native Method) [junit4:junit4] 2> =09 at java.util.concurrent.locks.LockSupport.p= ark(LockSupport.java:186) [junit4:junit4] 2> =09 at java.util.concurrent.locks.AbstractQueue= dSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) [junit4:junit4] 2> =09 at java.util.concurrent.LinkedBlockingQueue= .take(LinkedBlockingQueue.java:442) [junit4:junit4] 2> =09 at java.util.concurrent.ThreadPoolExecutor.= getTask(ThreadPoolExecutor.java:1043) [junit4:junit4] 2> =09 at java.util.concurrent.ThreadPoolExecutor.= runWorker(ThreadPoolExecutor.java:1103) [junit4:junit4] 2> =09 at java.util.concurrent.ThreadPoolExecutor$= Worker.run(ThreadPoolExecutor.java:603) [junit4:junit4] 2> =09 at java.lang.Thread.run(Thread.java:722) [junit4:junit4] 2> =09 39) Thread[id=3D1333, name=3DsearcherExecutor-739= -thread-1, state=3DWAITING, group=3DTGRP-BasicDistributedZkTest] [junit4:junit4] 2> =09 at sun.misc.Unsafe.park(Native Method) [junit4:junit4] 2> =09 at java.util.concurrent.locks.LockSupport.p= ark(LockSupport.java:186) [junit4:junit4] 2> =09 at java.util.concurrent.locks.AbstractQueue= dSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) [junit4:junit4] 2> =09 at java.util.concurrent.LinkedBlockingQueue= .take(LinkedBlockingQueue.java:442) [junit4:junit4] 2> =09 at java.util.concurrent.ThreadPoolExecutor.= getTask(ThreadPoolExecutor.java:1043) [junit4:junit4] 2> =09 at java.util.concurrent.ThreadPoolExecutor.= runWorker(ThreadPoolExecutor.java:1103) [junit4:junit4] 2> =09 at java.util.concurrent.ThreadPoolExecutor$= Worker.run(ThreadPoolExecutor.java:603) [junit4:junit4] 2> =09 at java.lang.Thread.run(Thread.java:722) [junit4:junit4] 2> =09 40) Thread[id=3D1248, name=3Dqtp1754970675-1248 A= cceptor0 SocketConnector@127.0.0.1:41913, state=3DRUNNABLE, group=3DTGRP-Ba= sicDistributedZkTest] [junit4:junit4] 2> =09 at java.net.PlainSocketImpl.socketAccept(Na= tive Method) [junit4:junit4] 2> =09 at java.net.AbstractPlainSocketImpl.accept(= AbstractPlainSocketImpl.java:398) [junit4:junit4] 2> =09 at java.net.ServerSocket.implAccept(ServerS= ocket.java:522) [junit4:junit4] 2> =09 at java.net.ServerSocket.accept(ServerSocke= t.java:490) [junit4:junit4] 2> =09 at org.eclipse.jetty.server.bio.SocketConne= ctor.accept(SocketConnector.java:117) [junit4:junit4] 2> =09 at org.eclipse.jetty.server.AbstractConnect= or$Acceptor.run(AbstractConnector.java:938) [junit4:junit4] 2> =09 at org.eclipse.jetty.util.thread.QueuedThre= adPool.runJob(QueuedThreadPool.java:608) [junit4:junit4] 2> =09 at org.eclipse.jetty.util.thread.QueuedThre= adPool$3.run(QueuedThreadPool.java:543) [junit4:junit4] 2> =09 at java.lang.Thread.run(Thread.java:722) [junit4:junit4] 2> =09 41) Thread[id=3D1230, name=3DTEST-BasicDistribute= dZkTest.testDistribSearch-seed#[A299B2FD956D8244]-SendThread(localhost:2674= 1), state=3DRUNNABLE, group=3DTGRP-BasicDistributedZkTest] [junit4:junit4] 2> =09 at sun.nio.ch.SelectorImpl.lockAndDoSelect(= SelectorImpl.java:82) [junit4:junit4] 2> =09 at sun.nio.ch.SelectorImpl.select(SelectorI= mpl.java:98) [junit4:junit4] 2> =09 at org.apache.zookeeper.ClientCnxnSocketNIO= .doTransport(ClientCnxnSocketNIO.java:338) [junit4:junit4] 2> =09 at org.apache.zookeeper.ClientCnxn$SendThre= ad.run(ClientCnxn.java:1068) [junit4:junit4] 2> =09 42) Thread[id=3D1395, name=3DsearcherExecutor-794= -thread-1, state=3DWAITING, group=3DTGRP-BasicDistributedZkTest] [junit4:junit4] 2> =09 at sun.misc.Unsafe.park(Native Method) [junit4:junit4] 2> =09 at java.util.concurrent.locks.LockSupport.p= ark(LockSupport.java:186) [junit4:junit4] 2> =09 at java.util.concurrent.locks.AbstractQueue= dSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) [junit4:junit4] 2> =09 at java.util.concurrent.LinkedBlockingQueue= .take(LinkedBlockingQueue.java:442) [junit4:junit4] 2> =09 at java.util.concurrent.ThreadPoolExecutor.= getTask(ThreadPoolExecutor.java:1043) [junit4:junit4] 2> =09 at java.util.concurrent.ThreadPoolExecutor.= runWorker(ThreadPoolExecutor.java:1103) [junit4:junit4] 2> =09 at java.util.concurrent.ThreadPoolExecutor$= Worker.run(ThreadPoolExecutor.java:603) [junit4:junit4] 2> =09 at java.lang.Thread.run(Thread.java:722) [junit4:junit4] 2> NOTE: test params are: codec=3DSimpleText, sim=3DRando= mSimilarityProvider(queryNorm=3Dfalse,coord=3Dcrazy): {}, locale=3Des_CR, t= imezone=3DEurope/Copenhagen [junit4:junit4] 2> NOTE: FreeBSD 9.0-RELEASE amd64/Oracle Corporation 1.7= .0_09 (64-bit)/cpus=3D16,threads=3D45,free=3D223483368,total=3D383778816 [junit4:junit4] 2> NOTE: All tests run in this JVM: [StatsComponentTest, = AnalysisAfterCoreReloadTest, TermVectorComponentDistributedTest, ReturnFiel= dsTest, TestFoldingMultitermQuery, FullSolrCloudDistribCmdsTest, SchemaVers= ionSpecificBehaviorTest, TestReplicationHandler, LukeRequestHandlerTest, Te= stMergePolicyConfig, TestCSVLoader, TestRecovery, ExternalFileFieldSortTest= , XmlUpdateRequestHandlerTest, EchoParamsTest, TestLRUCache, SolrIndexConfi= gTest, TestUtils, TestFunctionQuery, DocumentBuilderTest, CoreContainerCore= InitFailuresTest, SpellingQueryConverterTest, LeaderElectionTest, DirectSol= rSpellCheckerTest, TestOmitPositions, TestCSVResponseWriter, TestDistribute= dSearch, TestAtomicUpdateErrorCases, BasicFunctionalityTest, TestElisionMul= titermQuery, TestFastWriter, DisMaxRequestHandlerTest, TestArbitraryIndexDi= r, QueryParsingTest, TestFastOutputStream, IndexSchemaTest, TestStressVersi= ons, TestTrie, TestPhraseSuggestions, OpenExchangeRatesOrgProviderTest, Dis= tributedQueryElevationComponentTest, TestSurroundQueryParser, PeerSyncTest,= IndexReaderFactoryTest, ShowFileRequestHandlerTest, ScriptEngineTest, Solr= CoreTest, TestPropInjectDefaults, TestHashPartitioner, RAMDirectoryFactoryT= est, SuggesterTSTTest, StatelessScriptUpdateProcessorFactoryTest, OutputWri= terTest, QueryEqualityTest, SolrInfoMBeanTest, PolyFieldTest, OverseerColle= ctionProcessorTest, TestUpdate, UUIDFieldTest, TimeZoneUtilsTest, BasicDist= ributedZkTest] [junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=3DBasicDist= ributedZkTest -Dtests.seed=3DA299B2FD956D8244 -Dtests.multiplier=3D3 -Dtest= s.slow=3Dtrue -Dtests.locale=3Des_CR -Dtests.timezone=3DEurope/Copenhagen -= Dtests.file.encoding=3DUS-ASCII [junit4:junit4] ERROR 0.00s J1 | BasicDistributedZkTest (suite) <<< [junit4:junit4] > Throwable #1: java.lang.Exception: Suite timeout excee= ded (>=3D 7200000 msec). [junit4:junit4] > =09at __randomizedtesting.SeedInfo.seed([A299B2FD956D8= 244]:0) [junit4:junit4] Completed on J1 in 7223.98s, 1 test, 2 errors <<< FAILURES! [...truncated 12 lines...] BUILD FAILED /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/build.x= ml:353: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/build.x= ml:39: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/bu= ild.xml:178: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/co= mmon-build.xml:438: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/= common-build.xml:1176: The following error occurred while executing this li= ne: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/= common-build.xml:841: There were test failures: 245 suites, 1013 tests, 1 s= uite-level error, 1 error, 1 failure, 22 ignored (4 assumptions) Total time: 147 minutes 9 seconds Build step 'Invoke Ant' marked build as failure Archiving artifacts Recording test results Email was triggered for: Failure Sending email for trigger: Failure ------=_Part_3995_1850686708.1357004335591 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_3995_1850686708.1357004335591--