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 CE96FF371 for ; Thu, 21 Mar 2013 13:20:30 +0000 (UTC) Received: (qmail 27705 invoked by uid 500); 21 Mar 2013 13:20:29 -0000 Delivered-To: apmail-lucene-dev-archive@lucene.apache.org Received: (qmail 27428 invoked by uid 500); 21 Mar 2013 13:20:28 -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 27405 invoked by uid 99); 21 Mar 2013 13:20:28 -0000 Received: from nike.apache.org (HELO nike.apache.org) (192.87.106.230) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 21 Mar 2013 13:20:28 +0000 X-ASF-Spam-Status: No, hits=0.0 required=5.0 tests=NORMAL_HTTP_TO_IP,SPF_PASS,WEIRD_PORT X-Spam-Check-By: apache.org Received-SPF: pass (nike.apache.org: domain of jenkins@thetaphi.de designates 188.138.97.18 as permitted sender) Received: from [188.138.97.18] (HELO mail.sd-datasolutions.de) (188.138.97.18) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 21 Mar 2013 13:20:04 +0000 Received: from serv1 (localhost.localdomain [127.0.0.1]) by mail.sd-datasolutions.de (Postfix) with ESMTP id 7A0EA14AA080; Thu, 21 Mar 2013 13:19:43 +0000 (UTC) Date: Thu, 21 Mar 2013 13:15:04 +0000 (UTC) From: Policeman Jenkins Server To: dev@lucene.apache.org, janhoy@apache.org Message-ID: <746660704.77.1363871983475.JavaMail.jenkins@serv1.sd-datasolutions.de> Subject: [JENKINS] Lucene-Solr-trunk-Linux (64bit/jdk1.8.0-ea-b79) - Build # 4808 - Failure! MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="----=_Part_76_186566627.1363871704605" X-Jenkins-Job: Lucene-Solr-trunk-Linux X-Jenkins-Result: FAILURE X-Virus-Checked: Checked by ClamAV on apache.org ------=_Part_76_186566627.1363871704605 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/4808/ Java: 64bit/jdk1.8.0-ea-b79 -XX:+UseParallelGC 1 tests failed. REGRESSION: org.apache.solr.cloud.BasicDistributedZk2Test.testDistribSearc= h Error Message: Server at http://127.0.0.1:54146/onenodecollectioncore returned non ok stat= us:404, message:Can not find: /onenodecollectioncore/update Stack Trace: org.apache.solr.common.SolrException: Server at http://127.0.0.1:54146/onen= odecollectioncore returned non ok status:404, message:Can not find: /onenod= ecollectioncore/update =09at __randomizedtesting.SeedInfo.seed([DD0A1818EB265ACD:5CEC96009C793AF1]= :0) =09at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServ= er.java:375) =09at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServ= er.java:181) =09at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(Ab= stractUpdateRequest.java:117) =09at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:116) =09at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:102) =09at org.apache.solr.cloud.BasicDistributedZk2Test.testNodeWithoutCollecti= onForwarding(BasicDistributedZk2Test.java:196) =09at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributed= Zk2Test.java:89) =09at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseD= istributedSearchTestCase.java:806) =09at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) =09at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.= java:57) =09at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces= sorImpl.java:43) =09at java.lang.reflect.Method.invoke(Method.java:487) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(Randomized= Runner.java:1559) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(Random= izedRunner.java:79) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(Random= izedRunner.java:737) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(Random= izedRunner.java:773) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(Random= izedRunner.java:787) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:53) =09at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRu= leSetupTeardownChained.java:50) =09at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFi= eldCacheSanity.java:51) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:46) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRul= e$1.evaluate(SystemPropertiesInvariantRule.java:55) =09at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleT= hreadAndTestName.java:49) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:70) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:48) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.= run(ThreadLeakControl.java:358) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTa= sk(ThreadLeakControl.java:782) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(Threa= dLeakControl.java:442) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(Ran= domizedRunner.java:746) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(Random= izedRunner.java:648) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(Random= izedRunner.java:682) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(Random= izedRunner.java:693) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:53) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:46) =09at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStor= eClassName.java:42) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRul= e$1.evaluate(SystemPropertiesInvariantRule.java:55) =09at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMeth= odsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) =09at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMeth= odsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRule= AssertionsRequired.java:43) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:48) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:70) =09at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIg= noreTestSuites.java:55) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.= run(ThreadLeakControl.java:358) =09at java.lang.Thread.run(Thread.java:722) Build Log: [...truncated 9264 lines...] [junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test [junit4:junit4] 2> 0 T1181 oas.BaseDistributedSearchTestCase.initHostCont= ext Setting hostContext system property: / [junit4:junit4] 2> 4 T1181 oas.SolrTestCaseJ4.setUp ###Starting testDistr= ibSearch [junit4:junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-So= lr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2T= est-1363871127344 [junit4:junit4] 2> 4 T1181 oasc.ZkTestServer.run STARTING ZK TEST SERVER [junit4:junit4] 2> 5 T1182 oasc.ZkTestServer$ZKServerMain.runFromConfig S= tarting server [junit4:junit4] 2> 5 T1182 oazs.ZooKeeperServer.setTickTime tickTime set = to 1000 [junit4:junit4] 2> 6 T1182 oazs.ZooKeeperServer.setMinSessionTimeout minS= essionTimeout set to -1 [junit4:junit4] 2> 6 T1182 oazs.ZooKeeperServer.setMaxSessionTimeout maxS= essionTimeout set to -1 [junit4:junit4] 2> 6 T1182 oazs.NIOServerCnxnFactory.configure binding to= port 0.0.0.0/0.0.0.0:0 [junit4:junit4] 2> 7 T1182 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to= /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1363871127344/zookeep= er/server1/data/version-2/snapshot.0 [junit4:junit4] 2> 105 T1181 oasc.ZkTestServer.run start zk server on por= t:38096 [junit4:junit4] 2> 106 T1181 oaz.ZooKeeper. Initiating client conne= ction, connectString=3D127.0.0.1:38096 sessionTimeout=3D10000 watcher=3Dorg= .apache.solr.common.cloud.ConnectionManager@588a6ffa [junit4:junit4] 2> 107 T1181 oascc.ConnectionManager.waitForConnected Wai= ting for client to connect to ZooKeeper [junit4:junit4] 2> 107 T1187 oaz.ClientCnxn$SendThread.logStartConnect Op= ening socket connection to server localhost.localdomain/127.0.0.1:38096. Wi= ll not attempt to authenticate using SASL (access denied ("javax.security.a= uth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 2> 107 T1187 oaz.ClientCnxn$SendThread.primeConnection So= cket connection established to localhost.localdomain/127.0.0.1:38096, initi= ating session [junit4:junit4] 2> 107 T1183 oazs.NIOServerCnxnFactory.run Accepted socke= t connection from /127.0.0.1:51489 [junit4:junit4] 2> 108 T1183 oazs.ZooKeeperServer.processConnectRequest C= lient attempting to establish new session at /127.0.0.1:51489 [junit4:junit4] 2> 108 T1185 oazsp.FileTxnLog.append Creating new log fil= e: log.1 [junit4:junit4] 2> 849 T1185 oazs.ZooKeeperServer.finishSessionInit Estab= lished session 0x13d8d0dd7330000 with negotiated timeout 10000 for client /= 127.0.0.1:51489 [junit4:junit4] 2> 849 T1187 oaz.ClientCnxn$SendThread.onConnected Sessio= n establishment complete on server localhost.localdomain/127.0.0.1:38096, s= essionid =3D 0x13d8d0dd7330000, negotiated timeout =3D 10000 [junit4:junit4] 2> 851 T1188 oascc.ConnectionManager.process Watcher org.= apache.solr.common.cloud.ConnectionManager@588a6ffa name:ZooKeeperConnectio= n Watcher:127.0.0.1:38096 got event WatchedEvent state:SyncConnected type:N= one path:null path:null type:None [junit4:junit4] 2> 851 T1181 oascc.ConnectionManager.waitForConnected Cli= ent is connected to ZooKeeper [junit4:junit4] 2> 851 T1181 oascc.SolrZkClient.makePath makePath: /solr [junit4:junit4] 2> 855 T1186 oazs.PrepRequestProcessor.pRequest2Txn Proce= ssed session termination for sessionid: 0x13d8d0dd7330000 [junit4:junit4] 2> 856 T1188 oaz.ClientCnxn$EventThread.run EventThread s= hut down [junit4:junit4] 2> 856 T1183 oazs.NIOServerCnxn.closeSock Closed socket c= onnection for client /127.0.0.1:51489 which had sessionid 0x13d8d0dd7330000 [junit4:junit4] 2> 856 T1181 oaz.ZooKeeper.close Session: 0x13d8d0dd73300= 00 closed [junit4:junit4] 2> 857 T1181 oaz.ZooKeeper. Initiating client conne= ction, connectString=3D127.0.0.1:38096/solr sessionTimeout=3D10000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@564d9a9b [junit4:junit4] 2> 858 T1181 oascc.ConnectionManager.waitForConnected Wai= ting for client to connect to ZooKeeper [junit4:junit4] 2> 858 T1189 oaz.ClientCnxn$SendThread.logStartConnect Op= ening socket connection to server localhost.localdomain/127.0.0.1:38096. Wi= ll not attempt to authenticate using SASL (access denied ("javax.security.a= uth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 2> 858 T1189 oaz.ClientCnxn$SendThread.primeConnection So= cket connection established to localhost.localdomain/127.0.0.1:38096, initi= ating session [junit4:junit4] 2> 858 T1183 oazs.NIOServerCnxnFactory.run Accepted socke= t connection from /127.0.0.1:51491 [junit4:junit4] 2> 859 T1183 oazs.ZooKeeperServer.processConnectRequest C= lient attempting to establish new session at /127.0.0.1:51491 [junit4:junit4] 2> 860 T1185 oazs.ZooKeeperServer.finishSessionInit Estab= lished session 0x13d8d0dd7330001 with negotiated timeout 10000 for client /= 127.0.0.1:51491 [junit4:junit4] 2> 860 T1189 oaz.ClientCnxn$SendThread.onConnected Sessio= n establishment complete on server localhost.localdomain/127.0.0.1:38096, s= essionid =3D 0x13d8d0dd7330001, negotiated timeout =3D 10000 [junit4:junit4] 2> 860 T1190 oascc.ConnectionManager.process Watcher org.= apache.solr.common.cloud.ConnectionManager@564d9a9b name:ZooKeeperConnectio= n Watcher:127.0.0.1:38096/solr got event WatchedEvent state:SyncConnected t= ype:None path:null path:null type:None [junit4:junit4] 2> 860 T1181 oascc.ConnectionManager.waitForConnected Cli= ent is connected to ZooKeeper [junit4:junit4] 2> 861 T1181 oascc.SolrZkClient.makePath makePath: /colle= ctions/collection1 [junit4:junit4] 2> 864 T1181 oascc.SolrZkClient.makePath makePath: /colle= ctions/collection1/shards [junit4:junit4] 2> 869 T1181 oascc.SolrZkClient.makePath makePath: /colle= ctions/control_collection [junit4:junit4] 2> 872 T1181 oascc.SolrZkClient.makePath makePath: /colle= ctions/control_collection/shards [junit4:junit4] 2> 876 T1181 oasc.AbstractZkTestCase.putConfig put /mnt/s= sd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-file= s/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xm= l [junit4:junit4] 2> 877 T1181 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/solrconfig.xml [junit4:junit4] 2> 884 T1181 oasc.AbstractZkTestCase.putConfig put /mnt/s= sd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-file= s/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml [junit4:junit4] 2> 885 T1181 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/schema.xml [junit4:junit4] 2> 889 T1181 oasc.AbstractZkTestCase.putConfig put /mnt/s= sd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-file= s/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt [junit4:junit4] 2> 890 T1181 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/stopwords.txt [junit4:junit4] 2> 898 T1181 oasc.AbstractZkTestCase.putConfig put /mnt/s= sd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-file= s/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt [junit4:junit4] 2> 899 T1181 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/protwords.txt [junit4:junit4] 2> 903 T1181 oasc.AbstractZkTestCase.putConfig put /mnt/s= sd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-file= s/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml [junit4:junit4] 2> 903 T1181 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/currency.xml [junit4:junit4] 2> 907 T1181 oasc.AbstractZkTestCase.putConfig put /mnt/s= sd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-file= s/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exc= hange-rates.json [junit4:junit4] 2> 907 T1181 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/open-exchange-rates.json [junit4:junit4] 2> 910 T1181 oasc.AbstractZkTestCase.putConfig put /mnt/s= sd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-file= s/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mappi= ng-ISOLatin1Accent.txt [junit4:junit4] 2> 914 T1181 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/mapping-ISOLatin1Accent.txt [junit4:junit4] 2> 928 T1181 oasc.AbstractZkTestCase.putConfig put /mnt/s= sd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-file= s/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt [junit4:junit4] 2> 929 T1181 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/old_synonyms.txt [junit4:junit4] 2> 931 T1181 oasc.AbstractZkTestCase.putConfig put /mnt/s= sd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-file= s/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt [junit4:junit4] 2> 932 T1181 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/synonyms.txt [junit4:junit4] 2> 935 T1186 oazs.PrepRequestProcessor.pRequest2Txn Proce= ssed session termination for sessionid: 0x13d8d0dd7330001 [junit4:junit4] 2> 935 T1183 oazs.NIOServerCnxn.closeSock Closed socket c= onnection for client /127.0.0.1:51491 which had sessionid 0x13d8d0dd7330001 [junit4:junit4] 2> 935 T1181 oaz.ZooKeeper.close Session: 0x13d8d0dd73300= 01 closed [junit4:junit4] 2> 936 T1190 oaz.ClientCnxn$EventThread.run EventThread s= hut down [junit4:junit4] 2> 1046 T1181 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 1087 T1181 oejs.AbstractConnector.doStart Started Sele= ctChannelConnector@127.0.0.1:37166 [junit4:junit4] 2> 1088 T1181 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() [junit4:junit4] 2> 1089 T1181 oasc.SolrResourceLoader.locateSolrHome JNDI= not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 1089 T1181 oasc.SolrResourceLoader.locateSolrHome usin= g system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-tr= unk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistrib= utedZk2Test-controljetty-1363871128276 [junit4:junit4] 2> 1089 T1181 oasc.CoreContainer$Initializer.initialize l= ooking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-L= inux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZ= k2Test-controljetty-1363871128276/solr.xml [junit4:junit4] 2> 1090 T1181 oasc.CoreContainer. New CoreContainer= 1689847368 [junit4:junit4] 2> 1090 T1181 oasc.CoreContainer.load Loading CoreContain= er using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/sol= r/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-c= ontroljetty-1363871128276/' [junit4:junit4] 2> 1090 T1181 oasc.SolrResourceLoader. new SolrReso= urceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Lin= ux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2= Test-controljetty-1363871128276/' [junit4:junit4] 2> 1109 T1181 oashc.HttpShardHandlerFactory.getParameter = Setting socketTimeout to: 120000 [junit4:junit4] 2> 1110 T1181 oashc.HttpShardHandlerFactory.getParameter = Setting urlScheme to: http:// [junit4:junit4] 2> 1110 T1181 oashc.HttpShardHandlerFactory.getParameter = Setting connTimeout to: 15000 [junit4:junit4] 2> 1110 T1181 oashc.HttpShardHandlerFactory.getParameter = Setting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 1110 T1181 oashc.HttpShardHandlerFactory.getParameter = Setting corePoolSize to: 0 [junit4:junit4] 2> 1111 T1181 oashc.HttpShardHandlerFactory.getParameter = Setting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 1111 T1181 oashc.HttpShardHandlerFactory.getParameter = Setting maxThreadIdleTime to: 5 [junit4:junit4] 2> 1111 T1181 oashc.HttpShardHandlerFactory.getParameter = Setting sizeOfQueue to: -1 [junit4:junit4] 2> 1111 T1181 oashc.HttpShardHandlerFactory.getParameter = Setting fairnessPolicy to: false [junit4:junit4] 2> 1112 T1181 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000&= socketTimeout=3D120000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 1118 T1181 oasc.CoreContainer.load Registering Log Lis= tener [junit4:junit4] 2> 1127 T1181 oasc.CoreContainer.initZooKeeper Zookeeper = client=3D127.0.0.1:38096/solr [junit4:junit4] 2> 1127 T1181 oasc.ZkController.checkChrootPath zkHost in= cludes chroot [junit4:junit4] 2> 1127 T1181 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:38096 sessionTimeout=3D60000 watcher=3Dor= g.apache.solr.common.cloud.ConnectionManager@40ef3ae2 [junit4:junit4] 2> 1128 T1181 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 1128 T1200 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost.localdomain/127.0.0.1:38096. W= ill not attempt to authenticate using SASL (access denied ("javax.security.= auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 2> 1129 T1200 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost.localdomain/127.0.0.1:38096, init= iating session [junit4:junit4] 2> 1129 T1183 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /127.0.0.1:51492 [junit4:junit4] 2> 1130 T1183 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /127.0.0.1:51492 [junit4:junit4] 2> 1130 T1185 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13d8d0dd7330002 with negotiated timeout 20000 for client = /127.0.0.1:51492 [junit4:junit4] 2> 1130 T1200 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost.localdomain/127.0.0.1:38096, = sessionid =3D 0x13d8d0dd7330002, negotiated timeout =3D 20000 [junit4:junit4] 2> 1131 T1201 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@40ef3ae2 name:ZooKeeperConnecti= on Watcher:127.0.0.1:38096 got event WatchedEvent state:SyncConnected type:= None path:null path:null type:None [junit4:junit4] 2> 1131 T1181 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 1132 T1186 oazs.PrepRequestProcessor.pRequest2Txn Proc= essed session termination for sessionid: 0x13d8d0dd7330002 [junit4:junit4] 2> 1133 T1183 oazs.NIOServerCnxn.closeSock Closed socket = connection for client /127.0.0.1:51492 which had sessionid 0x13d8d0dd733000= 2 [junit4:junit4] 2> 1133 T1181 oaz.ZooKeeper.close Session: 0x13d8d0dd7330= 002 closed [junit4:junit4] 2> 1134 T1201 oaz.ClientCnxn$EventThread.run EventThread = shut down [junit4:junit4] 2> 1134 T1181 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&so= cketTimeout=3D120000&connTimeout=3D15000 [junit4:junit4] 2> 1137 T1181 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:38096/solr sessionTimeout=3D30000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@37aae32d [junit4:junit4] 2> 1139 T1181 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 1139 T1202 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost.localdomain/127.0.0.1:38096. W= ill not attempt to authenticate using SASL (access denied ("javax.security.= auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 2> 1141 T1202 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost.localdomain/127.0.0.1:38096, init= iating session [junit4:junit4] 2> 1141 T1183 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /127.0.0.1:51493 [junit4:junit4] 2> 1142 T1183 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /127.0.0.1:51493 [junit4:junit4] 2> 1143 T1185 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13d8d0dd7330003 with negotiated timeout 20000 for client = /127.0.0.1:51493 [junit4:junit4] 2> 1143 T1202 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost.localdomain/127.0.0.1:38096, = sessionid =3D 0x13d8d0dd7330003, negotiated timeout =3D 20000 [junit4:junit4] 2> 1144 T1203 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@37aae32d name:ZooKeeperConnecti= on Watcher:127.0.0.1:38096/solr got event WatchedEvent state:SyncConnected = type:None path:null path:null type:None [junit4:junit4] 2> 1144 T1181 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 1147 T1181 oascc.SolrZkClient.makePath makePath: /over= seer/queue [junit4:junit4] 2> 1149 T1186 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13d8d0dd7330003 type:cre= ate cxid:0x7 zxid:0x1b txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 1150 T1181 oascc.SolrZkClient.makePath makePath: /over= seer/collection-queue-work [junit4:junit4] 2> 1154 T1181 oascc.SolrZkClient.makePath makePath: /live= _nodes [junit4:junit4] 2> 1156 T1181 oasc.ZkController.createEphemeralLiveNode R= egister node as live in ZooKeeper:/live_nodes/127.0.0.1:37166_ [junit4:junit4] 2> 1157 T1186 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13d8d0dd7330003 type:del= ete cxid:0x12 zxid:0x1e txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/= 127.0.0.1:37166_ Error:KeeperErrorCode =3D NoNode for /solr/live_nodes/127.= 0.0.1:37166_ [junit4:junit4] 2> 1157 T1181 oascc.SolrZkClient.makePath makePath: /live= _nodes/127.0.0.1:37166_ [junit4:junit4] 2> 1161 T1181 oascc.SolrZkClient.makePath makePath: /over= seer_elect/election [junit4:junit4] 2> 1167 T1186 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13d8d0dd7330003 type:del= ete cxid:0x20 zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer_el= ect/leader Error:KeeperErrorCode =3D NoNode for /solr/overseer_elect/leader [junit4:junit4] 2> 1168 T1181 oascc.SolrZkClient.makePath makePath: /over= seer_elect/leader [junit4:junit4] 2> 1171 T1181 oasc.Overseer.start Overseer (id=3D89382658= 201812995-127.0.0.1:37166_-n_0000000000) starting [junit4:junit4] 2> 1172 T1186 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13d8d0dd7330003 type:cre= ate cxid:0x25 zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 1173 T1186 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13d8d0dd7330003 type:cre= ate cxid:0x26 zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 1174 T1186 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13d8d0dd7330003 type:cre= ate cxid:0x28 zxid:0x27 txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 1175 T1181 oascc.SolrZkClient.makePath makePath: /over= seer/queue-work [junit4:junit4] 2> 1179 T1186 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13d8d0dd7330003 type:cre= ate cxid:0x2e zxid:0x29 txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 1180 T1205 oasc.OverseerCollectionProcessor.run Proces= s current queue of collection creations [junit4:junit4] 2> 1180 T1181 oascc.SolrZkClient.makePath makePath: /clus= terstate.json [junit4:junit4] 2> 1183 T1181 oascc.SolrZkClient.makePath makePath: /alia= ses.json [junit4:junit4] 2> 1184 T1181 oascc.ZkStateReader.createClusterStateWatch= ersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 1186 T1204 oasc.Overseer$ClusterStateUpdater.run Start= ing to work on the main queue [junit4:junit4] 2> 1190 T1206 oasc.CoreContainer.create Creating SolrCore= 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-tr= unk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistrib= utedZk2Test-controljetty-1363871128276/collection1 [junit4:junit4] 2> 1190 T1206 oasc.ZkController.createCollectionZkNode Ch= eck for collection zkNode:control_collection [junit4:junit4] 2> 1190 T1206 oasc.ZkController.createCollectionZkNode Co= llection zkNode exists [junit4:junit4] 2> 1191 T1206 oasc.ZkController.readConfigName Load colle= ction config from:/collections/control_collection [junit4:junit4] 2> 1192 T1206 oasc.SolrResourceLoader. new SolrReso= urceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Lin= ux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2= Test-controljetty-1363871128276/collection1/' [junit4:junit4] 2> 1192 T1206 oasc.SolrResourceLoader.replaceClassLoader = Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/= solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljett= y-1363871128276/collection1/lib/README' to classloader [junit4:junit4] 2> 1192 T1206 oasc.SolrResourceLoader.replaceClassLoader = Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/= solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljett= y-1363871128276/collection1/lib/classes/' to classloader [junit4:junit4] 2> 1216 T1206 oasc.SolrConfig. Using Lucene MatchVe= rsion: LUCENE_50 [junit4:junit4] 2> 1246 T1206 oasc.SolrConfig. Loaded SolrConfig: s= olrconfig.xml [junit4:junit4] 2> 1247 T1206 oass.IndexSchema.readSchema Reading Solr Sc= hema [junit4:junit4] 2> 1251 T1206 oass.IndexSchema.readSchema Schema name=3Dt= est [junit4:junit4] 2> 1630 T1206 oass.OpenExchangeRatesOrgProvider.init Init= ialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 1636 T1206 oass.IndexSchema.readSchema default search = field in schema is text [junit4:junit4] 2> 1638 T1206 oass.IndexSchema.readSchema unique key fiel= d: id [junit4:junit4] 2> 1648 T1206 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 1653 T1206 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 1657 T1206 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 1658 T1206 oass.OpenExchangeRatesOrgProvider$OpenExcha= ngeRates. WARNING Unknown key IMPORTANT NOTE [junit4:junit4] 2> 1658 T1206 oass.OpenExchangeRatesOrgProvider$OpenExcha= ngeRates. WARNING Expected key, got STRING [junit4:junit4] 2> 1658 T1206 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 1659 T1206 oass.OpenExchangeRatesOrgProvider$OpenExcha= ngeRates. WARNING Unknown key IMPORTANT NOTE [junit4:junit4] 2> 1659 T1206 oass.OpenExchangeRatesOrgProvider$OpenExcha= ngeRates. WARNING Expected key, got STRING [junit4:junit4] 2> 1659 T1206 oasc.SolrCore.initDirectoryFactory org.apac= he.solr.core.MockDirectoryFactory [junit4:junit4] 2> 1659 T1206 oasc.SolrCore. [collection1] Opening = new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/bui= ld/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-contro= ljetty-1363871128276/collection1/, dataDir=3D./org.apache.solr.cloud.BasicD= istributedZk2Test-1363871127344/control/data/ [junit4:junit4] 2> 1660 T1206 oasc.JmxMonitoredMap. JMX monitoring = is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMB= eanServer@558a7fb3 [junit4:junit4] 2> 1660 T1206 oasc.SolrCore.initDirectoryFactory org.apac= he.solr.core.MockDirectoryFactory [junit4:junit4] 2> 1660 T1206 oasc.CachingDirectoryFactory.get return new= directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-136387112734= 4/control/data forceNew: false [junit4:junit4] 2> 1660 T1206 oasc.SolrCore.getNewIndexDir New index dire= ctory detected: old=3Dnull new=3D./org.apache.solr.cloud.BasicDistributedZk= 2Test-1363871127344/control/data/index/ [junit4:junit4] 2> 1661 T1206 oasc.SolrCore.initIndex WARNING [collection= 1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-13= 63871127344/control/data/index' doesn't exist. Creating new index... [junit4:junit4] 2> 1661 T1206 oasc.CachingDirectoryFactory.get return new= directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-136387112734= 4/control/data/index forceNew: false [junit4:junit4] 2> 1662 T1206 oasc.SolrDeletionPolicy.onCommit SolrDeleti= onPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@4b669d7c lockFactory=3Dorg.apache.lucene.store.NativeFSLoc= kFactory@8c2ba6a),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1= ] [junit4:junit4] 2> 1662 T1206 oasc.SolrDeletionPolicy.updateCommits newes= t commit =3D 1[segments_1] [junit4:junit4] 2> 1664 T1206 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe" [junit4:junit4] 2> 1664 T1206 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "s= tored_sig" [junit4:junit4] 2> 1665 T1206 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= istrib-dup-test-chain-implicit" [junit4:junit4] 2> 1665 T1206 oasc.RequestHandlers.initHandlersFromConfig= created standard: solr.StandardRequestHandler [junit4:junit4] 2> 1666 T1206 oasc.RequestHandlers.initHandlersFromConfig= created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 1666 T1206 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 1666 T1206 oasc.RequestHandlers.initHandlersFromConfig= created /replication: solr.ReplicationHandler [junit4:junit4] 2> 1667 T1206 oasc.RequestHandlers.initHandlersFromConfig= created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 1667 T1206 oasc.RequestHandlers.initHandlersFromConfig= created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 1670 T1206 oashl.XMLLoader.init xsltCacheLifetimeSecon= ds=3D60 [junit4:junit4] 2> 1672 T1206 oass.SolrIndexSearcher. Opening Searc= her@367522b8 main [junit4:junit4] 2> 1672 T1206 oasu.UpdateHandler.clearLog Clearing tlog f= iles, tlogDir=3D./org.apache.solr.cloud.BasicDistributedZk2Test-13638711273= 44/control/data/tlog [junit4:junit4] 2> 1672 T1206 oasu.CommitTracker. Hard AutoCommit: = disabled [junit4:junit4] 2> 1673 T1206 oasu.CommitTracker. Soft AutoCommit: = disabled [junit4:junit4] 2> 1675 T1207 oasc.SolrCore.registerSearcher [collection1= ] Registered new searcher Searcher@367522b8 main{StandardDirectoryReader(se= gments_1:1)} [junit4:junit4] 2> 1676 T1206 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Ddown [junit4:junit4] 2> 1676 T1206 oasc.ZkController.publish numShards not fou= nd on descriptor - reading it from system property [junit4:junit4] 2> 2690 T1204 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 2691 T1204 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "collection":"control_collection", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:37166", [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "shard":null, [junit4:junit4] 2> =09 "node_name":"127.0.0.1:37166_", [junit4:junit4] 2> =09 "state":"down", [junit4:junit4] 2> =09 "core_node_name":null} [junit4:junit4] 2> 2691 T1204 oasc.Overseer$ClusterStateUpdater.createCol= lection Create collection control_collection with numShards 1 [junit4:junit4] 2> 2691 T1204 oasc.Overseer$ClusterStateUpdater.updateSta= te Assigning new node to shard shard=3Dshard1 [junit4:junit4] 2> 2695 T1203 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 1) [junit4:junit4] 2> 3678 T1206 oasc.CoreContainer.registerCore registering= core: collection1 [junit4:junit4] 2> 3678 T1206 oasc.ZkController.register Register replica= - core:collection1 address:http://127.0.0.1:37166 collection:control_colle= ction shard:shard1 [junit4:junit4] 2> 3679 T1206 oascc.SolrZkClient.makePath makePath: /coll= ections/control_collection/leader_elect/shard1/election [junit4:junit4] 2> 3684 T1186 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13d8d0dd7330003 type:del= ete cxid:0x82 zxid:0x35 txntype:-1 reqpath:n/a Error Path:/solr/collections= /control_collection/leaders Error:KeeperErrorCode =3D NoNode for /solr/coll= ections/control_collection/leaders [junit4:junit4] 2> 3684 T1206 oasc.ShardLeaderElectionContext.runLeaderPr= ocess Running the leader process. [junit4:junit4] 2> 3685 T1186 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13d8d0dd7330003 type:cre= ate cxid:0x83 zxid:0x36 txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 3686 T1206 oasc.ShardLeaderElectionContext.waitForRepl= icasToComeUp Enough replicas found to continue. [junit4:junit4] 2> 3686 T1206 oasc.ShardLeaderElectionContext.runLeaderPr= ocess I may be the new leader - try and sync [junit4:junit4] 2> 3687 T1206 oasc.SyncStrategy.sync Sync replicas to htt= p://127.0.0.1:37166/collection1/ [junit4:junit4] 2> 3687 T1206 oasc.SyncStrategy.syncReplicas Sync Success= - now sync replicas to me [junit4:junit4] 2> 3687 T1206 oasc.SyncStrategy.syncToMe http://127.0.0.1= :37166/collection1/ has no replicas [junit4:junit4] 2> 3687 T1206 oasc.ShardLeaderElectionContext.runLeaderPr= ocess I am the new leader: http://127.0.0.1:37166/collection1/ [junit4:junit4] 2> 3687 T1206 oascc.SolrZkClient.makePath makePath: /coll= ections/control_collection/leaders/shard1 [junit4:junit4] 2> 3690 T1186 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13d8d0dd7330003 type:cre= ate cxid:0x8e zxid:0x3a txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 4201 T1204 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 4208 T1203 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 1) [junit4:junit4] 2> 4243 T1206 oasc.ZkController.register We are http://12= 7.0.0.1:37166/collection1/ and leader is http://127.0.0.1:37166/collection1= / [junit4:junit4] 2> 4243 T1206 oasc.ZkController.register No LogReplay nee= ded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:37166 [junit4:junit4] 2> 4243 T1206 oasc.ZkController.checkRecovery I am the le= ader, no recovery necessary [junit4:junit4] 2> 4244 T1206 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Dactive [junit4:junit4] 2> 4244 T1206 oasc.ZkController.publish numShards not fou= nd on descriptor - reading it from system property [junit4:junit4] 2> 4246 T1206 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 4247 T1181 oass.SolrDispatchFilter.init user.dir=3D/mn= t/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J= 1 [junit4:junit4] 2> 4247 T1181 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() done [junit4:junit4] 2> 4248 T1181 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&fo= llowRedirects=3Dfalse [junit4:junit4] 2> 4251 T1181 oascsi.HttpClientUtil.createClient Creating= new http client, config: [junit4:junit4] 2> 4252 T1181 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:38096/solr sessionTimeout=3D10000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@6392e862 [junit4:junit4] 2> 4252 T1181 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 4253 T1209 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost.localdomain/127.0.0.1:38096. W= ill not attempt to authenticate using SASL (access denied ("javax.security.= auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 2> 4253 T1209 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost.localdomain/127.0.0.1:38096, init= iating session [junit4:junit4] 2> 4253 T1183 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /127.0.0.1:51494 [junit4:junit4] 2> 4254 T1183 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /127.0.0.1:51494 [junit4:junit4] 2> 4254 T1185 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13d8d0dd7330004 with negotiated timeout 10000 for client = /127.0.0.1:51494 [junit4:junit4] 2> 4255 T1209 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost.localdomain/127.0.0.1:38096, = sessionid =3D 0x13d8d0dd7330004, negotiated timeout =3D 10000 [junit4:junit4] 2> 4255 T1210 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@6392e862 name:ZooKeeperConnecti= on Watcher:127.0.0.1:38096/solr got event WatchedEvent state:SyncConnected = type:None path:null path:null type:None [junit4:junit4] 2> 4255 T1181 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 4257 T1181 oascc.ZkStateReader.createClusterStateWatch= ersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 4259 T1181 oasc.ChaosMonkey.monkeyLog monkey: init - e= xpire sessions:true cause connection loss:true [junit4:junit4] 2> 4341 T1181 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 4343 T1181 oejs.AbstractConnector.doStart Started Sele= ctChannelConnector@127.0.0.1:55486 [junit4:junit4] 2> 4344 T1181 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() [junit4:junit4] 2> 4344 T1181 oasc.SolrResourceLoader.locateSolrHome JNDI= not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 4344 T1181 oasc.SolrResourceLoader.locateSolrHome usin= g system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-tr= unk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistrib= utedZk2Test-jetty1-1363871131600 [junit4:junit4] 2> 4345 T1181 oasc.CoreContainer$Initializer.initialize l= ooking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-L= inux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZ= k2Test-jetty1-1363871131600/solr.xml [junit4:junit4] 2> 4345 T1181 oasc.CoreContainer. New CoreContainer= 729517555 [junit4:junit4] 2> 4346 T1181 oasc.CoreContainer.load Loading CoreContain= er using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/sol= r/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-j= etty1-1363871131600/' [junit4:junit4] 2> 4346 T1181 oasc.SolrResourceLoader. new SolrReso= urceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Lin= ux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2= Test-jetty1-1363871131600/' [junit4:junit4] 2> 4374 T1181 oashc.HttpShardHandlerFactory.getParameter = Setting socketTimeout to: 120000 [junit4:junit4] 2> 4375 T1181 oashc.HttpShardHandlerFactory.getParameter = Setting urlScheme to: http:// [junit4:junit4] 2> 4375 T1181 oashc.HttpShardHandlerFactory.getParameter = Setting connTimeout to: 15000 [junit4:junit4] 2> 4376 T1181 oashc.HttpShardHandlerFactory.getParameter = Setting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 4376 T1181 oashc.HttpShardHandlerFactory.getParameter = Setting corePoolSize to: 0 [junit4:junit4] 2> 4377 T1181 oashc.HttpShardHandlerFactory.getParameter = Setting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 4377 T1181 oashc.HttpShardHandlerFactory.getParameter = Setting maxThreadIdleTime to: 5 [junit4:junit4] 2> 4378 T1181 oashc.HttpShardHandlerFactory.getParameter = Setting sizeOfQueue to: -1 [junit4:junit4] 2> 4378 T1181 oashc.HttpShardHandlerFactory.getParameter = Setting fairnessPolicy to: false [junit4:junit4] 2> 4379 T1181 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000&= socketTimeout=3D120000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 4387 T1181 oasc.CoreContainer.load Registering Log Lis= tener [junit4:junit4] 2> 4400 T1181 oasc.CoreContainer.initZooKeeper Zookeeper = client=3D127.0.0.1:38096/solr [junit4:junit4] 2> 4401 T1181 oasc.ZkController.checkChrootPath zkHost in= cludes chroot [junit4:junit4] 2> 4401 T1181 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:38096 sessionTimeout=3D60000 watcher=3Dor= g.apache.solr.common.cloud.ConnectionManager@7ccd71c2 [junit4:junit4] 2> 4402 T1181 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 4402 T1220 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost.localdomain/127.0.0.1:38096. W= ill not attempt to authenticate using SASL (access denied ("javax.security.= auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 2> 4403 T1220 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost.localdomain/127.0.0.1:38096, init= iating session [junit4:junit4] 2> 4403 T1183 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /127.0.0.1:51495 [junit4:junit4] 2> 4403 T1183 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /127.0.0.1:51495 [junit4:junit4] 2> 4404 T1185 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13d8d0dd7330005 with negotiated timeout 20000 for client = /127.0.0.1:51495 [junit4:junit4] 2> 4404 T1220 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost.localdomain/127.0.0.1:38096, = sessionid =3D 0x13d8d0dd7330005, negotiated timeout =3D 20000 [junit4:junit4] 2> 4404 T1221 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@7ccd71c2 name:ZooKeeperConnecti= on Watcher:127.0.0.1:38096 got event WatchedEvent state:SyncConnected type:= None path:null path:null type:None [junit4:junit4] 2> 4404 T1181 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 4406 T1186 oazs.PrepRequestProcessor.pRequest2Txn Proc= essed session termination for sessionid: 0x13d8d0dd7330005 [junit4:junit4] 2> 4406 T1183 oazs.NIOServerCnxn.closeSock Closed socket = connection for client /127.0.0.1:51495 which had sessionid 0x13d8d0dd733000= 5 [junit4:junit4] 2> 4406 T1181 oaz.ZooKeeper.close Session: 0x13d8d0dd7330= 005 closed [junit4:junit4] 2> 4407 T1181 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&so= cketTimeout=3D120000&connTimeout=3D15000 [junit4:junit4] 2> 4407 T1221 oaz.ClientCnxn$EventThread.run EventThread = shut down [junit4:junit4] 2> 4409 T1181 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:38096/solr sessionTimeout=3D30000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@67a578fe [junit4:junit4] 2> 4411 T1222 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost.localdomain/127.0.0.1:38096. W= ill not attempt to authenticate using SASL (access denied ("javax.security.= auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 2> 4411 T1222 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost.localdomain/127.0.0.1:38096, init= iating session [junit4:junit4] 2> 4411 T1181 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 4411 T1183 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /127.0.0.1:51496 [junit4:junit4] 2> 4412 T1183 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /127.0.0.1:51496 [junit4:junit4] 2> 4413 T1185 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13d8d0dd7330006 with negotiated timeout 20000 for client = /127.0.0.1:51496 [junit4:junit4] 2> 4413 T1222 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost.localdomain/127.0.0.1:38096, = sessionid =3D 0x13d8d0dd7330006, negotiated timeout =3D 20000 [junit4:junit4] 2> 4413 T1223 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@67a578fe name:ZooKeeperConnecti= on Watcher:127.0.0.1:38096/solr got event WatchedEvent state:SyncConnected = type:None path:null path:null type:None [junit4:junit4] 2> 4413 T1181 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 4414 T1186 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13d8d0dd7330006 type:cre= ate cxid:0x1 zxid:0x48 txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 4415 T1186 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13d8d0dd7330006 type:cre= ate cxid:0x3 zxid:0x49 txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 4417 T1181 oascc.ZkStateReader.createClusterStateWatch= ersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 5425 T1181 oasc.ZkController.createEphemeralLiveNode R= egister node as live in ZooKeeper:/live_nodes/127.0.0.1:55486_ [junit4:junit4] 2> 5426 T1186 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13d8d0dd7330006 type:del= ete cxid:0xd zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/1= 27.0.0.1:55486_ Error:KeeperErrorCode =3D NoNode for /solr/live_nodes/127.0= .0.1:55486_ [junit4:junit4] 2> 5427 T1181 oascc.SolrZkClient.makePath makePath: /live= _nodes/127.0.0.1:55486_ [junit4:junit4] 2> 5429 T1203 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/= live_nodes, has occurred - updating... (live nodes size: 1) [junit4:junit4] 2> 5430 T1210 oascc.ZkStateReader$3.process Updating live= nodes... (2) [junit4:junit4] 2> 5430 T1223 oascc.ZkStateReader$3.process Updating live= nodes... (2) [junit4:junit4] 2> 5431 T1203 oascc.ZkStateReader$3.process Updating live= nodes... (2) [junit4:junit4] 2> 5437 T1224 oasc.CoreContainer.create Creating SolrCore= 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-tr= unk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistrib= utedZk2Test-jetty1-1363871131600/collection1 [junit4:junit4] 2> 5437 T1224 oasc.ZkController.createCollectionZkNode Ch= eck for collection zkNode:collection1 [junit4:junit4] 2> 5437 T1224 oasc.ZkController.createCollectionZkNode Co= llection zkNode exists [junit4:junit4] 2> 5438 T1224 oasc.ZkController.readConfigName Load colle= ction config from:/collections/collection1 [junit4:junit4] 2> 5438 T1224 oasc.SolrResourceLoader. new SolrReso= urceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Lin= ux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2= Test-jetty1-1363871131600/collection1/' [junit4:junit4] 2> 5439 T1224 oasc.SolrResourceLoader.replaceClassLoader = Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/= solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1363= 871131600/collection1/lib/README' to classloader [junit4:junit4] 2> 5439 T1224 oasc.SolrResourceLoader.replaceClassLoader = Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/= solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1363= 871131600/collection1/lib/classes/' to classloader [junit4:junit4] 2> 5473 T1224 oasc.SolrConfig. Using Lucene MatchVe= rsion: LUCENE_50 [junit4:junit4] 2> 5512 T1224 oasc.SolrConfig. Loaded SolrConfig: s= olrconfig.xml [junit4:junit4] 2> 5513 T1224 oass.IndexSchema.readSchema Reading Solr Sc= hema [junit4:junit4] 2> 5518 T1224 oass.IndexSchema.readSchema Schema name=3Dt= est [junit4:junit4] 2> 5920 T1204 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 5921 T1204 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "collection":"control_collection", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:37166", [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "shard":"shard1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:37166_", [junit4:junit4] 2> =09 "state":"active", [junit4:junit4] 2> =09 "core_node_name":"127.0.0.1:37166__collection1"} [junit4:junit4] 2> 5926 T1203 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 5926 T1210 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 5926 T1223 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 6132 T1224 oass.OpenExchangeRatesOrgProvider.init Init= ialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 6137 T1224 oass.IndexSchema.readSchema default search = field in schema is text [junit4:junit4] 2> 6140 T1224 oass.IndexSchema.readSchema unique key fiel= d: id [junit4:junit4] 2> 6150 T1224 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 6153 T1224 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 6157 T1224 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 6158 T1224 oass.OpenExchangeRatesOrgProvider$OpenExcha= ngeRates. WARNING Unknown key IMPORTANT NOTE [junit4:junit4] 2> 6158 T1224 oass.OpenExchangeRatesOrgProvider$OpenExcha= ngeRates. WARNING Expected key, got STRING [junit4:junit4] 2> 6158 T1224 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 6159 T1224 oass.OpenExchangeRatesOrgProvider$OpenExcha= ngeRates. WARNING Unknown key IMPORTANT NOTE [junit4:junit4] 2> 6159 T1224 oass.OpenExchangeRatesOrgProvider$OpenExcha= ngeRates. WARNING Expected key, got STRING [junit4:junit4] 2> 6160 T1224 oasc.SolrCore.initDirectoryFactory org.apac= he.solr.core.MockDirectoryFactory [junit4:junit4] 2> 6160 T1224 oasc.SolrCore. [collection1] Opening = new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/bui= ld/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1= -1363871131600/collection1/, dataDir=3D./org.apache.solr.cloud.BasicDistrib= utedZk2Test-1363871127344/jetty1/ [junit4:junit4] 2> 6160 T1224 oasc.JmxMonitoredMap. JMX monitoring = is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMB= eanServer@558a7fb3 [junit4:junit4] 2> 6160 T1224 oasc.SolrCore.initDirectoryFactory org.apac= he.solr.core.MockDirectoryFactory [junit4:junit4] 2> 6161 T1224 oasc.CachingDirectoryFactory.get return new= directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-136387112734= 4/jetty1 forceNew: false [junit4:junit4] 2> 6161 T1224 oasc.SolrCore.getNewIndexDir New index dire= ctory detected: old=3Dnull new=3D./org.apache.solr.cloud.BasicDistributedZk= 2Test-1363871127344/jetty1/index/ [junit4:junit4] 2> 6161 T1224 oasc.SolrCore.initIndex WARNING [collection= 1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-13= 63871127344/jetty1/index' doesn't exist. Creating new index... [junit4:junit4] 2> 6162 T1224 oasc.CachingDirectoryFactory.get return new= directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-136387112734= 4/jetty1/index forceNew: false [junit4:junit4] 2> 6163 T1224 oasc.SolrDeletionPolicy.onCommit SolrDeleti= onPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@481f34e6 lockFactory=3Dorg.apache.lucene.store.NativeFSLoc= kFactory@67aadddc),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_= 1] [junit4:junit4] 2> 6163 T1224 oasc.SolrDeletionPolicy.updateCommits newes= t commit =3D 1[segments_1] [junit4:junit4] 2> 6165 T1224 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe" [junit4:junit4] 2> 6165 T1224 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "s= tored_sig" [junit4:junit4] 2> 6166 T1224 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= istrib-dup-test-chain-implicit" [junit4:junit4] 2> 6166 T1224 oasc.RequestHandlers.initHandlersFromConfig= created standard: solr.StandardRequestHandler [junit4:junit4] 2> 6167 T1224 oasc.RequestHandlers.initHandlersFromConfig= created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 6167 T1224 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 6167 T1224 oasc.RequestHandlers.initHandlersFromConfig= created /replication: solr.ReplicationHandler [junit4:junit4] 2> 6167 T1224 oasc.RequestHandlers.initHandlersFromConfig= created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 6168 T1224 oasc.RequestHandlers.initHandlersFromConfig= created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 6171 T1224 oashl.XMLLoader.init xsltCacheLifetimeSecon= ds=3D60 [junit4:junit4] 2> 6174 T1224 oass.SolrIndexSearcher. Opening Searc= her@77cb7906 main [junit4:junit4] 2> 6174 T1224 oasu.UpdateHandler.clearLog Clearing tlog f= iles, tlogDir=3D./org.apache.solr.cloud.BasicDistributedZk2Test-13638711273= 44/jetty1/tlog [junit4:junit4] 2> 6174 T1224 oasu.CommitTracker. Hard AutoCommit: = disabled [junit4:junit4] 2> 6175 T1224 oasu.CommitTracker. Soft AutoCommit: = disabled [junit4:junit4] 2> 6179 T1225 oasc.SolrCore.registerSearcher [collection1= ] Registered new searcher Searcher@77cb7906 main{StandardDirectoryReader(se= gments_1:1)} [junit4:junit4] 2> 6182 T1224 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Ddown [junit4:junit4] 2> 6182 T1224 oasc.ZkController.publish numShards not fou= nd on descriptor - reading it from system property [junit4:junit4] 2> 7429 T1204 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 7430 T1204 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D2 message=3D{ [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:55486", [junit4:junit4] 2> =09 "numShards":"2", [junit4:junit4] 2> =09 "shard":null, [junit4:junit4] 2> =09 "node_name":"127.0.0.1:55486_", [junit4:junit4] 2> =09 "state":"down", [junit4:junit4] 2> =09 "core_node_name":null} [junit4:junit4] 2> 7430 T1204 oasc.Overseer$ClusterStateUpdater.createCol= lection Create collection collection1 with numShards 2 [junit4:junit4] 2> 7430 T1204 oasc.Overseer$ClusterStateUpdater.updateSta= te Assigning new node to shard shard=3Dshard1 [junit4:junit4] 2> 7471 T1210 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 7471 T1223 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 7471 T1203 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 8183 T1224 oasc.CoreContainer.registerCore registering= core: collection1 [junit4:junit4] 2> 8183 T1224 oasc.ZkController.register Register replica= - core:collection1 address:http://127.0.0.1:55486 collection:collection1 s= hard:shard1 [junit4:junit4] 2> 8184 T1224 oascc.SolrZkClient.makePath makePath: /coll= ections/collection1/leader_elect/shard1/election [junit4:junit4] 2> 8189 T1186 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13d8d0dd7330006 type:del= ete cxid:0x4a 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> 8190 T1224 oasc.ShardLeaderElectionContext.runLeaderPr= ocess Running the leader process. [junit4:junit4] 2> 8190 T1186 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13d8d0dd7330006 type:cre= ate cxid:0x4b zxid:0x5b txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 8192 T1224 oasc.ShardLeaderElectionContext.waitForRepl= icasToComeUp Enough replicas found to continue. [junit4:junit4] 2> 8192 T1224 oasc.ShardLeaderElectionContext.runLeaderPr= ocess I may be the new leader - try and sync [junit4:junit4] 2> 8192 T1224 oasc.SyncStrategy.sync Sync replicas to htt= p://127.0.0.1:55486/collection1/ [junit4:junit4] 2> 8192 T1224 oasc.SyncStrategy.syncReplicas Sync Success= - now sync replicas to me [junit4:junit4] 2> 8193 T1224 oasc.SyncStrategy.syncToMe http://127.0.0.1= :55486/collection1/ has no replicas [junit4:junit4] 2> 8193 T1224 oasc.ShardLeaderElectionContext.runLeaderPr= ocess I am the new leader: http://127.0.0.1:55486/collection1/ [junit4:junit4] 2> 8193 T1224 oascc.SolrZkClient.makePath makePath: /coll= ections/collection1/leaders/shard1 [junit4:junit4] 2> 8196 T1186 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13d8d0dd7330006 type:cre= ate cxid:0x56 zxid:0x5f txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 8977 T1204 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 8983 T1223 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 8983 T1203 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 8983 T1210 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 9000 T1224 oasc.ZkController.register We are http://12= 7.0.0.1:55486/collection1/ and leader is http://127.0.0.1:55486/collection1= / [junit4:junit4] 2> 9000 T1224 oasc.ZkController.register No LogReplay nee= ded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:55486 [junit4:junit4] 2> 9000 T1224 oasc.ZkController.checkRecovery I am the le= ader, no recovery necessary [junit4:junit4] 2> 9001 T1224 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Dactive [junit4:junit4] 2> 9001 T1224 oasc.ZkController.publish numShards not fou= nd on descriptor - reading it from system property [junit4:junit4] 2> 9002 T1224 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 9003 T1181 oass.SolrDispatchFilter.init user.dir=3D/mn= t/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J= 1 [junit4:junit4] 2> 9004 T1181 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() done [junit4:junit4] 2> 9004 T1181 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&fo= llowRedirects=3Dfalse [junit4:junit4] 2> 9095 T1181 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 9097 T1181 oejs.AbstractConnector.doStart Started Sele= ctChannelConnector@127.0.0.1:54146 [junit4:junit4] 2> 9098 T1181 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() [junit4:junit4] 2> 9098 T1181 oasc.SolrResourceLoader.locateSolrHome JNDI= not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 9099 T1181 oasc.SolrResourceLoader.locateSolrHome usin= g system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-tr= unk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistrib= utedZk2Test-jetty2-1363871136348 [junit4:junit4] 2> 9099 T1181 oasc.CoreContainer$Initializer.initialize l= ooking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-L= inux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZ= k2Test-jetty2-1363871136348/solr.xml [junit4:junit4] 2> 9099 T1181 oasc.CoreContainer. New CoreContainer= 374078220 [junit4:junit4] 2> 9100 T1181 oasc.CoreContainer.load Loading CoreContain= er using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/sol= r/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-j= etty2-1363871136348/' [junit4:junit4] 2> 9100 T1181 oasc.SolrResourceLoader. new SolrReso= urceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Lin= ux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2= Test-jetty2-1363871136348/' [junit4:junit4] 2> 9117 T1181 oashc.HttpShardHandlerFactory.getParameter = Setting socketTimeout to: 120000 [junit4:junit4] 2> 9118 T1181 oashc.HttpShardHandlerFactory.getParameter = Setting urlScheme to: http:// [junit4:junit4] 2> 9118 T1181 oashc.HttpShardHandlerFactory.getParameter = Setting connTimeout to: 15000 [junit4:junit4] 2> 9118 T1181 oashc.HttpShardHandlerFactory.getParameter = Setting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 9119 T1181 oashc.HttpShardHandlerFactory.getParameter = Setting corePoolSize to: 0 [junit4:junit4] 2> 9119 T1181 oashc.HttpShardHandlerFactory.getParameter = Setting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 9119 T1181 oashc.HttpShardHandlerFactory.getParameter = Setting maxThreadIdleTime to: 5 [junit4:junit4] 2> 9120 T1181 oashc.HttpShardHandlerFactory.getParameter = Setting sizeOfQueue to: -1 [junit4:junit4] 2> 9120 T1181 oashc.HttpShardHandlerFactory.getParameter = Setting fairnessPolicy to: false [junit4:junit4] 2> 9120 T1181 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000&= socketTimeout=3D120000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 9126 T1181 oasc.CoreContainer.load Registering Log Lis= tener [junit4:junit4] 2> 9135 T1181 oasc.CoreContainer.initZooKeeper Zookeeper = client=3D127.0.0.1:38096/solr [junit4:junit4] 2> 9135 T1181 oasc.ZkController.checkChrootPath zkHost in= cludes chroot [junit4:junit4] 2> 9135 T1181 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:38096 sessionTimeout=3D60000 watcher=3Dor= g.apache.solr.common.cloud.ConnectionManager@781b9b7b [junit4:junit4] 2> 9136 T1181 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 9136 T1236 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost.localdomain/127.0.0.1:38096. W= ill not attempt to authenticate using SASL (access denied ("javax.security.= auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 2> 9137 T1236 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost.localdomain/127.0.0.1:38096, init= iating session [junit4:junit4] 2> 9137 T1183 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /127.0.0.1:51503 [junit4:junit4] 2> 9138 T1183 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /127.0.0.1:51503 [junit4:junit4] 2> 9138 T1185 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13d8d0dd7330007 with negotiated timeout 20000 for client = /127.0.0.1:51503 [junit4:junit4] 2> 9138 T1236 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost.localdomain/127.0.0.1:38096, = sessionid =3D 0x13d8d0dd7330007, negotiated timeout =3D 20000 [junit4:junit4] 2> 9139 T1237 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@781b9b7b name:ZooKeeperConnecti= on Watcher:127.0.0.1:38096 got event WatchedEvent state:SyncConnected type:= None path:null path:null type:None [junit4:junit4] 2> 9139 T1181 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 9140 T1186 oazs.PrepRequestProcessor.pRequest2Txn Proc= essed session termination for sessionid: 0x13d8d0dd7330007 [junit4:junit4] 2> 9140 T1237 oaz.ClientCnxn$EventThread.run EventThread = shut down [junit4:junit4] 2> 9140 T1183 oazs.NIOServerCnxn.closeSock Closed socket = connection for client /127.0.0.1:51503 which had sessionid 0x13d8d0dd733000= 7 [junit4:junit4] 2> 9140 T1181 oaz.ZooKeeper.close Session: 0x13d8d0dd7330= 007 closed [junit4:junit4] 2> 9141 T1181 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&so= cketTimeout=3D120000&connTimeout=3D15000 [junit4:junit4] 2> 9143 T1181 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:38096/solr sessionTimeout=3D30000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@4b8b826a [junit4:junit4] 2> 9144 T1181 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 9144 T1238 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost.localdomain/127.0.0.1:38096. W= ill not attempt to authenticate using SASL (access denied ("javax.security.= auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 2> 9145 T1238 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost.localdomain/127.0.0.1:38096, init= iating session [junit4:junit4] 2> 9145 T1183 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /127.0.0.1:51504 [junit4:junit4] 2> 9145 T1183 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /127.0.0.1:51504 [junit4:junit4] 2> 9146 T1185 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13d8d0dd7330008 with negotiated timeout 20000 for client = /127.0.0.1:51504 [junit4:junit4] 2> 9146 T1238 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost.localdomain/127.0.0.1:38096, = sessionid =3D 0x13d8d0dd7330008, negotiated timeout =3D 20000 [junit4:junit4] 2> 9146 T1239 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@4b8b826a name:ZooKeeperConnecti= on Watcher:127.0.0.1:38096/solr got event WatchedEvent state:SyncConnected = type:None path:null path:null type:None [junit4:junit4] 2> 9146 T1181 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 9148 T1186 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13d8d0dd7330008 type:cre= ate cxid:0x1 zxid:0x6c txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 9149 T1186 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13d8d0dd7330008 type:cre= ate cxid:0x3 zxid:0x6d txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 9150 T1181 oascc.ZkStateReader.createClusterStateWatch= ersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 10153 T1181 oasc.ZkController.createEphemeralLiveNode = Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54146_ [junit4:junit4] 2> 10154 T1186 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d8d0dd7330008 type:de= lete cxid:0xd zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/= 127.0.0.1:54146_ Error:KeeperErrorCode =3D NoNode for /solr/live_nodes/127.= 0.0.1:54146_ [junit4:junit4] 2> 10154 T1181 oascc.SolrZkClient.makePath makePath: /liv= e_nodes/127.0.0.1:54146_ [junit4:junit4] 2> 10156 T1223 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 10156 T1203 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 10156 T1210 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 10157 T1239 oascc.ZkStateReader$3.process Updating liv= e nodes... (3) [junit4:junit4] 2> 10158 T1203 oascc.ZkStateReader$3.process Updating liv= e nodes... (3) [junit4:junit4] 2> 10158 T1210 oascc.ZkStateReader$3.process Updating liv= e nodes... (3) [junit4:junit4] 2> 10159 T1223 oascc.ZkStateReader$3.process Updating liv= e nodes... (3) [junit4:junit4] 2> 10162 T1240 oasc.CoreContainer.create Creating SolrCor= e 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-t= runk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistri= butedZk2Test-jetty2-1363871136348/collection1 [junit4:junit4] 2> 10162 T1240 oasc.ZkController.createCollectionZkNode C= heck for collection zkNode:collection1 [junit4:junit4] 2> 10163 T1240 oasc.ZkController.createCollectionZkNode C= ollection zkNode exists [junit4:junit4] 2> 10163 T1240 oasc.ZkController.readConfigName Load coll= ection config from:/collections/collection1 [junit4:junit4] 2> 10164 T1240 oasc.SolrResourceLoader. new SolrRes= ourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Li= nux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk= 2Test-jetty2-1363871136348/collection1/' [junit4:junit4] 2> 10164 T1240 oasc.SolrResourceLoader.replaceClassLoader= Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build= /solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-136= 3871136348/collection1/lib/README' to classloader [junit4:junit4] 2> 10164 T1240 oasc.SolrResourceLoader.replaceClassLoader= Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build= /solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-136= 3871136348/collection1/lib/classes/' to classloader [junit4:junit4] 2> 10185 T1240 oasc.SolrConfig. Using Lucene MatchV= ersion: LUCENE_50 [junit4:junit4] 2> 10210 T1240 oasc.SolrConfig. Loaded SolrConfig: = solrconfig.xml [junit4:junit4] 2> 10211 T1240 oass.IndexSchema.readSchema Reading Solr S= chema [junit4:junit4] 2> 10214 T1240 oass.IndexSchema.readSchema Schema name=3D= test [junit4:junit4] 2> 10488 T1204 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 10489 T1204 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D2 message=3D{ [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:55486", [junit4:junit4] 2> =09 "numShards":"2", [junit4:junit4] 2> =09 "shard":"shard1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:55486_", [junit4:junit4] 2> =09 "state":"active", [junit4:junit4] 2> =09 "core_node_name":"127.0.0.1:55486__collection1"} [junit4:junit4] 2> 10490 T1240 oass.OpenExchangeRatesOrgProvider.init Ini= tialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 10492 T1203 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 10492 T1223 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 10492 T1239 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 10492 T1210 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 10496 T1240 oass.IndexSchema.readSchema default search= field in schema is text [junit4:junit4] 2> 10498 T1240 oass.IndexSchema.readSchema unique key fie= ld: id [junit4:junit4] 2> 10509 T1240 oass.FileExchangeRateProvider.reload Reloa= ding exchange rates from file currency.xml [junit4:junit4] 2> 10512 T1240 oass.FileExchangeRateProvider.reload Reloa= ding exchange rates from file currency.xml [junit4:junit4] 2> 10516 T1240 oass.OpenExchangeRatesOrgProvider.reload R= eloading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 10517 T1240 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Unknown key IMPORTANT NOTE [junit4:junit4] 2> 10517 T1240 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Expected key, got STRING [junit4:junit4] 2> 10517 T1240 oass.OpenExchangeRatesOrgProvider.reload R= eloading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 10518 T1240 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Unknown key IMPORTANT NOTE [junit4:junit4] 2> 10518 T1240 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Expected key, got STRING [junit4:junit4] 2> 10518 T1240 oasc.SolrCore.initDirectoryFactory org.apa= che.solr.core.MockDirectoryFactory [junit4:junit4] 2> 10518 T1240 oasc.SolrCore. [collection1] Opening= new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/bu= ild/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty= 2-1363871136348/collection1/, dataDir=3D./org.apache.solr.cloud.BasicDistri= butedZk2Test-1363871127344/jetty2/ [junit4:junit4] 2> 10519 T1240 oasc.JmxMonitoredMap. JMX monitoring= is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxM= BeanServer@558a7fb3 [junit4:junit4] 2> 10519 T1240 oasc.SolrCore.initDirectoryFactory org.apa= che.solr.core.MockDirectoryFactory [junit4:junit4] 2> 10519 T1240 oasc.CachingDirectoryFactory.get return ne= w directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-13638711273= 44/jetty2 forceNew: false [junit4:junit4] 2> 10519 T1240 oasc.SolrCore.getNewIndexDir New index dir= ectory detected: old=3Dnull new=3D./org.apache.solr.cloud.BasicDistributedZ= k2Test-1363871127344/jetty2/index/ [junit4:junit4] 2> 10520 T1240 oasc.SolrCore.initIndex WARNING [collectio= n1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1= 363871127344/jetty2/index' doesn't exist. Creating new index... [junit4:junit4] 2> 10520 T1240 oasc.CachingDirectoryFactory.get return ne= w directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-13638711273= 44/jetty2/index forceNew: false [junit4:junit4] 2> 10521 T1240 oasc.SolrDeletionPolicy.onCommit SolrDelet= ionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@22bd74fd lockFactory=3Dorg.apache.lucene.store.NativeFSLoc= kFactory@2b4418cc),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_= 1] [junit4:junit4] 2> 10521 T1240 oasc.SolrDeletionPolicy.updateCommits newe= st commit =3D 1[segments_1] [junit4:junit4] 2> 10523 T1240 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= dedupe" [junit4:junit4] 2> 10523 T1240 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= stored_sig" [junit4:junit4] 2> 10523 T1240 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= distrib-dup-test-chain-implicit" [junit4:junit4] 2> 10524 T1240 oasc.RequestHandlers.initHandlersFromConfi= g created standard: solr.StandardRequestHandler [junit4:junit4] 2> 10524 T1240 oasc.RequestHandlers.initHandlersFromConfi= g created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 10524 T1240 oasc.RequestHandlers.initHandlersFromConfi= g adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 10525 T1240 oasc.RequestHandlers.initHandlersFromConfi= g created /replication: solr.ReplicationHandler [junit4:junit4] 2> 10525 T1240 oasc.RequestHandlers.initHandlersFromConfi= g created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 10525 T1240 oasc.RequestHandlers.initHandlersFromConfi= g created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 10528 T1240 oashl.XMLLoader.init xsltCacheLifetimeSeco= nds=3D60 [junit4:junit4] 2> 10531 T1240 oass.SolrIndexSearcher. Opening Sear= cher@622d42c3 main [junit4:junit4] 2> 10531 T1240 oasu.UpdateHandler.clearLog Clearing tlog = files, tlogDir=3D./org.apache.solr.cloud.BasicDistributedZk2Test-1363871127= 344/jetty2/tlog [junit4:junit4] 2> 10532 T1240 oasu.CommitTracker. Hard AutoCommit:= disabled [junit4:junit4] 2> 10532 T1240 oasu.CommitTracker. Soft AutoCommit:= disabled [junit4:junit4] 2> 10537 T1241 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@622d42c3 main{StandardDirectoryReader(s= egments_1:1)} [junit4:junit4] 2> 10539 T1240 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Ddown [junit4:junit4] 2> 10539 T1240 oasc.ZkController.publish numShards not fo= und on descriptor - reading it from system property [junit4:junit4] 2> 11995 T1204 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 11996 T1204 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D2 message=3D{ [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:54146", [junit4:junit4] 2> =09 "numShards":"2", [junit4:junit4] 2> =09 "shard":null, [junit4:junit4] 2> =09 "node_name":"127.0.0.1:54146_", [junit4:junit4] 2> =09 "state":"down", [junit4:junit4] 2> =09 "core_node_name":null} [junit4:junit4] 2> 11996 T1204 oasc.Overseer$ClusterStateUpdater.updateSt= ate Collection already exists with numShards=3D2 [junit4:junit4] 2> 11996 T1204 oasc.Overseer$ClusterStateUpdater.updateSt= ate Assigning new node to shard shard=3Dshard2 [junit4:junit4] 2> 11999 T1223 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 11999 T1239 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 11999 T1203 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 11999 T1210 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 12540 T1240 oasc.CoreContainer.registerCore registerin= g core: collection1 [junit4:junit4] 2> 12541 T1240 oasc.ZkController.register Register replic= a - core:collection1 address:http://127.0.0.1:54146 collection:collection1 = shard:shard2 [junit4:junit4] 2> 12541 T1240 oascc.SolrZkClient.makePath makePath: /col= lections/collection1/leader_elect/shard2/election [junit4:junit4] 2> 12546 T1186 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d8d0dd7330008 type:de= lete cxid:0x49 zxid:0x7d txntype:-1 reqpath:n/a Error Path:/solr/collection= s/collection1/leaders/shard2 Error:KeeperErrorCode =3D NoNode for /solr/col= lections/collection1/leaders/shard2 [junit4:junit4] 2> 12546 T1240 oasc.ShardLeaderElectionContext.runLeaderP= rocess Running the leader process. [junit4:junit4] 2> 12547 T1186 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d8d0dd7330008 type:cr= eate cxid:0x4a zxid:0x7e txntype:-1 reqpath:n/a Error Path:/solr/overseer E= rror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 12548 T1240 oasc.ShardLeaderElectionContext.waitForRep= licasToComeUp Enough replicas found to continue. [junit4:junit4] 2> 12549 T1240 oasc.ShardLeaderElectionContext.runLeaderP= rocess I may be the new leader - try and sync [junit4:junit4] 2> 12549 T1240 oasc.SyncStrategy.sync Sync replicas to ht= tp://127.0.0.1:54146/collection1/ [junit4:junit4] 2> 12549 T1240 oasc.SyncStrategy.syncReplicas Sync Succes= s - now sync replicas to me [junit4:junit4] 2> 12549 T1240 oasc.SyncStrategy.syncToMe http://127.0.0.= 1:54146/collection1/ has no replicas [junit4:junit4] 2> 12549 T1240 oasc.ShardLeaderElectionContext.runLeaderP= rocess I am the new leader: http://127.0.0.1:54146/collection1/ [junit4:junit4] 2> 12550 T1240 oascc.SolrZkClient.makePath makePath: /col= lections/collection1/leaders/shard2 [junit4:junit4] 2> 12552 T1186 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d8d0dd7330008 type:cr= eate cxid:0x54 zxid:0x81 txntype:-1 reqpath:n/a Error Path:/solr/overseer E= rror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 13503 T1204 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 13510 T1239 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 13510 T1203 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 13510 T1223 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 13511 T1210 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 13556 T1240 oasc.ZkController.register We are http://1= 27.0.0.1:54146/collection1/ and leader is http://127.0.0.1:54146/collection= 1/ [junit4:junit4] 2> 13556 T1240 oasc.ZkController.register No LogReplay ne= eded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:54146 [junit4:junit4] 2> 13556 T1240 oasc.ZkController.checkRecovery I am the l= eader, no recovery necessary [junit4:junit4] 2> 13556 T1240 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Dactive [junit4:junit4] 2> 13557 T1240 oasc.ZkController.publish numShards not fo= und on descriptor - reading it from system property [junit4:junit4] 2> 13558 T1240 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 13559 T1181 oass.SolrDispatchFilter.init user.dir=3D/m= nt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/= J1 [junit4:junit4] 2> 13560 T1181 oass.SolrDispatchFilter.init SolrDispatchF= ilter.init() done [junit4:junit4] 2> 13560 T1181 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&f= ollowRedirects=3Dfalse [junit4:junit4] 2> 13616 T1181 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 13618 T1181 oejs.AbstractConnector.doStart Started Sel= ectChannelConnector@127.0.0.1:53442 [junit4:junit4] 2> 13619 T1181 oass.SolrDispatchFilter.init SolrDispatchF= ilter.init() [junit4:junit4] 2> 13619 T1181 oasc.SolrResourceLoader.locateSolrHome JND= I not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 13619 T1181 oasc.SolrResourceLoader.locateSolrHome usi= ng system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-t= runk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistri= butedZk2Test-jetty3-1363871140902 [junit4:junit4] 2> 13620 T1181 oasc.CoreContainer$Initializer.initialize = looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-= Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributed= Zk2Test-jetty3-1363871140902/solr.xml [junit4:junit4] 2> 13620 T1181 oasc.CoreContainer. New CoreContaine= r 684543628 [junit4:junit4] 2> 13620 T1181 oasc.CoreContainer.load Loading CoreContai= ner using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/so= lr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-= jetty3-1363871140902/' [junit4:junit4] 2> 13621 T1181 oasc.SolrResourceLoader. new SolrRes= ourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Li= nux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk= 2Test-jetty3-1363871140902/' [junit4:junit4] 2> 13637 T1181 oashc.HttpShardHandlerFactory.getParameter= Setting socketTimeout to: 120000 [junit4:junit4] 2> 13637 T1181 oashc.HttpShardHandlerFactory.getParameter= Setting urlScheme to: http:// [junit4:junit4] 2> 13638 T1181 oashc.HttpShardHandlerFactory.getParameter= Setting connTimeout to: 15000 [junit4:junit4] 2> 13638 T1181 oashc.HttpShardHandlerFactory.getParameter= Setting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 13638 T1181 oashc.HttpShardHandlerFactory.getParameter= Setting corePoolSize to: 0 [junit4:junit4] 2> 13638 T1181 oashc.HttpShardHandlerFactory.getParameter= Setting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 13639 T1181 oashc.HttpShardHandlerFactory.getParameter= Setting maxThreadIdleTime to: 5 [junit4:junit4] 2> 13639 T1181 oashc.HttpShardHandlerFactory.getParameter= Setting sizeOfQueue to: -1 [junit4:junit4] 2> 13639 T1181 oashc.HttpShardHandlerFactory.getParameter= Setting fairnessPolicy to: false [junit4:junit4] 2> 13639 T1181 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000= &socketTimeout=3D120000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 13645 T1181 oasc.CoreContainer.load Registering Log Li= stener [junit4:junit4] 2> 13653 T1181 oasc.CoreContainer.initZooKeeper Zookeeper= client=3D127.0.0.1:38096/solr [junit4:junit4] 2> 13653 T1181 oasc.ZkController.checkChrootPath zkHost i= ncludes chroot [junit4:junit4] 2> 13654 T1181 oaz.ZooKeeper. Initiating client con= nection, connectString=3D127.0.0.1:38096 sessionTimeout=3D60000 watcher=3Do= rg.apache.solr.common.cloud.ConnectionManager@74b889e4 [junit4:junit4] 2> 13654 T1181 oascc.ConnectionManager.waitForConnected W= aiting for client to connect to ZooKeeper [junit4:junit4] 2> 13655 T1252 oaz.ClientCnxn$SendThread.logStartConnect = Opening socket connection to server localhost.localdomain/127.0.0.1:38096. = Will not attempt to authenticate using SASL (access denied ("javax.security= .auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 2> 13655 T1252 oaz.ClientCnxn$SendThread.primeConnection = Socket connection established to localhost.localdomain/127.0.0.1:38096, ini= tiating session [junit4:junit4] 2> 13655 T1183 oazs.NIOServerCnxnFactory.run Accepted soc= ket connection from /127.0.0.1:51508 [junit4:junit4] 2> 13656 T1183 oazs.ZooKeeperServer.processConnectRequest= Client attempting to establish new session at /127.0.0.1:51508 [junit4:junit4] 2> 13657 T1185 oazs.ZooKeeperServer.finishSessionInit Est= ablished session 0x13d8d0dd7330009 with negotiated timeout 20000 for client= /127.0.0.1:51508 [junit4:junit4] 2> 13657 T1252 oaz.ClientCnxn$SendThread.onConnected Sess= ion establishment complete on server localhost.localdomain/127.0.0.1:38096,= sessionid =3D 0x13d8d0dd7330009, negotiated timeout =3D 20000 [junit4:junit4] 2> 13657 T1253 oascc.ConnectionManager.process Watcher or= g.apache.solr.common.cloud.ConnectionManager@74b889e4 name:ZooKeeperConnect= ion Watcher:127.0.0.1:38096 got event WatchedEvent state:SyncConnected type= :None path:null path:null type:None [junit4:junit4] 2> 13657 T1181 oascc.ConnectionManager.waitForConnected C= lient is connected to ZooKeeper [junit4:junit4] 2> 13658 T1186 oazs.PrepRequestProcessor.pRequest2Txn Pro= cessed session termination for sessionid: 0x13d8d0dd7330009 [junit4:junit4] 2> 13659 T1183 oazs.NIOServerCnxn.closeSock Closed socket= connection for client /127.0.0.1:51508 which had sessionid 0x13d8d0dd73300= 09 [junit4:junit4] 2> 13659 T1253 oaz.ClientCnxn$EventThread.run EventThread= shut down [junit4:junit4] 2> 13659 T1181 oaz.ZooKeeper.close Session: 0x13d8d0dd733= 0009 closed [junit4:junit4] 2> 13659 T1181 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&s= ocketTimeout=3D120000&connTimeout=3D15000 [junit4:junit4] 2> 13662 T1181 oaz.ZooKeeper. Initiating client con= nection, connectString=3D127.0.0.1:38096/solr sessionTimeout=3D30000 watche= r=3Dorg.apache.solr.common.cloud.ConnectionManager@4e1c538f [junit4:junit4] 2> 13662 T1181 oascc.ConnectionManager.waitForConnected W= aiting for client to connect to ZooKeeper [junit4:junit4] 2> 13662 T1254 oaz.ClientCnxn$SendThread.logStartConnect = Opening socket connection to server localhost.localdomain/127.0.0.1:38096. = Will not attempt to authenticate using SASL (access denied ("javax.security= .auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 2> 13663 T1254 oaz.ClientCnxn$SendThread.primeConnection = Socket connection established to localhost.localdomain/127.0.0.1:38096, ini= tiating session [junit4:junit4] 2> 13663 T1183 oazs.NIOServerCnxnFactory.run Accepted soc= ket connection from /127.0.0.1:51509 [junit4:junit4] 2> 13663 T1183 oazs.ZooKeeperServer.processConnectRequest= Client attempting to establish new session at /127.0.0.1:51509 [junit4:junit4] 2> 13664 T1185 oazs.ZooKeeperServer.finishSessionInit Est= ablished session 0x13d8d0dd733000a with negotiated timeout 20000 for client= /127.0.0.1:51509 [junit4:junit4] 2> 13664 T1254 oaz.ClientCnxn$SendThread.onConnected Sess= ion establishment complete on server localhost.localdomain/127.0.0.1:38096,= sessionid =3D 0x13d8d0dd733000a, negotiated timeout =3D 20000 [junit4:junit4] 2> 13664 T1255 oascc.ConnectionManager.process Watcher or= g.apache.solr.common.cloud.ConnectionManager@4e1c538f name:ZooKeeperConnect= ion Watcher:127.0.0.1:38096/solr got event WatchedEvent state:SyncConnected= type:None path:null path:null type:None [junit4:junit4] 2> 13664 T1181 oascc.ConnectionManager.waitForConnected C= lient is connected to ZooKeeper [junit4:junit4] 2> 13665 T1186 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d8d0dd733000a type:cr= eate cxid:0x1 zxid:0x8e txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 13666 T1186 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d8d0dd733000a type:cr= eate cxid:0x3 zxid:0x8f txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 13668 T1181 oascc.ZkStateReader.createClusterStateWatc= hersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 14670 T1181 oasc.ZkController.createEphemeralLiveNode = Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53442_ [junit4:junit4] 2> 14671 T1186 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d8d0dd733000a type:de= lete cxid:0xd zxid:0x90 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/= 127.0.0.1:53442_ Error:KeeperErrorCode =3D NoNode for /solr/live_nodes/127.= 0.0.1:53442_ [junit4:junit4] 2> 14671 T1181 oascc.SolrZkClient.makePath makePath: /liv= e_nodes/127.0.0.1:53442_ [junit4:junit4] 2> 14673 T1203 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 14674 T1210 oascc.ZkStateReader$3.process Updating liv= e nodes... (4) [junit4:junit4] 2> 14674 T1223 oascc.ZkStateReader$3.process Updating liv= e nodes... (4) [junit4:junit4] 2> 14674 T1210 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 14674 T1239 oascc.ZkStateReader$3.process Updating liv= e nodes... (4) [junit4:junit4] 2> 14674 T1239 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 14674 T1223 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 14674 T1255 oascc.ZkStateReader$3.process Updating liv= e nodes... (4) [junit4:junit4] 2> 14676 T1203 oascc.ZkStateReader$3.process Updating liv= e nodes... (4) [junit4:junit4] 2> 14680 T1256 oasc.CoreContainer.create Creating SolrCor= e 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-t= runk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistri= butedZk2Test-jetty3-1363871140902/collection1 [junit4:junit4] 2> 14680 T1256 oasc.ZkController.createCollectionZkNode C= heck for collection zkNode:collection1 [junit4:junit4] 2> 14680 T1256 oasc.ZkController.createCollectionZkNode C= ollection zkNode exists [junit4:junit4] 2> 14681 T1256 oasc.ZkController.readConfigName Load coll= ection config from:/collections/collection1 [junit4:junit4] 2> 14682 T1256 oasc.SolrResourceLoader. new SolrRes= ourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Li= nux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk= 2Test-jetty3-1363871140902/collection1/' [junit4:junit4] 2> 14682 T1256 oasc.SolrResourceLoader.replaceClassLoader= Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build= /solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-136= 3871140902/collection1/lib/README' to classloader [junit4:junit4] 2> 14682 T1256 oasc.SolrResourceLoader.replaceClassLoader= Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build= /solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-136= 3871140902/collection1/lib/classes/' to classloader [junit4:junit4] 2> 14702 T1256 oasc.SolrConfig. Using Lucene MatchV= ersion: LUCENE_50 [junit4:junit4] 2> 14736 T1256 oasc.SolrConfig. Loaded SolrConfig: = solrconfig.xml [junit4:junit4] 2> 14737 T1256 oass.IndexSchema.readSchema Reading Solr S= chema [junit4:junit4] 2> 14742 T1256 oass.IndexSchema.readSchema Schema name=3D= test [junit4:junit4] 2> 15015 T1204 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 15016 T1204 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D2 message=3D{ [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:54146", [junit4:junit4] 2> =09 "numShards":"2", [junit4:junit4] 2> =09 "shard":"shard2", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:54146_", [junit4:junit4] 2> =09 "state":"active", [junit4:junit4] 2> =09 "core_node_name":"127.0.0.1:54146__collection1"} [junit4:junit4] 2> 15019 T1239 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 15019 T1223 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 15019 T1210 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 15019 T1255 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 15019 T1203 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 15054 T1256 oass.OpenExchangeRatesOrgProvider.init Ini= tialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 15059 T1256 oass.IndexSchema.readSchema default search= field in schema is text [junit4:junit4] 2> 15061 T1256 oass.IndexSchema.readSchema unique key fie= ld: id [junit4:junit4] 2> 15069 T1256 oass.FileExchangeRateProvider.reload Reloa= ding exchange rates from file currency.xml [junit4:junit4] 2> 15072 T1256 oass.FileExchangeRateProvider.reload Reloa= ding exchange rates from file currency.xml [junit4:junit4] 2> 15075 T1256 oass.OpenExchangeRatesOrgProvider.reload R= eloading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 15075 T1256 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Unknown key IMPORTANT NOTE [junit4:junit4] 2> 15076 T1256 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Expected key, got STRING [junit4:junit4] 2> 15076 T1256 oass.OpenExchangeRatesOrgProvider.reload R= eloading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 15076 T1256 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Unknown key IMPORTANT NOTE [junit4:junit4] 2> 15077 T1256 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Expected key, got STRING [junit4:junit4] 2> 15077 T1256 oasc.SolrCore.initDirectoryFactory org.apa= che.solr.core.MockDirectoryFactory [junit4:junit4] 2> 15077 T1256 oasc.SolrCore. [collection1] Opening= new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/bu= ild/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty= 3-1363871140902/collection1/, dataDir=3D./org.apache.solr.cloud.BasicDistri= butedZk2Test-1363871127344/jetty3/ [junit4:junit4] 2> 15077 T1256 oasc.JmxMonitoredMap. JMX monitoring= is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxM= BeanServer@558a7fb3 [junit4:junit4] 2> 15078 T1256 oasc.SolrCore.initDirectoryFactory org.apa= che.solr.core.MockDirectoryFactory [junit4:junit4] 2> 15078 T1256 oasc.CachingDirectoryFactory.get return ne= w directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-13638711273= 44/jetty3 forceNew: false [junit4:junit4] 2> 15078 T1256 oasc.SolrCore.getNewIndexDir New index dir= ectory detected: old=3Dnull new=3D./org.apache.solr.cloud.BasicDistributedZ= k2Test-1363871127344/jetty3/index/ [junit4:junit4] 2> 15079 T1256 oasc.SolrCore.initIndex WARNING [collectio= n1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1= 363871127344/jetty3/index' doesn't exist. Creating new index... [junit4:junit4] 2> 15079 T1256 oasc.CachingDirectoryFactory.get return ne= w directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-13638711273= 44/jetty3/index forceNew: false [junit4:junit4] 2> 15080 T1256 oasc.SolrDeletionPolicy.onCommit SolrDelet= ionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@41bde33d lockFactory=3Dorg.apache.lucene.store.NativeFSLoc= kFactory@3f48b6a2),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_= 1] [junit4:junit4] 2> 15080 T1256 oasc.SolrDeletionPolicy.updateCommits newe= st commit =3D 1[segments_1] [junit4:junit4] 2> 15082 T1256 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= dedupe" [junit4:junit4] 2> 15082 T1256 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= stored_sig" [junit4:junit4] 2> 15083 T1256 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= distrib-dup-test-chain-implicit" [junit4:junit4] 2> 15083 T1256 oasc.RequestHandlers.initHandlersFromConfi= g created standard: solr.StandardRequestHandler [junit4:junit4] 2> 15084 T1256 oasc.RequestHandlers.initHandlersFromConfi= g created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 15084 T1256 oasc.RequestHandlers.initHandlersFromConfi= g adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 15084 T1256 oasc.RequestHandlers.initHandlersFromConfi= g created /replication: solr.ReplicationHandler [junit4:junit4] 2> 15085 T1256 oasc.RequestHandlers.initHandlersFromConfi= g created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 15085 T1256 oasc.RequestHandlers.initHandlersFromConfi= g created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 15088 T1256 oashl.XMLLoader.init xsltCacheLifetimeSeco= nds=3D60 [junit4:junit4] 2> 15090 T1256 oass.SolrIndexSearcher. Opening Sear= cher@548a997f main [junit4:junit4] 2> 15090 T1256 oasu.UpdateHandler.clearLog Clearing tlog = files, tlogDir=3D./org.apache.solr.cloud.BasicDistributedZk2Test-1363871127= 344/jetty3/tlog [junit4:junit4] 2> 15090 T1256 oasu.CommitTracker. Hard AutoCommit:= disabled [junit4:junit4] 2> 15091 T1256 oasu.CommitTracker. Soft AutoCommit:= disabled [junit4:junit4] 2> 15096 T1257 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@548a997f main{StandardDirectoryReader(s= egments_1:1)} [junit4:junit4] 2> 15098 T1256 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Ddown [junit4:junit4] 2> 15098 T1256 oasc.ZkController.publish numShards not fo= und on descriptor - reading it from system property [junit4:junit4] 2> 16523 T1204 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 16524 T1204 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D2 message=3D{ [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:53442", [junit4:junit4] 2> =09 "numShards":"2", [junit4:junit4] 2> =09 "shard":null, [junit4:junit4] 2> =09 "node_name":"127.0.0.1:53442_", [junit4:junit4] 2> =09 "state":"down", [junit4:junit4] 2> =09 "core_node_name":null} [junit4:junit4] 2> 16524 T1204 oasc.Overseer$ClusterStateUpdater.updateSt= ate Collection already exists with numShards=3D2 [junit4:junit4] 2> 16524 T1204 oasc.Overseer$ClusterStateUpdater.updateSt= ate Assigning new node to shard shard=3Dshard1 [junit4:junit4] 2> 16527 T1210 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 16527 T1223 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 16527 T1239 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 16527 T1255 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 16527 T1203 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 17100 T1256 oasc.CoreContainer.registerCore registerin= g core: collection1 [junit4:junit4] 2> 17100 T1256 oasc.ZkController.register Register replic= a - core:collection1 address:http://127.0.0.1:53442 collection:collection1 = shard:shard1 [junit4:junit4] 2> 17103 T1256 oasc.ZkController.register We are http://1= 27.0.0.1:53442/collection1/ and leader is http://127.0.0.1:55486/collection= 1/ [junit4:junit4] 2> 17103 T1256 oasc.ZkController.register No LogReplay ne= eded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:53442 [junit4:junit4] 2> 17103 T1256 oasc.ZkController.checkRecovery Core needs= to recover:collection1 [junit4:junit4] 2> 17104 T1256 oasu.DefaultSolrCoreState.doRecovery Runni= ng recovery - first canceling any ongoing recovery [junit4:junit4] 2> ASYNC NEW_CORE C97 name=3Dcollection1 org.apache.solr= .core.SolrCore@2a1ec980 url=3Dhttp://127.0.0.1:53442/collection1 node=3D127= .0.0.1:53442_ C97_STATE=3Dcoll:collection1 core:collection1 props:{core=3Dc= ollection1, collection=3Dcollection1, base_url=3Dhttp://127.0.0.1:53442, no= de_name=3D127.0.0.1:53442_, state=3Ddown} [junit4:junit4] 2> 17104 T1258 C97 P53442 oasc.RecoveryStrategy.run Start= ing recovery process. core=3Dcollection1 recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 17104 T1256 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 17105 T1258 C97 P53442 oasc.RecoveryStrategy.doRecover= y ###### startupVersions=3D[] [junit4:junit4] 2> 17105 T1258 C97 P53442 oasc.ZkController.publish publi= shing core=3Dcollection1 state=3Drecovering [junit4:junit4] 2> 17106 T1258 C97 P53442 oasc.ZkController.publish numSh= ards not found on descriptor - reading it from system property [junit4:junit4] 2> 17106 T1181 oass.SolrDispatchFilter.init user.dir=3D/m= nt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/= J1 [junit4:junit4] 2> 17106 T1258 C97 P53442 oascsi.HttpClientUtil.createCli= ent Creating new http client, config:maxConnections=3D128&maxConnectionsPer= Host=3D32&followRedirects=3Dfalse [junit4:junit4] 2> 17107 T1181 oass.SolrDispatchFilter.init SolrDispatchF= ilter.init() done [junit4:junit4] 2> 17107 T1181 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&f= ollowRedirects=3Dfalse [junit4:junit4] 2> 17169 T1181 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 17171 T1181 oejs.AbstractConnector.doStart Started Sel= ectChannelConnector@127.0.0.1:45797 [junit4:junit4] 2> 17172 T1181 oass.SolrDispatchFilter.init SolrDispatchF= ilter.init() [junit4:junit4] 2> 17172 T1181 oasc.SolrResourceLoader.locateSolrHome JND= I not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 17172 T1181 oasc.SolrResourceLoader.locateSolrHome usi= ng system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-t= runk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistri= butedZk2Test-jetty4-1363871144450 [junit4:junit4] 2> 17173 T1181 oasc.CoreContainer$Initializer.initialize = looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-= Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributed= Zk2Test-jetty4-1363871144450/solr.xml [junit4:junit4] 2> 17173 T1181 oasc.CoreContainer. New CoreContaine= r 1614171621 [junit4:junit4] 2> 17173 T1181 oasc.CoreContainer.load Loading CoreContai= ner using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/so= lr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-= jetty4-1363871144450/' [junit4:junit4] 2> 17173 T1181 oasc.SolrResourceLoader. new SolrRes= ourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Li= nux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk= 2Test-jetty4-1363871144450/' [junit4:junit4] 2> 17189 T1181 oashc.HttpShardHandlerFactory.getParameter= Setting socketTimeout to: 120000 [junit4:junit4] 2> 17190 T1181 oashc.HttpShardHandlerFactory.getParameter= Setting urlScheme to: http:// [junit4:junit4] 2> 17190 T1181 oashc.HttpShardHandlerFactory.getParameter= Setting connTimeout to: 15000 [junit4:junit4] 2> 17190 T1181 oashc.HttpShardHandlerFactory.getParameter= Setting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 17191 T1181 oashc.HttpShardHandlerFactory.getParameter= Setting corePoolSize to: 0 [junit4:junit4] 2> 17191 T1181 oashc.HttpShardHandlerFactory.getParameter= Setting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 17191 T1181 oashc.HttpShardHandlerFactory.getParameter= Setting maxThreadIdleTime to: 5 [junit4:junit4] 2> 17192 T1181 oashc.HttpShardHandlerFactory.getParameter= Setting sizeOfQueue to: -1 [junit4:junit4] 2> 17192 T1181 oashc.HttpShardHandlerFactory.getParameter= Setting fairnessPolicy to: false [junit4:junit4] 2> 17192 T1181 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000= &socketTimeout=3D120000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 17197 T1181 oasc.CoreContainer.load Registering Log Li= stener [junit4:junit4] 2> 17206 T1181 oasc.CoreContainer.initZooKeeper Zookeeper= client=3D127.0.0.1:38096/solr [junit4:junit4] 2> 17206 T1181 oasc.ZkController.checkChrootPath zkHost i= ncludes chroot [junit4:junit4] 2> 17206 T1181 oaz.ZooKeeper. Initiating client con= nection, connectString=3D127.0.0.1:38096 sessionTimeout=3D60000 watcher=3Do= rg.apache.solr.common.cloud.ConnectionManager@1280c5d3 [junit4:junit4] 2> 17207 T1181 oascc.ConnectionManager.waitForConnected W= aiting for client to connect to ZooKeeper [junit4:junit4] 2> 17208 T1269 oaz.ClientCnxn$SendThread.logStartConnect = Opening socket connection to server localhost.localdomain/127.0.0.1:38096. = Will not attempt to authenticate using SASL (access denied ("javax.security= .auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 2> 17208 T1269 oaz.ClientCnxn$SendThread.primeConnection = Socket connection established to localhost.localdomain/127.0.0.1:38096, ini= tiating session [junit4:junit4] 2> 17208 T1183 oazs.NIOServerCnxnFactory.run Accepted soc= ket connection from /127.0.0.1:51525 [junit4:junit4] 2> 17209 T1183 oazs.ZooKeeperServer.processConnectRequest= Client attempting to establish new session at /127.0.0.1:51525 [junit4:junit4] 2> 17209 T1185 oazs.ZooKeeperServer.finishSessionInit Est= ablished session 0x13d8d0dd733000b with negotiated timeout 20000 for client= /127.0.0.1:51525 [junit4:junit4] 2> 17209 T1269 oaz.ClientCnxn$SendThread.onConnected Sess= ion establishment complete on server localhost.localdomain/127.0.0.1:38096,= sessionid =3D 0x13d8d0dd733000b, negotiated timeout =3D 20000 [junit4:junit4] 2> 17209 T1270 oascc.ConnectionManager.process Watcher or= g.apache.solr.common.cloud.ConnectionManager@1280c5d3 name:ZooKeeperConnect= ion Watcher:127.0.0.1:38096 got event WatchedEvent state:SyncConnected type= :None path:null path:null type:None [junit4:junit4] 2> 17210 T1181 oascc.ConnectionManager.waitForConnected C= lient is connected to ZooKeeper [junit4:junit4] 2> 17211 T1186 oazs.PrepRequestProcessor.pRequest2Txn Pro= cessed session termination for sessionid: 0x13d8d0dd733000b [junit4:junit4] 2> 17211 T1183 oazs.NIOServerCnxn.closeSock Closed socket= connection for client /127.0.0.1:51525 which had sessionid 0x13d8d0dd73300= 0b [junit4:junit4] 2> 17211 T1181 oaz.ZooKeeper.close Session: 0x13d8d0dd733= 000b closed [junit4:junit4] 2> 17212 T1181 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&s= ocketTimeout=3D120000&connTimeout=3D15000 [junit4:junit4] 2> 17214 T1181 oaz.ZooKeeper. Initiating client con= nection, connectString=3D127.0.0.1:38096/solr sessionTimeout=3D30000 watche= r=3Dorg.apache.solr.common.cloud.ConnectionManager@21e870e4 [junit4:junit4] 2> 17214 T1270 oaz.ClientCnxn$EventThread.run EventThread= shut down [junit4:junit4] 2> 17215 T1181 oascc.ConnectionManager.waitForConnected W= aiting for client to connect to ZooKeeper [junit4:junit4] 2> 17215 T1271 oaz.ClientCnxn$SendThread.logStartConnect = Opening socket connection to server localhost.localdomain/127.0.0.1:38096. = Will not attempt to authenticate using SASL (access denied ("javax.security= .auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 2> 17215 T1271 oaz.ClientCnxn$SendThread.primeConnection = Socket connection established to localhost.localdomain/127.0.0.1:38096, ini= tiating session [junit4:junit4] 2> 17216 T1183 oazs.NIOServerCnxnFactory.run Accepted soc= ket connection from /127.0.0.1:51526 [junit4:junit4] 2> 17216 T1183 oazs.ZooKeeperServer.processConnectRequest= Client attempting to establish new session at /127.0.0.1:51526 [junit4:junit4] 2> 17216 T1185 oazs.ZooKeeperServer.finishSessionInit Est= ablished session 0x13d8d0dd733000c with negotiated timeout 20000 for client= /127.0.0.1:51526 [junit4:junit4] 2> 17216 T1271 oaz.ClientCnxn$SendThread.onConnected Sess= ion establishment complete on server localhost.localdomain/127.0.0.1:38096,= sessionid =3D 0x13d8d0dd733000c, negotiated timeout =3D 20000 [junit4:junit4] 2> 17217 T1272 oascc.ConnectionManager.process Watcher or= g.apache.solr.common.cloud.ConnectionManager@21e870e4 name:ZooKeeperConnect= ion Watcher:127.0.0.1:38096/solr got event WatchedEvent state:SyncConnected= type:None path:null path:null type:None [junit4:junit4] 2> 17217 T1181 oascc.ConnectionManager.waitForConnected C= lient is connected to ZooKeeper [junit4:junit4] 2> 17218 T1186 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d8d0dd733000c type:cr= eate cxid:0x1 zxid:0xa1 txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 17219 T1186 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d8d0dd733000c type:cr= eate cxid:0x3 zxid:0xa2 txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 17220 T1181 oascc.ZkStateReader.createClusterStateWatc= hersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 18034 T1204 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 18035 T1204 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D2 message=3D{ [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:53442", [junit4:junit4] 2> =09 "numShards":"2", [junit4:junit4] 2> =09 "shard":"shard1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:53442_", [junit4:junit4] 2> =09 "state":"recovering", [junit4:junit4] 2> =09 "core_node_name":"127.0.0.1:53442__collection1"} [junit4:junit4] 2> 18039 T1210 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 18039 T1223 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 18039 T1255 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 18040 T1203 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 18039 T1239 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 18039 T1272 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 18110 T1216 oass.SolrDispatchFilter.handleAdminRequest= /admin/cores {core=3Dcollection1&checkLive=3Dtrue&nodeName=3D127.0.0.1:534= 42_&version=3D2&onlyIfLeader=3Dtrue&wt=3Djavabin&action=3DPREPRECOVERY&core= NodeName=3D127.0.0.1:53442__collection1&state=3Drecovering} status=3D0 QTim= e=3D1000=20 [junit4:junit4] 2> 18222 T1181 oasc.ZkController.createEphemeralLiveNode = Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45797_ [junit4:junit4] 2> 18223 T1186 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d8d0dd733000c type:de= lete cxid:0xf zxid:0xa7 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/= 127.0.0.1:45797_ Error:KeeperErrorCode =3D NoNode for /solr/live_nodes/127.= 0.0.1:45797_ [junit4:junit4] 2> 18224 T1181 oascc.SolrZkClient.makePath makePath: /liv= e_nodes/127.0.0.1:45797_ [junit4:junit4] 2> 18225 T1203 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 18226 T1239 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 18226 T1210 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 18226 T1255 oascc.ZkStateReader$3.process Updating liv= e nodes... (5) [junit4:junit4] 2> 18226 T1255 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 18227 T1223 oascc.ZkStateReader$3.process Updating liv= e nodes... (5) [junit4:junit4] 2> 18227 T1223 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 18228 T1203 oascc.ZkStateReader$3.process Updating liv= e nodes... (5) [junit4:junit4] 2> 18228 T1272 oascc.ZkStateReader$3.process Updating liv= e nodes... (5) [junit4:junit4] 2> 18228 T1210 oascc.ZkStateReader$3.process Updating liv= e nodes... (5) [junit4:junit4] 2> 18228 T1239 oascc.ZkStateReader$3.process Updating liv= e nodes... (5) [junit4:junit4] 2> 18228 T1272 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 18232 T1273 oasc.CoreContainer.create Creating SolrCor= e 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-t= runk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistri= butedZk2Test-jetty4-1363871144450/collection1 [junit4:junit4] 2> 18233 T1273 oasc.ZkController.createCollectionZkNode C= heck for collection zkNode:collection1 [junit4:junit4] 2> 18233 T1273 oasc.ZkController.createCollectionZkNode C= ollection zkNode exists [junit4:junit4] 2> 18233 T1273 oasc.ZkController.readConfigName Load coll= ection config from:/collections/collection1 [junit4:junit4] 2> 18234 T1273 oasc.SolrResourceLoader. new SolrRes= ourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Li= nux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk= 2Test-jetty4-1363871144450/collection1/' [junit4:junit4] 2> 18235 T1273 oasc.SolrResourceLoader.replaceClassLoader= Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build= /solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-136= 3871144450/collection1/lib/README' to classloader [junit4:junit4] 2> 18235 T1273 oasc.SolrResourceLoader.replaceClassLoader= Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build= /solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-136= 3871144450/collection1/lib/classes/' to classloader [junit4:junit4] 2> 18255 T1273 oasc.SolrConfig. Using Lucene MatchV= ersion: LUCENE_50 [junit4:junit4] 2> 18281 T1273 oasc.SolrConfig. Loaded SolrConfig: = solrconfig.xml [junit4:junit4] 2> 18282 T1273 oass.IndexSchema.readSchema Reading Solr S= chema [junit4:junit4] 2> 18285 T1273 oass.IndexSchema.readSchema Schema name=3D= test [junit4:junit4] 2> 18566 T1273 oass.OpenExchangeRatesOrgProvider.init Ini= tialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 18571 T1273 oass.IndexSchema.readSchema default search= field in schema is text [junit4:junit4] 2> 18573 T1273 oass.IndexSchema.readSchema unique key fie= ld: id [junit4:junit4] 2> 18582 T1273 oass.FileExchangeRateProvider.reload Reloa= ding exchange rates from file currency.xml [junit4:junit4] 2> 18584 T1273 oass.FileExchangeRateProvider.reload Reloa= ding exchange rates from file currency.xml [junit4:junit4] 2> 18586 T1273 oass.OpenExchangeRatesOrgProvider.reload R= eloading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 18587 T1273 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Unknown key IMPORTANT NOTE [junit4:junit4] 2> 18587 T1273 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Expected key, got STRING [junit4:junit4] 2> 18587 T1273 oass.OpenExchangeRatesOrgProvider.reload R= eloading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 18588 T1273 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Unknown key IMPORTANT NOTE [junit4:junit4] 2> 18588 T1273 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Expected key, got STRING [junit4:junit4] 2> 18588 T1273 oasc.SolrCore.initDirectoryFactory org.apa= che.solr.core.MockDirectoryFactory [junit4:junit4] 2> 18589 T1273 oasc.SolrCore. [collection1] Opening= new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/bu= ild/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty= 4-1363871144450/collection1/, dataDir=3D./org.apache.solr.cloud.BasicDistri= butedZk2Test-1363871127344/jetty4/ [junit4:junit4] 2> 18589 T1273 oasc.JmxMonitoredMap. JMX monitoring= is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxM= BeanServer@558a7fb3 [junit4:junit4] 2> 18589 T1273 oasc.SolrCore.initDirectoryFactory org.apa= che.solr.core.MockDirectoryFactory [junit4:junit4] 2> 18590 T1273 oasc.CachingDirectoryFactory.get return ne= w directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-13638711273= 44/jetty4 forceNew: false [junit4:junit4] 2> 18590 T1273 oasc.SolrCore.getNewIndexDir New index dir= ectory detected: old=3Dnull new=3D./org.apache.solr.cloud.BasicDistributedZ= k2Test-1363871127344/jetty4/index/ [junit4:junit4] 2> 18590 T1273 oasc.SolrCore.initIndex WARNING [collectio= n1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1= 363871127344/jetty4/index' doesn't exist. Creating new index... [junit4:junit4] 2> 18590 T1273 oasc.CachingDirectoryFactory.get return ne= w directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-13638711273= 44/jetty4/index forceNew: false [junit4:junit4] 2> 18591 T1273 oasc.SolrDeletionPolicy.onCommit SolrDelet= ionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@e77cd12 lockFactory=3Dorg.apache.lucene.store.NativeFSLock= Factory@2d99e865),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1= ] [junit4:junit4] 2> 18591 T1273 oasc.SolrDeletionPolicy.updateCommits newe= st commit =3D 1[segments_1] [junit4:junit4] 2> 18593 T1273 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= dedupe" [junit4:junit4] 2> 18593 T1273 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= stored_sig" [junit4:junit4] 2> 18593 T1273 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= distrib-dup-test-chain-implicit" [junit4:junit4] 2> 18594 T1273 oasc.RequestHandlers.initHandlersFromConfi= g created standard: solr.StandardRequestHandler [junit4:junit4] 2> 18594 T1273 oasc.RequestHandlers.initHandlersFromConfi= g created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 18594 T1273 oasc.RequestHandlers.initHandlersFromConfi= g adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 18595 T1273 oasc.RequestHandlers.initHandlersFromConfi= g created /replication: solr.ReplicationHandler [junit4:junit4] 2> 18595 T1273 oasc.RequestHandlers.initHandlersFromConfi= g created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 18595 T1273 oasc.RequestHandlers.initHandlersFromConfi= g created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 18597 T1273 oashl.XMLLoader.init xsltCacheLifetimeSeco= nds=3D60 [junit4:junit4] 2> 18599 T1273 oass.SolrIndexSearcher. Opening Sear= cher@598cd7eb main [junit4:junit4] 2> 18599 T1273 oasu.UpdateHandler.clearLog Clearing tlog = files, tlogDir=3D./org.apache.solr.cloud.BasicDistributedZk2Test-1363871127= 344/jetty4/tlog [junit4:junit4] 2> 18600 T1273 oasu.CommitTracker. Hard AutoCommit:= disabled [junit4:junit4] 2> 18600 T1273 oasu.CommitTracker. Soft AutoCommit:= disabled [junit4:junit4] 2> 18603 T1274 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@598cd7eb main{StandardDirectoryReader(s= egments_1:1)} [junit4:junit4] 2> 18605 T1273 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Ddown [junit4:junit4] 2> 18605 T1273 oasc.ZkController.publish numShards not fo= und on descriptor - reading it from system property [junit4:junit4] 2> 19543 T1204 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 19544 T1204 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D2 message=3D{ [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:45797", [junit4:junit4] 2> =09 "numShards":"2", [junit4:junit4] 2> =09 "shard":null, [junit4:junit4] 2> =09 "node_name":"127.0.0.1:45797_", [junit4:junit4] 2> =09 "state":"down", [junit4:junit4] 2> =09 "core_node_name":null} [junit4:junit4] 2> 19544 T1204 oasc.Overseer$ClusterStateUpdater.updateSt= ate Collection already exists with numShards=3D2 [junit4:junit4] 2> 19544 T1204 oasc.Overseer$ClusterStateUpdater.updateSt= ate Assigning new node to shard shard=3Dshard2 [junit4:junit4] 2> 19548 T1210 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 19548 T1255 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 19548 T1203 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 19548 T1272 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 19548 T1239 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 19548 T1223 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 19607 T1273 oasc.CoreContainer.registerCore registerin= g core: collection1 [junit4:junit4] 2> 19608 T1273 oasc.ZkController.register Register replic= a - core:collection1 address:http://127.0.0.1:45797 collection:collection1 = shard:shard2 [junit4:junit4] 2> 19611 T1273 oasc.ZkController.register We are http://1= 27.0.0.1:45797/collection1/ and leader is http://127.0.0.1:54146/collection= 1/ [junit4:junit4] 2> 19611 T1273 oasc.ZkController.register No LogReplay ne= eded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:45797 [junit4:junit4] 2> 19611 T1273 oasc.ZkController.checkRecovery Core needs= to recover:collection1 [junit4:junit4] 2> 19611 T1273 oasu.DefaultSolrCoreState.doRecovery Runni= ng recovery - first canceling any ongoing recovery [junit4:junit4] 2> ASYNC NEW_CORE C98 name=3Dcollection1 org.apache.solr= .core.SolrCore@5d108816 url=3Dhttp://127.0.0.1:45797/collection1 node=3D127= .0.0.1:45797_ C98_STATE=3Dcoll:collection1 core:collection1 props:{core=3Dc= ollection1, collection=3Dcollection1, base_url=3Dhttp://127.0.0.1:45797, no= de_name=3D127.0.0.1:45797_, state=3Ddown} [junit4:junit4] 2> 19612 T1275 C98 P45797 oasc.RecoveryStrategy.run Start= ing recovery process. core=3Dcollection1 recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 19612 T1275 C98 P45797 oasc.RecoveryStrategy.doRecover= y ###### startupVersions=3D[] [junit4:junit4] 2> 19613 T1275 C98 P45797 oasc.ZkController.publish publi= shing core=3Dcollection1 state=3Drecovering [junit4:junit4] 2> 19613 T1273 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 19613 T1275 C98 P45797 oasc.ZkController.publish numSh= ards not found on descriptor - reading it from system property [junit4:junit4] 2> 19614 T1275 C98 P45797 oascsi.HttpClientUtil.createCli= ent Creating new http client, config:maxConnections=3D128&maxConnectionsPer= Host=3D32&followRedirects=3Dfalse [junit4:junit4] 2> 19614 T1181 oass.SolrDispatchFilter.init user.dir=3D/m= nt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/= J1 [junit4:junit4] 2> 19614 T1181 oass.SolrDispatchFilter.init SolrDispatchF= ilter.init() done [junit4:junit4] 2> 19615 T1181 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&f= ollowRedirects=3Dfalse [junit4:junit4] 2> 19619 T1181 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 19620 T1181 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&f= ollowRedirects=3Dfalse [junit4:junit4] 2> 19625 T1219 oasc.CoreContainer.create Creating SolrCor= e 'onenodecollectioncore' using instanceDir: /mnt/ssd/jenkins/workspace/Luc= ene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.B= asicDistributedZk2Test-jetty1-1363871131600/onenodecollectioncore [junit4:junit4] 2> 19626 T1219 oasc.ZkController.createCollectionZkNode C= heck for collection zkNode:onenodecollection [junit4:junit4] 2> 19627 T1219 oasc.ZkController.createCollectionZkNode C= reating collection in ZooKeeper:onenodecollection [junit4:junit4] 2> 19627 T1219 oasc.ZkController.getConfName Looking for = collection configName [junit4:junit4] 2> 19628 T1219 oasc.ZkController.getConfName Only one con= fig set found in zk - using it:conf1 [junit4:junit4] 2> 19628 T1219 oascc.SolrZkClient.makePath makePath: /col= lections/onenodecollection [junit4:junit4] 2> 19630 T1219 oasc.ZkController.readConfigName Load coll= ection config from:/collections/onenodecollection [junit4:junit4] 2> 19632 T1219 oasc.SolrResourceLoader. new SolrRes= ourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Li= nux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk= 2Test-jetty1-1363871131600/onenodecollectioncore/' [junit4:junit4] 2> 19673 T1219 oasc.SolrConfig. Using Lucene MatchV= ersion: LUCENE_50 [junit4:junit4] 2> 19720 T1219 oasc.SolrConfig. Loaded SolrConfig: = solrconfig.xml [junit4:junit4] 2> 19721 T1219 oass.IndexSchema.readSchema Reading Solr S= chema [junit4:junit4] 2> 19727 T1219 oass.IndexSchema.readSchema Schema name=3D= test [junit4:junit4] 2> 20094 T1219 oass.OpenExchangeRatesOrgProvider.init Ini= tialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 20099 T1219 oass.IndexSchema.readSchema default search= field in schema is text [junit4:junit4] 2> 20101 T1219 oass.IndexSchema.readSchema unique key fie= ld: id [junit4:junit4] 2> C97_STATE=3Dcoll:collection1 core:collection1 props:{= core=3Dcollection1, collection=3Dcollection1, base_url=3Dhttp://127.0.0.1:5= 3442, shard=3Dshard1, node_name=3D127.0.0.1:53442_, state=3Drecovering} [junit4:junit4] 2> 20111 T1258 C97 P53442 oasc.RecoveryStrategy.doRecover= y Attempting to PeerSync from http://127.0.0.1:55486/collection1/ core=3Dco= llection1 - recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 20111 T1258 C97 P53442 oasu.PeerSync.sync PeerSync: co= re=3Dcollection1 url=3Dhttp://127.0.0.1:53442 START replicas=3D[http://127.= 0.0.1:55486/collection1/] nUpdates=3D100 [junit4:junit4] 2> 20111 T1219 oass.FileExchangeRateProvider.reload Reloa= ding exchange rates from file currency.xml [junit4:junit4] 2> 20112 T1258 C97 P53442 oasu.PeerSync.sync WARNING no f= rame of reference to tell of we've missed updates [junit4:junit4] 2> 20112 T1258 C97 P53442 oasc.RecoveryStrategy.doRecover= y PeerSync Recovery was not successful - trying replication. core=3Dcollect= ion1 [junit4:junit4] 2> 20112 T1258 C97 P53442 oasc.RecoveryStrategy.doRecover= y Starting Replication Recovery. core=3Dcollection1 [junit4:junit4] 2> 20112 T1258 C97 P53442 oasc.RecoveryStrategy.doRecover= y Begin buffering updates. core=3Dcollection1 [junit4:junit4] 2> 20112 T1258 C97 P53442 oasu.UpdateLog.bufferUpdates St= arting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog=3Dnull} [junit4:junit4] 2> 20113 T1258 C97 P53442 oasc.RecoveryStrategy.replicate= Attempting to replicate from http://127.0.0.1:55486/collection1/. core=3Dc= ollection1 [junit4:junit4] 2> 20113 T1258 C97 P53442 oascsi.HttpClientUtil.createCli= ent Creating new http client, config:maxConnections=3D128&maxConnectionsPer= Host=3D32&followRedirects=3Dfalse [junit4:junit4] 2> 20116 T1219 oass.FileExchangeRateProvider.reload Reloa= ding exchange rates from file currency.xml [junit4:junit4] 2> ASYNC NEW_CORE C99 name=3Dcollection1 org.apache.solr= .core.SolrCore@32e29dd2 url=3Dhttp://127.0.0.1:55486/collection1 node=3D127= .0.0.1:55486_ C99_STATE=3Dcoll:collection1 core:collection1 props:{core=3Dc= ollection1, collection=3Dcollection1, base_url=3Dhttp://127.0.0.1:55486, sh= ard=3Dshard1, node_name=3D127.0.0.1:55486_, state=3Dactive, leader=3Dtrue} [junit4:junit4] 2> 20118 T1216 C99 P55486 oasu.DirectUpdateHandler2.commi= t start commit{,optimize=3Dfalse,openSearcher=3Dfalse,waitSearcher=3Dtrue,e= xpungeDeletes=3Dfalse,softCommit=3Dfalse,prepareCommit=3Dfalse} [junit4:junit4] 2> 20119 T1217 C99 P55486 REQ /get {qt=3D/get&distrib=3Df= alse&version=3D2&getVersions=3D100&wt=3Djavabin} status=3D0 QTime=3D2=20 [junit4:junit4] 2> 20120 T1216 C99 P55486 oasc.SolrDeletionPolicy.onInit = SolrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@481f34e6 lockFactory=3Dorg.apache.lucene.store.NativeFSLoc= kFactory@67aadddc),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_= 1] [junit4:junit4] 2> 20121 T1219 oass.OpenExchangeRatesOrgProvider.reload R= eloading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 20121 T1216 C99 P55486 oasc.SolrDeletionPolicy.updateC= ommits newest commit =3D 1[segments_1] [junit4:junit4] 2> 20122 T1216 C99 P55486 oasc.SolrDeletionPolicy.onCommi= t SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@481f34e6 lockFactory=3Dorg.apache.lucene.store.NativeFSLoc= kFactory@67aadddc),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_= 1] [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@481f34e6 lockFactory=3Dorg.apache.lucene.store.NativeFSLoc= kFactory@67aadddc),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_= 2] [junit4:junit4] 2> 20122 T1219 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Unknown key IMPORTANT NOTE [junit4:junit4] 2> 20122 T1216 C99 P55486 oasc.SolrDeletionPolicy.updateC= ommits newest commit =3D 2[segments_2] [junit4:junit4] 2> 20122 T1219 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Expected key, got STRING [junit4:junit4] 2> 20123 T1216 C99 P55486 oass.SolrIndexSearcher. O= pening Searcher@2f317fc3 realtime [junit4:junit4] 2> 20123 T1219 oass.OpenExchangeRatesOrgProvider.reload R= eloading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 20123 T1216 C99 P55486 oasu.DirectUpdateHandler2.commi= t end_commit_flush [junit4:junit4] 2> 20123 T1216 C99 P55486 /update {waitSearcher=3Dtrue&ve= rsion=3D2&commit_end_point=3Dtrue&wt=3Djavabin&openSearcher=3Dfalse&commit= =3Dtrue&softCommit=3Dfalse} {commit=3D} 0 5 [junit4:junit4] 2> 20124 T1258 C97 P53442 oash.ReplicationHandler.inform = Commits will be reserved for 10000 [junit4:junit4] 2> 20124 T1258 C97 P53442 oash.SnapPuller. No valu= e set for 'pollInterval'. Timer Task not started. [junit4:junit4] 2> 20125 T1219 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Unknown key IMPORTANT NOTE [junit4:junit4] 2> 20125 T1219 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Expected key, got STRING [junit4:junit4] 2> 20126 T1219 oasc.SolrCore.initDirectoryFactory org.apa= che.solr.core.MockDirectoryFactory [junit4:junit4] 2> 20126 T1219 oasc.SolrCore. [onenodecollectioncor= e] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Lin= ux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2= Test-jetty1-1363871131600/onenodecollectioncore/, dataDir=3D/mnt/ssd/jenkin= s/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest= -BasicDistributedZk2Test-1363871127344/onenodecollection/ [junit4:junit4] 2> 20127 T1219 oasc.JmxMonitoredMap. JMX monitoring= is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxM= BeanServer@558a7fb3 [junit4:junit4] 2> 20128 T1219 oasc.SolrCore.initDirectoryFactory org.apa= che.solr.core.MockDirectoryFactory [junit4:junit4] 2> 20129 T1219 oasc.CachingDirectoryFactory.get return ne= w directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/bui= ld/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1363871127344/oneno= decollection forceNew: false [junit4:junit4] 2> 20129 T1219 oasc.SolrCore.getNewIndexDir New index dir= ectory detected: old=3Dnull new=3D/mnt/ssd/jenkins/workspace/Lucene-Solr-tr= unk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1= 363871127344/onenodecollection/index/ [junit4:junit4] 2> 20130 T1218 C99 P55486 oash.ReplicationHandler.inform = Commits will be reserved for 10000 [junit4:junit4] 2> 20130 T1219 oasc.SolrCore.initIndex WARNING [onenodeco= llectioncore] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-= trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test= -1363871127344/onenodecollection/index' doesn't exist. Creating new index..= . [junit4:junit4] 2> 20130 T1218 C99 P55486 REQ /replication {qt=3D/replica= tion&version=3D2&command=3Dindexversion&wt=3Djavabin} status=3D0 QTime=3D5= =20 [junit4:junit4] 2> 20130 T1219 oasc.CachingDirectoryFactory.get return ne= w directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/bui= ld/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1363871127344/oneno= decollection/index forceNew: false [junit4:junit4] 2> 20131 T1258 C97 P53442 oash.SnapPuller.fetchLatestInde= x Master's generation: 2 [junit4:junit4] 2> 20131 T1258 C97 P53442 oash.SnapPuller.fetchLatestInde= x Slave's generation: 1 [junit4:junit4] 2> 20131 T1258 C97 P53442 oash.SnapPuller.fetchLatestInde= x Starting replication process [junit4:junit4] 2> 20132 T1219 oasc.SolrDeletionPolicy.onCommit SolrDelet= ionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@108bc8fe lockFactory=3Dorg.apache.lucene.store.NativeFSLoc= kFactory@2830e1f9),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_= 1] [junit4:junit4] 2> 20132 T1219 oasc.SolrDeletionPolicy.updateCommits newe= st commit =3D 1[segments_1] [junit4:junit4] 2> 20133 T1216 C99 P55486 REQ /replication {qt=3D/replica= tion&generation=3D2&version=3D2&command=3Dfilelist&wt=3Djavabin} status=3D0= QTime=3D0=20 [junit4:junit4] 2> 20134 T1258 C97 P53442 oash.SnapPuller.fetchLatestInde= x Number of files in latest index in master: 1 [junit4:junit4] 2> 20135 T1258 C97 P53442 oasc.CachingDirectoryFactory.ge= t return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-= 1363871127344/jetty3/index.20130321060547474 forceNew: false [junit4:junit4] 2> 20135 T1219 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= dedupe" [junit4:junit4] 2> 20135 T1258 C97 P53442 oash.SnapPuller.fetchLatestInde= x Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@= 151546c2 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@e396b04)= fullCopy=3Dfalse [junit4:junit4] 2> 20135 T1219 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= stored_sig" [junit4:junit4] 2> 20136 T1219 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= distrib-dup-test-chain-implicit" [junit4:junit4] 2> 20136 T1219 oasc.RequestHandlers.initHandlersFromConfi= g created standard: solr.StandardRequestHandler [junit4:junit4] 2> 20137 T1219 oasc.RequestHandlers.initHandlersFromConfi= g created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 20137 T1219 oasc.RequestHandlers.initHandlersFromConfi= g adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 20137 T1217 C99 P55486 REQ /replication {file=3Dsegmen= ts_2&qt=3D/replication&checksum=3Dtrue&generation=3D2&command=3Dfilecontent= &wt=3Dfilestream} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 20137 T1219 oasc.RequestHandlers.initHandlersFromConfi= g created /replication: solr.ReplicationHandler [junit4:junit4] 2> 20138 T1219 oasc.RequestHandlers.initHandlersFromConfi= g created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 20138 T1258 C97 P53442 oash.SnapPuller.fetchLatestInde= x Total time taken for download : 0 secs [junit4:junit4] 2> 20138 T1219 oasc.RequestHandlers.initHandlersFromConfi= g created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 20139 T1258 C97 P53442 oasu.DefaultSolrCoreState.newIn= dexWriter Creating new IndexWriter... [junit4:junit4] 2> 20140 T1258 C97 P53442 oasu.DefaultSolrCoreState.newIn= dexWriter Waiting until IndexWriter is unused... core=3Dcollection1 [junit4:junit4] 2> 20141 T1258 C97 P53442 oasc.SolrDeletionPolicy.onInit = SolrDeletionPolicy.onInit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@41bde33d lockFactory=3Dorg.apache.lucene.store.NativeFSLoc= kFactory@3f48b6a2),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_= 1] [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@41bde33d lockFactory=3Dorg.apache.lucene.store.NativeFSLoc= kFactory@3f48b6a2),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_= 2] [junit4:junit4] 2> 20141 T1258 C97 P53442 oasc.SolrDeletionPolicy.updateC= ommits newest commit =3D 2[segments_2] [junit4:junit4] 2> 20142 T1258 C97 P53442 oasu.DefaultSolrCoreState.newIn= dexWriter New IndexWriter is ready to be used. [junit4:junit4] 2> 20142 T1258 C97 P53442 oass.SolrIndexSearcher. O= pening Searcher@710e2be3 main [junit4:junit4] 2> 20142 T1219 oashl.XMLLoader.init xsltCacheLifetimeSeco= nds=3D60 [junit4:junit4] 2> 20143 T1257 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@710e2be3 main{StandardDirectoryReader(s= egments_2:1:nrt)} [junit4:junit4] 2> 20143 T1258 C97 P53442 oasc.RecoveryStrategy.replay No= replay needed. core=3Dcollection1 [junit4:junit4] 2> 20143 T1258 C97 P53442 oasc.RecoveryStrategy.doRecover= y Replication Recovery was successful - registering as Active. core=3Dcolle= ction1 [junit4:junit4] 2> 20144 T1258 C97 P53442 oasc.ZkController.publish publi= shing core=3Dcollection1 state=3Dactive [junit4:junit4] 2> 20144 T1258 C97 P53442 oasc.ZkController.publish numSh= ards not found on descriptor - reading it from system property [junit4:junit4] 2> 20145 T1258 C97 P53442 oasc.RecoveryStrategy.doRecover= y Finished recovery process. core=3Dcollection1 [junit4:junit4] 2> 20145 T1219 oass.SolrIndexSearcher. Opening Sear= cher@3043fa0a main [junit4:junit4] 2> 20146 T1219 oasu.UpdateHandler.clearLog Clearing tlog = files, tlogDir=3D/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/bu= ild/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1363871127344/onen= odecollection/tlog [junit4:junit4] 2> 20146 T1219 oasu.CommitTracker. Hard AutoCommit:= disabled [junit4:junit4] 2> 20147 T1219 oasu.CommitTracker. Soft AutoCommit:= disabled [junit4:junit4] 2> 20150 T1279 oasc.SolrCore.registerSearcher [onenodecol= lectioncore] Registered new searcher Searcher@3043fa0a main{StandardDirecto= ryReader(segments_1:1)} [junit4:junit4] 2> 20152 T1219 oasc.ZkController.publish publishing core= =3Donenodecollectioncore state=3Ddown [junit4:junit4] 2> 21052 T1204 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 21053 T1204 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D2 message=3D{ [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:45797", [junit4:junit4] 2> =09 "numShards":"2", [junit4:junit4] 2> =09 "shard":"shard2", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:45797_", [junit4:junit4] 2> =09 "state":"recovering", [junit4:junit4] 2> =09 "core_node_name":"127.0.0.1:45797__collection1"} [junit4:junit4] 2> 21055 T1204 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D2 message=3D{ [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:53442", [junit4:junit4] 2> =09 "numShards":"2", [junit4:junit4] 2> =09 "shard":"shard1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:53442_", [junit4:junit4] 2> =09 "state":"active", [junit4:junit4] 2> =09 "core_node_name":"127.0.0.1:53442__collection1"} [junit4:junit4] 2> 21058 T1204 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "core":"onenodecollectioncore", [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "roles":"none", [junit4:junit4] 2> =09 "collection":"onenodecollection", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:55486", [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "shard":null, [junit4:junit4] 2> =09 "node_name":"127.0.0.1:55486_", [junit4:junit4] 2> =09 "state":"down", [junit4:junit4] 2> =09 "core_node_name":null} [junit4:junit4] 2> 21058 T1204 oasc.Overseer$ClusterStateUpdater.createCo= llection Create collection onenodecollection with numShards 1 [junit4:junit4] 2> 21058 T1204 oasc.Overseer$ClusterStateUpdater.updateSt= ate Assigning new node to shard shard=3Dshard1 [junit4:junit4] 2> 21062 T1210 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 21062 T1272 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 21062 T1223 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 21062 T1255 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 21062 T1239 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 21063 T1203 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 21154 T1219 oasc.CoreContainer.registerCore registerin= g core: onenodecollectioncore [junit4:junit4] 2> 21154 T1219 oasc.ZkController.register Register replic= a - core:onenodecollectioncore address:http://127.0.0.1:55486 collection:on= enodecollection shard:shard1 [junit4:junit4] 2> 21155 T1219 oascc.SolrZkClient.makePath makePath: /col= lections/onenodecollection/leader_elect/shard1/election [junit4:junit4] 2> 21161 T1186 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d8d0dd7330006 type:de= lete cxid:0xac zxid:0xc2 txntype:-1 reqpath:n/a Error Path:/solr/collection= s/onenodecollection/leaders Error:KeeperErrorCode =3D NoNode for /solr/coll= ections/onenodecollection/leaders [junit4:junit4] 2> 21161 T1219 oasc.ShardLeaderElectionContext.runLeaderP= rocess Running the leader process. [junit4:junit4] 2> 21162 T1186 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d8d0dd7330006 type:cr= eate cxid:0xad zxid:0xc3 txntype:-1 reqpath:n/a Error Path:/solr/overseer E= rror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 21164 T1219 oasc.ShardLeaderElectionContext.waitForRep= licasToComeUp Enough replicas found to continue. [junit4:junit4] 2> 21164 T1219 oasc.ShardLeaderElectionContext.runLeaderP= rocess I may be the new leader - try and sync [junit4:junit4] 2> 21164 T1219 oasc.SyncStrategy.sync Sync replicas to ht= tp://127.0.0.1:55486/onenodecollectioncore/ [junit4:junit4] 2> 21165 T1219 oasc.SyncStrategy.syncReplicas Sync Succes= s - now sync replicas to me [junit4:junit4] 2> 21165 T1219 oasc.SyncStrategy.syncToMe http://127.0.0.= 1:55486/onenodecollectioncore/ has no replicas [junit4:junit4] 2> 21165 T1219 oasc.ShardLeaderElectionContext.runLeaderP= rocess I am the new leader: http://127.0.0.1:55486/onenodecollectioncore/ [junit4:junit4] 2> 21166 T1219 oascc.SolrZkClient.makePath makePath: /col= lections/onenodecollection/leaders/shard1 [junit4:junit4] 2> 21168 T1186 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d8d0dd7330006 type:cr= eate cxid:0xb8 zxid:0xc7 txntype:-1 reqpath:n/a Error Path:/solr/overseer E= rror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 21620 T1232 oass.SolrDispatchFilter.handleAdminRequest= /admin/cores {core=3Dcollection1&checkLive=3Dtrue&nodeName=3D127.0.0.1:457= 97_&version=3D2&onlyIfLeader=3Dtrue&wt=3Djavabin&action=3DPREPRECOVERY&core= NodeName=3D127.0.0.1:45797__collection1&state=3Drecovering} status=3D0 QTim= e=3D2001=20 [junit4:junit4] 2> 22569 T1204 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 22575 T1255 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 22575 T1239 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 22575 T1210 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 22575 T1223 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 22575 T1203 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 22575 T1272 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 22624 T1219 oasc.ZkController.register We are http://1= 27.0.0.1:55486/onenodecollectioncore/ and leader is http://127.0.0.1:55486/= onenodecollectioncore/ [junit4:junit4] 2> 22624 T1219 oasc.ZkController.register No LogReplay ne= eded for core=3Donenodecollectioncore baseURL=3Dhttp://127.0.0.1:55486 [junit4:junit4] 2> 22624 T1219 oasc.ZkController.checkRecovery I am the l= eader, no recovery necessary [junit4:junit4] 2> 22624 T1219 oasc.ZkController.publish publishing core= =3Donenodecollectioncore state=3Dactive [junit4:junit4] 2> 22626 T1219 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 22627 T1219 oass.SolrDispatchFilter.handleAdminRequest= /admin/cores {dataDir=3D/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux= /solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1363871127= 344/onenodecollection&version=3D2&name=3Donenodecollectioncore&roles=3Dnone= &collection=3Donenodecollection&wt=3Djavabin&action=3DCREATE&numShards=3D1}= status=3D0 QTime=3D3002=20 [junit4:junit4] 2> 22627 T1181 oasc.AbstractDistribZkTestBase.waitForReco= veriesToFinish Wait for recoveries to finish - collection: onenodecollectio= n failOnTimeout:true timeout (sec):230 [junit4:junit4] 2> 22628 T1181 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> C98_STATE=3Dcoll:collection1 core:collection1 props:{= core=3Dcollection1, collection=3Dcollection1, base_url=3Dhttp://127.0.0.1:4= 5797, shard=3Dshard2, node_name=3D127.0.0.1:45797_, state=3Drecovering} [junit4:junit4] 2> 23621 T1275 C98 P45797 oasc.RecoveryStrategy.doRecover= y Attempting to PeerSync from http://127.0.0.1:54146/collection1/ core=3Dco= llection1 - recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 23621 T1275 C98 P45797 oasu.PeerSync.sync PeerSync: co= re=3Dcollection1 url=3Dhttp://127.0.0.1:45797 START replicas=3D[http://127.= 0.0.1:54146/collection1/] nUpdates=3D100 [junit4:junit4] 2> 23622 T1275 C98 P45797 oasu.PeerSync.sync WARNING no f= rame of reference to tell of we've missed updates [junit4:junit4] 2> 23622 T1275 C98 P45797 oasc.RecoveryStrategy.doRecover= y PeerSync Recovery was not successful - trying replication. core=3Dcollect= ion1 [junit4:junit4] 2> 23622 T1275 C98 P45797 oasc.RecoveryStrategy.doRecover= y Starting Replication Recovery. core=3Dcollection1 [junit4:junit4] 2> 23622 T1275 C98 P45797 oasc.RecoveryStrategy.doRecover= y Begin buffering updates. core=3Dcollection1 [junit4:junit4] 2> 23622 T1275 C98 P45797 oasu.UpdateLog.bufferUpdates St= arting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog=3Dnull} [junit4:junit4] 2> 23623 T1275 C98 P45797 oasc.RecoveryStrategy.replicate= Attempting to replicate from http://127.0.0.1:54146/collection1/. core=3Dc= ollection1 [junit4:junit4] 2> 23623 T1275 C98 P45797 oascsi.HttpClientUtil.createCli= ent Creating new http client, config:maxConnections=3D128&maxConnectionsPer= Host=3D32&followRedirects=3Dfalse [junit4:junit4] 2> ASYNC NEW_CORE C100 name=3Dcollection1 org.apache.sol= r.core.SolrCore@1ce040ea url=3Dhttp://127.0.0.1:54146/collection1 node=3D12= 7.0.0.1:54146_ C100_STATE=3Dcoll:collection1 core:collection1 props:{core= =3Dcollection1, collection=3Dcollection1, base_url=3Dhttp://127.0.0.1:54146= , shard=3Dshard2, node_name=3D127.0.0.1:54146_, state=3Dactive, leader=3Dtr= ue} [junit4:junit4] 2> 23627 T1235 C100 P54146 REQ /get {qt=3D/get&distrib=3D= false&version=3D2&getVersions=3D100&wt=3Djavabin} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 23628 T1233 C100 P54146 oasu.DirectUpdateHandler2.comm= it start commit{,optimize=3Dfalse,openSearcher=3Dfalse,waitSearcher=3Dtrue,= expungeDeletes=3Dfalse,softCommit=3Dfalse,prepareCommit=3Dfalse} [junit4:junit4] 2> 23629 T1181 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 23631 T1233 C100 P54146 oasc.SolrDeletionPolicy.onInit= SolrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@22bd74fd lockFactory=3Dorg.apache.lucene.store.NativeFSLoc= kFactory@2b4418cc),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_= 1] [junit4:junit4] 2> 23631 T1233 C100 P54146 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 1[segments_1] [junit4:junit4] 2> 23632 T1233 C100 P54146 oasc.SolrDeletionPolicy.onComm= it SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@22bd74fd lockFactory=3Dorg.apache.lucene.store.NativeFSLoc= kFactory@2b4418cc),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_= 1] [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@22bd74fd lockFactory=3Dorg.apache.lucene.store.NativeFSLoc= kFactory@2b4418cc),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_= 2] [junit4:junit4] 2> 23632 T1233 C100 P54146 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 2[segments_2] [junit4:junit4] 2> 23633 T1233 C100 P54146 oass.SolrIndexSearcher. = Opening Searcher@1c63ff96 realtime [junit4:junit4] 2> 23633 T1233 C100 P54146 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 23634 T1233 C100 P54146 /update {waitSearcher=3Dtrue&v= ersion=3D2&commit_end_point=3Dtrue&wt=3Djavabin&openSearcher=3Dfalse&commit= =3Dtrue&softCommit=3Dfalse} {commit=3D} 0 6 [junit4:junit4] 2> 23635 T1275 C98 P45797 oash.ReplicationHandler.inform = Commits will be reserved for 10000 [junit4:junit4] 2> 23635 T1275 C98 P45797 oash.SnapPuller. No valu= e set for 'pollInterval'. Timer Task not started. [junit4:junit4] 2> 23637 T1234 C100 P54146 oash.ReplicationHandler.inform= Commits will be reserved for 10000 [junit4:junit4] 2> 23638 T1234 C100 P54146 REQ /replication {qt=3D/replic= ation&version=3D2&command=3Dindexversion&wt=3Djavabin} status=3D0 QTime=3D1= =20 [junit4:junit4] 2> 23638 T1275 C98 P45797 oash.SnapPuller.fetchLatestInde= x Master's generation: 2 [junit4:junit4] 2> 23639 T1275 C98 P45797 oash.SnapPuller.fetchLatestInde= x Slave's generation: 1 [junit4:junit4] 2> 23639 T1275 C98 P45797 oash.SnapPuller.fetchLatestInde= x Starting replication process [junit4:junit4] 2> 23641 T1233 C100 P54146 REQ /replication {qt=3D/replic= ation&generation=3D2&version=3D2&command=3Dfilelist&wt=3Djavabin} status=3D= 0 QTime=3D0=20 [junit4:junit4] 2> 23642 T1275 C98 P45797 oash.SnapPuller.fetchLatestInde= x Number of files in latest index in master: 1 [junit4:junit4] 2> 23643 T1275 C98 P45797 oasc.CachingDirectoryFactory.ge= t return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-= 1363871127344/jetty4/index.20130321060550982 forceNew: false [junit4:junit4] 2> 23643 T1275 C98 P45797 oash.SnapPuller.fetchLatestInde= x Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@= 4c2c8ef1 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@9177d39)= fullCopy=3Dfalse [junit4:junit4] 2> 23646 T1232 C100 P54146 REQ /replication {file=3Dsegme= nts_2&qt=3D/replication&checksum=3Dtrue&generation=3D2&command=3Dfileconten= t&wt=3Dfilestream} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 23647 T1275 C98 P45797 oash.SnapPuller.fetchLatestInde= x Total time taken for download : 0 secs [junit4:junit4] 2> 23648 T1275 C98 P45797 oasu.DefaultSolrCoreState.newIn= dexWriter Creating new IndexWriter... [junit4:junit4] 2> 23649 T1275 C98 P45797 oasu.DefaultSolrCoreState.newIn= dexWriter Waiting until IndexWriter is unused... core=3Dcollection1 [junit4:junit4] 2> 23650 T1275 C98 P45797 oasc.SolrDeletionPolicy.onInit = SolrDeletionPolicy.onInit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@e77cd12 lockFactory=3Dorg.apache.lucene.store.NativeFSLock= Factory@2d99e865),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1= ] [junit4:junit4] 2> =09=09commit{dir=3DMockDirWrapper(org.apache.lucene.st= ore.RAMDirectory@e77cd12 lockFactory=3Dorg.apache.lucene.store.NativeFSLock= Factory@2d99e865),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_2= ] [junit4:junit4] 2> 23650 T1275 C98 P45797 oasc.SolrDeletionPolicy.updateC= ommits newest commit =3D 2[segments_2] [junit4:junit4] 2> 23651 T1275 C98 P45797 oasu.DefaultSolrCoreState.newIn= dexWriter New IndexWriter is ready to be used. [junit4:junit4] 2> 23651 T1275 C98 P45797 oass.SolrIndexSearcher. O= pening Searcher@576a466e main [junit4:junit4] 2> 23652 T1274 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@576a466e main{StandardDirectoryReader(s= egments_2:1:nrt)} [junit4:junit4] 2> 23653 T1275 C98 P45797 oasc.RecoveryStrategy.replay No= replay needed. core=3Dcollection1 [junit4:junit4] 2> 23653 T1275 C98 P45797 oasc.RecoveryStrategy.doRecover= y Replication Recovery was successful - registering as Active. core=3Dcolle= ction1 [junit4:junit4] 2> 23653 T1275 C98 P45797 oasc.ZkController.publish publi= shing core=3Dcollection1 state=3Dactive [junit4:junit4] 2> 23653 T1275 C98 P45797 oasc.ZkController.publish numSh= ards not found on descriptor - reading it from system property [junit4:junit4] 2> 23654 T1275 C98 P45797 oasc.RecoveryStrategy.doRecover= y Finished recovery process. core=3Dcollection1 [junit4:junit4] 2> 24083 T1204 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 24084 T1204 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "core":"onenodecollectioncore", [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "roles":"none", [junit4:junit4] 2> =09 "collection":"onenodecollection", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:55486", [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "shard":"shard1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:55486_", [junit4:junit4] 2> =09 "state":"active", [junit4:junit4] 2> =09 "core_node_name":"127.0.0.1:55486__onenodecollect= ioncore"} [junit4:junit4] 2> 24086 T1204 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D2 message=3D{ [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:45797", [junit4:junit4] 2> =09 "numShards":"2", [junit4:junit4] 2> =09 "shard":"shard2", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:45797_", [junit4:junit4] 2> =09 "state":"active", [junit4:junit4] 2> =09 "core_node_name":"127.0.0.1:45797__collection1"} [junit4:junit4] 2> 24091 T1272 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 24091 T1239 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 24091 T1255 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 24091 T1223 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 24091 T1210 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 24091 T1203 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 24631 T1181 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 24632 T1181 oasc.AbstractDistribZkTestBase.waitForReco= veriesToFinish Recoveries finished - collection: onenodecollection [junit4:junit4] 2> 24633 T1181 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&f= ollowRedirects=3Dfalse [junit4:junit4] 2> 24646 T1181 oaz.ZooKeeper. Initiating client con= nection, connectString=3D127.0.0.1:38096 sessionTimeout=3D10000 watcher=3Do= rg.apache.solr.common.cloud.ConnectionManager@33310580 [junit4:junit4] 2> 24646 T1181 oascc.ConnectionManager.waitForConnected W= aiting for client to connect to ZooKeeper [junit4:junit4] 2> 24647 T1282 oaz.ClientCnxn$SendThread.logStartConnect = Opening socket connection to server localhost.localdomain/127.0.0.1:38096. = Will not attempt to authenticate using SASL (access denied ("javax.security= .auth.AuthPermission" "getLoginConfiguration")) [junit4:junit4] 2> 24647 T1282 oaz.ClientCnxn$SendThread.primeConnection = Socket connection established to localhost.localdomain/127.0.0.1:38096, ini= tiating session [junit4:junit4] 2> 24647 T1183 oazs.NIOServerCnxnFactory.run Accepted soc= ket connection from /127.0.0.1:51542 [junit4:junit4] 2> 24648 T1183 oazs.ZooKeeperServer.processConnectRequest= Client attempting to establish new session at /127.0.0.1:51542 [junit4:junit4] 2> 24649 T1185 oazs.ZooKeeperServer.finishSessionInit Est= ablished session 0x13d8d0dd733000d with negotiated timeout 10000 for client= /127.0.0.1:51542 [junit4:junit4] 2> 24649 T1282 oaz.ClientCnxn$SendThread.onConnected Sess= ion establishment complete on server localhost.localdomain/127.0.0.1:38096,= sessionid =3D 0x13d8d0dd733000d, negotiated timeout =3D 10000 [junit4:junit4] 2> 24649 T1283 oascc.ConnectionManager.process Watcher or= g.apache.solr.common.cloud.ConnectionManager@33310580 name:ZooKeeperConnect= ion Watcher:127.0.0.1:38096 got event WatchedEvent state:SyncConnected type= :None path:null path:null type:None [junit4:junit4] 2> 24649 T1181 oascc.ConnectionManager.waitForConnected C= lient is connected to ZooKeeper [junit4:junit4] 2> 24695 T1186 oazs.PrepRequestProcessor.pRequest2Txn Pro= cessed session termination for sessionid: 0x13d8d0dd733000d [junit4:junit4] 2> 24696 T1183 oazs.NIOServerCnxn.closeSock Closed socket= connection for client /127.0.0.1:51542 which had sessionid 0x13d8d0dd73300= 0d [junit4:junit4] 2> 24696 T1181 oaz.ZooKeeper.close Session: 0x13d8d0dd733= 000d closed [junit4:junit4] 2> 24696 T1283 oaz.ClientCnxn$EventThread.run EventThread= shut down [junit4:junit4] 2> 24697 T1186 oazs.PrepRequestProcessor.pRequest2Txn Pro= cessed session termination for sessionid: 0x13d8d0dd7330004 [junit4:junit4] 2> 24697 T1210 oaz.ClientCnxn$EventThread.run EventThread= shut down [junit4:junit4] 2> 24698 T1183 oazs.NIOServerCnxn.closeSock Closed socket= connection for client /127.0.0.1:51494 which had sessionid 0x13d8d0dd73300= 04 [junit4:junit4] 2> 24697 T1181 oaz.ZooKeeper.close Session: 0x13d8d0dd733= 0004 closed [junit4:junit4] 2> 24699 T1181 oasc.ChaosMonkey.monkeyLog monkey: stop sh= ard! 37166 [junit4:junit4] 2> 24700 T1181 oasc.CoreContainer.shutdown Shutting down = CoreContainer instance=3D1689847368 [junit4:junit4] 2> 25597 T1204 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 25598 T1204 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3Dnull message=3D{ [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "collection":"control_collection", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:37166", [junit4:junit4] 2> =09 "shard":"shard1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:37166_", [junit4:junit4] 2> =09 "state":"down", [junit4:junit4] 2> =09 "core_node_name":"127.0.0.1:37166__collection1"} [junit4:junit4] 2> 25600 T1272 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 25600 T1223 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 25600 T1239 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 25600 T1203 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 25601 T1255 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 26701 T1181 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Ddown [junit4:junit4] 2> 26701 T1181 oasc.ZkController.publish numShards not fo= und on descriptor - reading it from system property [junit4:junit4] 2> 26704 T1181 oasc.SolrCore.close [collection1] CLOSING= SolrCore org.apache.solr.core.SolrCore@2d229e0d [junit4:junit4] 2> 26706 T1181 oasu.DirectUpdateHandler2.close closing Di= rectUpdateHandler2{commits=3D0,autocommits=3D0,soft autocommits=3D0,optimiz= es=3D0,rollbacks=3D0,expungeDeletes=3D0,docsPending=3D0,adds=3D0,deletesByI= d=3D0,deletesByQuery=3D0,errors=3D0,cumulative_adds=3D0,cumulative_deletesB= yId=3D0,cumulative_deletesByQuery=3D0,cumulative_errors=3D0} [junit4:junit4] 2> 26707 T1181 oasu.SolrCoreState.decrefSolrCoreState Clo= sing SolrCoreState [junit4:junit4] 2> 26707 T1181 oasu.DefaultSolrCoreState.closeIndexWriter= SolrCoreState ref count has reached 0 - closing IndexWriter [junit4:junit4] 2> 26707 T1181 oasu.DefaultSolrCoreState.closeIndexWriter= closing IndexWriter with IndexWriterCloser [junit4:junit4] 2> 26708 T1181 oasc.SolrCore.closeSearcher [collection1] = Closing main searcher on request. [junit4:junit4] 2> 26708 T1181 oasc.CachingDirectoryFactory.close Closing= directory when closing factory: ./org.apache.solr.cloud.BasicDistributedZk= 2Test-1363871127344/control/data/index [junit4:junit4] 2> 26708 T1181 oasc.CachingDirectoryFactory.closeDirector= y Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-136387= 1127344/control/data/index [junit4:junit4] 2> 26709 T1181 oasc.CachingDirectoryFactory.close Closing= directory when closing factory: ./org.apache.solr.cloud.BasicDistributedZk= 2Test-1363871127344/control/data [junit4:junit4] 2> 26709 T1181 oasc.CachingDirectoryFactory.closeDirector= y Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-136387= 1127344/control/data [junit4:junit4] 2> 26710 T1204 oasc.Overseer$ClusterStateUpdater.amILeade= r According to ZK I (id=3D89382658201812995-127.0.0.1:37166_-n_0000000000) = am no longer a leader. [junit4:junit4] 2> 26710 T1186 oazs.PrepRequestProcessor.pRequest2Txn Pro= cessed session termination for sessionid: 0x13d8d0dd7330003 [junit4:junit4] 2> 26711 T1223 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 26711 T1203 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 26711 T1183 oazs.NIOServerCnxn.closeSock Closed socket= connection for client /127.0.0.1:51493 which had sessionid 0x13d8d0dd73300= 03 [junit4:junit4] 2> 26711 T1181 oaz.ZooKeeper.close Session: 0x13d8d0dd733= 0003 closed [junit4:junit4] 2> 26711 T1203 oascc.ZkStateReader$2.process WARNING ZooK= eeper watch triggered, but Solr cannot talk to ZK [junit4:junit4] 2> 26712 T1203 oascc.ZkStateReader$3.process WARNING ZooK= eeper watch triggered, but Solr cannot talk to ZK [junit4:junit4] 2> 26712 T1239 oascc.ZkStateReader$3.process Updating liv= e nodes... (4) [junit4:junit4] 2> 26712 T1272 oascc.ZkStateReader$3.process Updating liv= e nodes... (4) [junit4:junit4] 2> 26712 T1203 oaz.ClientCnxn$EventThread.run EventThread= shut down [junit4:junit4] 2> 26712 T1239 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 26712 T1255 oascc.ZkStateReader$3.process Updating liv= e nodes... (4) [junit4:junit4] 2> 26712 T1272 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 26712 T1255 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 26713 T1223 oascc.ZkStateReader$3.process Updating liv= e nodes... (4) [junit4:junit4] 2> 26713 T1186 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d8d0dd7330006 type:de= lete cxid:0xc9 zxid:0xe3 txntype:-1 reqpath:n/a Error Path:/solr/overseer_e= lect/leader Error:KeeperErrorCode =3D NoNode for /solr/overseer_elect/leade= r [junit4:junit4] 2> 26714 T1223 oascc.SolrZkClient.makePath makePath: /ove= rseer_elect/leader [junit4:junit4] 2> 26716 T1223 oasc.Overseer.start Overseer (id=3D8938265= 8201812998-127.0.0.1:55486_-n_0000000001) starting [junit4:junit4] 2> 26716 T1186 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d8d0dd7330006 type:cr= eate cxid:0xce zxid:0xe5 txntype:-1 reqpath:n/a Error Path:/solr/overseer E= rror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 26717 T1186 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d8d0dd7330006 type:cr= eate cxid:0xcf zxid:0xe6 txntype:-1 reqpath:n/a Error Path:/solr/overseer E= rror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 26718 T1186 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d8d0dd7330006 type:cr= eate cxid:0xd1 zxid:0xe7 txntype:-1 reqpath:n/a Error Path:/solr/overseer E= rror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 26719 T1186 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d8d0dd7330006 type:cr= eate cxid:0xd3 zxid:0xe8 txntype:-1 reqpath:n/a Error Path:/solr/overseer E= rror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 26719 T1285 oasc.OverseerCollectionProcessor.run Proce= ss current queue of collection creations [junit4:junit4] 2> 26720 T1284 oasc.Overseer$ClusterStateUpdater.run Star= ting to work on the main queue [junit4:junit4] 2> 26721 T1284 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 26722 T1284 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D2 message=3D{ [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "collection":"control_collection", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:37166", [junit4:junit4] 2> =09 "numShards":"2", [junit4:junit4] 2> =09 "shard":"shard1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:37166_", [junit4:junit4] 2> =09 "state":"down", [junit4:junit4] 2> =09 "core_node_name":"127.0.0.1:37166__collection1"} [junit4:junit4] 2> 26725 T1272 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 26725 T1239 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 26725 T1255 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 26725 T1223 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 26733 T1181 oejsh.ContextHandler.doStop stopped o.e.j.= s.ServletContextHandler{/,null} [junit4:junit4] 2> 26784 T1181 oasc.ChaosMonkey.monkeyLog monkey: stop sh= ard! 55486 [junit4:junit4] 2> 26785 T1181 oasc.CoreContainer.shutdown Shutting down = CoreContainer instance=3D729517555 [junit4:junit4] 2> 28229 T1284 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 28231 T1284 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3Dnull message=3D{ [junit4:junit4] 2> =09 "core":"onenodecollectioncore", [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "roles":"none", [junit4:junit4] 2> =09 "collection":"onenodecollection", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:55486", [junit4:junit4] 2> =09 "shard":"shard1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:55486_", [junit4:junit4] 2> =09 "state":"down", [junit4:junit4] 2> =09 "core_node_name":"127.0.0.1:55486__onenodecollect= ioncore"} [junit4:junit4] 2> 28236 T1284 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3Dnull message=3D{ [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:55486", [junit4:junit4] 2> =09 "shard":"shard1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:55486_", [junit4:junit4] 2> =09 "state":"down", [junit4:junit4] 2> =09 "core_node_name":"127.0.0.1:55486__collection1"} [junit4:junit4] 2> 28242 T1255 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 28242 T1223 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 28243 T1272 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 28243 T1239 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 29787 T1181 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Ddown [junit4:junit4] 2> 29787 T1181 oasc.ZkController.publish numShards not fo= und on descriptor - reading it from system property [junit4:junit4] 2> 29789 T1181 oasc.ZkController.publish publishing core= =3Donenodecollectioncore state=3Ddown [junit4:junit4] 2> 29791 T1181 oasc.SolrCore.close [collection1] CLOSING= SolrCore org.apache.solr.core.SolrCore@32e29dd2 [junit4:junit4] 2> 29795 T1181 oasu.DirectUpdateHandler2.close closing Di= rectUpdateHandler2{commits=3D1,autocommits=3D0,soft autocommits=3D0,optimiz= es=3D0,rollbacks=3D0,expungeDeletes=3D0,docsPending=3D0,adds=3D0,deletesByI= d=3D0,deletesByQuery=3D0,errors=3D0,cumulative_adds=3D0,cumulative_deletesB= yId=3D0,cumulative_deletesByQuery=3D0,cumulative_errors=3D0} [junit4:junit4] 2> 29795 T1181 oasu.SolrCoreState.decrefSolrCoreState Clo= sing SolrCoreState [junit4:junit4] 2> 29796 T1181 oasu.DefaultSolrCoreState.closeIndexWriter= SolrCoreState ref count has reached 0 - closing IndexWriter [junit4:junit4] 2> 29796 T1181 oasu.DefaultSolrCoreState.closeIndexWriter= closing IndexWriter with IndexWriterCloser [junit4:junit4] 2> 29798 T1181 oasc.SolrCore.closeSearcher [collection1] = Closing main searcher on request. [junit4:junit4] 2> 29798 T1181 oasc.CachingDirectoryFactory.close Closing= directory when closing factory: ./org.apache.solr.cloud.BasicDistributedZk= 2Test-1363871127344/jetty1/index [junit4:junit4] 2> 29799 T1181 oasc.CachingDirectoryFactory.closeDirector= y Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-136387= 1127344/jetty1/index [junit4:junit4] 2> 29799 T1181 oasc.CachingDirectoryFactory.close Closing= directory when closing factory: ./org.apache.solr.cloud.BasicDistributedZk= 2Test-1363871127344/jetty1 [junit4:junit4] 2> 29799 T1181 oasc.CachingDirectoryFactory.closeDirector= y Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-136387= 1127344/jetty1 [junit4:junit4] 2> 29800 T1181 oasc.SolrCore.close [onenodecollectioncore= ] CLOSING SolrCore org.apache.solr.core.SolrCore@22acab77 [junit4:junit4] 2> 29805 T1181 oasu.DirectUpdateHandler2.close closing Di= rectUpdateHandler2{commits=3D0,autocommits=3D0,soft autocommits=3D0,optimiz= es=3D0,rollbacks=3D0,expungeDeletes=3D0,docsPending=3D0,adds=3D0,deletesByI= d=3D0,deletesByQuery=3D0,errors=3D0,cumulative_adds=3D0,cumulative_deletesB= yId=3D0,cumulative_deletesByQuery=3D0,cumulative_errors=3D0} [junit4:junit4] 2> 29806 T1181 oasu.SolrCoreState.decrefSolrCoreState Clo= sing SolrCoreState [junit4:junit4] 2> 29806 T1181 oasu.DefaultSolrCoreState.closeIndexWriter= SolrCoreState ref count has reached 0 - closing IndexWriter [junit4:junit4] 2> 29806 T1181 oasu.DefaultSolrCoreState.closeIndexWriter= closing IndexWriter with IndexWriterCloser [junit4:junit4] 2> 29807 T1181 oasc.SolrCore.closeSearcher [onenodecollec= tioncore] Closing main searcher on request. [junit4:junit4] 2> 29808 T1181 oasc.CachingDirectoryFactory.close Closing= directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-tru= nk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-13= 63871127344/onenodecollection/index [junit4:junit4] 2> 29808 T1181 oasc.CachingDirectoryFactory.closeDirector= y Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/sol= r/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1363871127344/= onenodecollection/index [junit4:junit4] 2> 29808 T1181 oasc.CachingDirectoryFactory.close Closing= directory when closing factory: /mnt/ssd/jenkins/workspace/Lucene-Solr-tru= nk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-13= 63871127344/onenodecollection [junit4:junit4] 2> 29809 T1181 oasc.CachingDirectoryFactory.closeDirector= y Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/sol= r/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1363871127344/= onenodecollection [junit4:junit4] 2> 29810 T1284 oasc.Overseer$ClusterStateUpdater.amILeade= r According to ZK I (id=3D89382658201812998-127.0.0.1:55486_-n_0000000001) = am no longer a leader. [junit4:junit4] 2> 29810 T1186 oazs.PrepRequestProcessor.pRequest2Txn Pro= cessed session termination for sessionid: 0x13d8d0dd7330006 [junit4:junit4] 2> 29811 T1223 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 29811 T1239 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 29811 T1183 oazs.NIOServerCnxn.doIO WARNING caught end= of stream exception EndOfStreamException: Unable to read additional data f= rom client sessionid 0x13d8d0dd7330006, likely client has closed socket [junit4:junit4] 2> =09at org.apache.zookeeper.server.NIOServerCnxn.doIO(N= IOServerCnxn.java:220) [junit4:junit4] 2> =09at org.apache.zookeeper.server.NIOServerCnxnFactory= .run(NIOServerCnxnFactory.java:208) [junit4:junit4] 2> =09at java.lang.Thread.run(Thread.java:722) [junit4:junit4] 2>=20 [junit4:junit4] 2> 29811 T1272 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 29811 T1181 oaz.ZooKeeper.close Session: 0x13d8d0dd733= 0006 closed [junit4:junit4] 2> 29811 T1183 oazs.NIOServerCnxn.closeSock Closed socket= connection for client /127.0.0.1:51496 which had sessionid 0x13d8d0dd73300= 06 [junit4:junit4] 2> 29811 T1223 oascc.ZkStateReader$2.process WARNING ZooK= eeper watch triggered, but Solr cannot talk to ZK [junit4:junit4] 2> 29812 T1223 oascc.ZkStateReader$3.process WARNING ZooK= eeper watch triggered, but Solr cannot talk to ZK [junit4:junit4] 2> 29812 T1186 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d8d0dd733000a type:de= lete cxid:0x5e zxid:0xf9 txntype:-1 reqpath:n/a Error Path:/solr/collection= s/collection1/leaders/shard1 Error:KeeperErrorCode =3D NoNode for /solr/col= lections/collection1/leaders/shard1 [junit4:junit4] 2> 29812 T1223 oaz.ClientCnxn$EventThread.run EventThread= shut down [junit4:junit4] 2> 29812 T1255 oasc.ShardLeaderElectionContext.runLeaderP= rocess Running the leader process. [junit4:junit4] 2> 29813 T1186 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d8d0dd733000a type:cr= eate cxid:0x5f zxid:0xfa txntype:-1 reqpath:n/a Error Path:/solr/overseer E= rror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 29813 T1272 oascc.ZkStateReader$3.process Updating liv= e nodes... (3) [junit4:junit4] 2> 29813 T1239 oascc.ZkStateReader$3.process Updating liv= e nodes... (3) [junit4:junit4] 2> 29814 T1186 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d8d0dd7330008 type:de= lete cxid:0x7f zxid:0xfc txntype:-1 reqpath:n/a Error Path:/solr/overseer_e= lect/leader Error:KeeperErrorCode =3D NoNode for /solr/overseer_elect/leade= r [junit4:junit4] 2> 29814 T1255 oasc.ShardLeaderElectionContext.shouldIBeL= eader Checking if I should try and be the leader. [junit4:junit4] 2> 29814 T1255 oasc.ShardLeaderElectionContext.shouldIBeL= eader My last published State was Active, it's okay to be the leader. [junit4:junit4] 2> 29815 T1255 oasc.ShardLeaderElectionContext.runLeaderP= rocess I may be the new leader - try and sync [junit4:junit4] 2> 29815 T1239 oascc.SolrZkClient.makePath makePath: /ove= rseer_elect/leader [junit4:junit4] 2> 29815 T1255 oasc.SyncStrategy.sync Sync replicas to ht= tp://127.0.0.1:53442/collection1/ [junit4:junit4] 2> 29815 T1255 oasu.PeerSync.sync PeerS [...truncated too long message...] xception: Server at http://127.0.0.1:54146/onenodecollectioncore returned n= on ok status:404, message:Can not find: /onenodecollectioncore/update [junit4:junit4] > =09at __randomizedtesting.SeedInfo.seed([DD0A1818EB265= ACD:5CEC96009C793AF1]:0) [junit4:junit4] > =09at org.apache.solr.client.solrj.impl.HttpSolrServer= .request(HttpSolrServer.java:375) [junit4:junit4] > =09at org.apache.solr.client.solrj.impl.HttpSolrServer= .request(HttpSolrServer.java:181) [junit4:junit4] > =09at org.apache.solr.client.solrj.request.AbstractUpd= ateRequest.process(AbstractUpdateRequest.java:117) [junit4:junit4] > =09at org.apache.solr.client.solrj.SolrServer.add(Solr= Server.java:116) [junit4:junit4] > =09at org.apache.solr.client.solrj.SolrServer.add(Solr= Server.java:102) [junit4:junit4] > =09at org.apache.solr.cloud.BasicDistributedZk2Test.te= stNodeWithoutCollectionForwarding(BasicDistributedZk2Test.java:196) [junit4:junit4] > =09at org.apache.solr.cloud.BasicDistributedZk2Test.do= Test(BasicDistributedZk2Test.java:89) [junit4:junit4] > =09at org.apache.solr.BaseDistributedSearchTestCase.te= stDistribSearch(BaseDistributedSearchTestCase.java:806) [junit4:junit4] > =09at sun.reflect.NativeMethodAccessorImpl.invoke0(Nat= ive Method) [junit4:junit4] > =09at sun.reflect.NativeMethodAccessorImpl.invoke(Nati= veMethodAccessorImpl.java:57) [junit4:junit4] > =09at sun.reflect.DelegatingMethodAccessorImpl.invoke(= DelegatingMethodAccessorImpl.java:43) [junit4:junit4] > =09at java.lang.reflect.Method.invoke(Method.java:487) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.RandomizedRun= ner.invoke(RandomizedRunner.java:1559) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.RandomizedRun= ner.access$600(RandomizedRunner.java:79) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.RandomizedRun= ner$6.evaluate(RandomizedRunner.java:737) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.RandomizedRun= ner$7.evaluate(RandomizedRunner.java:773) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.RandomizedRun= ner$8.evaluate(RandomizedRunner.java:787) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.rules.SystemP= ropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53) [junit4:junit4] > =09at org.apache.lucene.util.TestRuleSetupTeardownChai= ned$1.evaluate(TestRuleSetupTeardownChained.java:50) [junit4:junit4] > =09at org.apache.lucene.util.TestRuleFieldCacheSanity$= 1.evaluate(TestRuleFieldCacheSanity.java:51) [junit4:junit4] > =09at org.apache.lucene.util.AbstractBeforeAfterRule$1= .evaluate(AbstractBeforeAfterRule.java:46) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.rules.SystemP= ropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55) [junit4:junit4] > =09at org.apache.lucene.util.TestRuleThreadAndTestName= $1.evaluate(TestRuleThreadAndTestName.java:49) [junit4:junit4] > =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFai= lures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70) [junit4:junit4] > =09at org.apache.lucene.util.TestRuleMarkFailure$1.eva= luate(TestRuleMarkFailure.java:48) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.rules.Stateme= ntAdapter.evaluate(StatementAdapter.java:36) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.ThreadLeakCon= trol$StatementRunner.run(ThreadLeakControl.java:358) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.ThreadLeakCon= trol.forkTimeoutingTask(ThreadLeakControl.java:782) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.ThreadLeakCon= trol$3.evaluate(ThreadLeakControl.java:442) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.RandomizedRun= ner.runSingleTest(RandomizedRunner.java:746) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.RandomizedRun= ner$3.evaluate(RandomizedRunner.java:648) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.RandomizedRun= ner$4.evaluate(RandomizedRunner.java:682) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.RandomizedRun= ner$5.evaluate(RandomizedRunner.java:693) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.rules.Stateme= ntAdapter.evaluate(StatementAdapter.java:36) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.rules.SystemP= ropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53) [junit4:junit4] > =09at org.apache.lucene.util.AbstractBeforeAfterRule$1= .evaluate(AbstractBeforeAfterRule.java:46) [junit4:junit4] > =09at org.apache.lucene.util.TestRuleStoreClassName$1.= evaluate(TestRuleStoreClassName.java:42) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.rules.SystemP= ropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.rules.NoShado= wingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule= .java:39) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.rules.NoShado= wingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule= .java:39) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.rules.Stateme= ntAdapter.evaluate(StatementAdapter.java:36) [junit4:junit4] > =09at org.apache.lucene.util.TestRuleAssertionsRequire= d$1.evaluate(TestRuleAssertionsRequired.java:43) [junit4:junit4] > =09at org.apache.lucene.util.TestRuleMarkFailure$1.eva= luate(TestRuleMarkFailure.java:48) [junit4:junit4] > =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFai= lures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70) [junit4:junit4] > =09at org.apache.lucene.util.TestRuleIgnoreTestSuites$= 1.evaluate(TestRuleIgnoreTestSuites.java:55) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.rules.Stateme= ntAdapter.evaluate(StatementAdapter.java:36) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.ThreadLeakCon= trol$StatementRunner.run(ThreadLeakControl.java:358) [junit4:junit4] > =09at java.lang.Thread.run(Thread.java:722) [junit4:junit4] 2> 33235 T1181 oas.SolrTestCaseJ4.deleteCore ###deleteCor= e [junit4:junit4] 2> 33239 T1180 ccr.ThreadLeakControl.checkThreadLeaks WAR= NING Will linger awaiting termination of 2 leaked thread(s). [junit4:junit4] 2> 33297 T1255 oascc.ZkStateReader$3.process WARNING ZooK= eeper watch triggered, but Solr cannot talk to ZK [junit4:junit4] 2> 33297 T1255 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 33297 T1255 oascc.ZkStateReader$2.process WARNING ZooK= eeper watch triggered, but Solr cannot talk to ZK [junit4:junit4] 2> 33297 T1255 oaz.ClientCnxn$EventThread.run EventThread= shut down [junit4:junit4] 2> 33660 T1184 oazs.SessionTrackerImpl.run SessionTracker= Impl exited loop! [junit4:junit4] 2> NOTE: test params are: codec=3DAsserting, sim=3DRandom= SimilarityProvider(queryNorm=3Dfalse,coord=3Dno): {}, locale=3Dbe_BY, timez= one=3DMST [junit4:junit4] 2> NOTE: Linux 3.2.0-39-generic amd64/Oracle Corporation = 1.8.0-ea (64-bit)/cpus=3D8,threads=3D2,free=3D105239184,total=3D335609856 [junit4:junit4] 2> NOTE: All tests run in this JVM: [TestAtomicUpdateErro= rCases, EchoParamsTest, TestLMJelinekMercerSimilarityFactory, HighlighterCo= nfigTest, CurrencyFieldOpenExchangeTest, OutputWriterTest, UniqFieldsUpdate= ProcessorFactoryTest, TestDistributedSearch, DisMaxRequestHandlerTest, Test= DFRSimilarityFactory, DebugComponentTest, TestNumberUtils, SolrCoreCheckLoc= kOnStartupTest, TestElisionMultitermQuery, DOMUtilTest, TestMergePolicyConf= ig, TestCopyFieldCollectionResource, DocumentAnalysisRequestHandlerTest, Te= stPartialUpdateDeduplication, TestUtils, TestReload, TestStressLucene, Test= FastOutputStream, FieldAnalysisRequestHandlerTest, TestSolrXMLSerializer, T= estCSVResponseWriter, RequiredFieldsTest, TestCSVLoader, TestBM25Similarity= Factory, XmlUpdateRequestHandlerTest, TestFoldingMultitermQuery, TestSolr4S= patial, TestOmitPositions, BadIndexSchemaTest, SolrCmdDistributorTest, ZkSo= lrClientTest, CurrencyFieldXmlFileTest, HighlighterTest, IndexSchemaRuntime= FieldTest, SortByFunctionTest, SignatureUpdateProcessorFactoryTest, StatsCo= mponentTest, SuggesterWFSTTest, ConvertedLegacyTest, DefaultValueUpdateProc= essorTest, SpellCheckComponentTest, TestSystemIdResolver, TestFiltering, Te= stIndexingPerformance, TestArbitraryIndexDir, NotRequiredUniqueKeyTest, NoC= acheHeaderTest, SolrPluginUtilsTest, TestCollationField, TestBinaryResponse= Writer, DateMathParserTest, FullSolrCloudDistribCmdsTest, TestPropInject, T= estLuceneMatchVersion, TestFieldTypeResource, TestFieldTypeCollectionResour= ce, TestJmxIntegration, TestQuerySenderNoQuery, UpdateParamsTest, TestSolrJ= , XsltUpdateRequestHandlerTest, ChaosMonkeySafeLeaderTest, BasicDistributed= Zk2Test] [junit4:junit4] Completed on J1 in 33.76s, 1 test, 1 error <<< FAILURES! [...truncated 456 lines...] BUILD FAILED /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:375: The follo= wing error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:355: The follo= wing error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The follow= ing error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:183: The = following error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:44= 9: The following error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:= 1210: The following error occurred while executing this line: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:= 874: There were test failures: 272 suites, 1144 tests, 1 error, 13 ignored = (7 assumptions) Total time: 36 minutes 31 seconds Build step 'Invoke Ant' marked build as failure Archiving artifacts Recording test results Description set: Java: 64bit/jdk1.8.0-ea-b79 -XX:+UseParallelGC Email was triggered for: Failure Sending email for trigger: Failure ------=_Part_76_186566627.1363871704605 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_76_186566627.1363871704605--