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 6A3D0F502 for ; Fri, 12 Apr 2013 06:50:41 +0000 (UTC) Received: (qmail 2722 invoked by uid 500); 12 Apr 2013 06:50:39 -0000 Delivered-To: apmail-lucene-dev-archive@lucene.apache.org Received: (qmail 2662 invoked by uid 500); 12 Apr 2013 06:50:39 -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 2645 invoked by uid 99); 12 Apr 2013 06:50:39 -0000 Received: from nike.apache.org (HELO nike.apache.org) (192.87.106.230) by apache.org (qpsmtpd/0.29) with ESMTP; Fri, 12 Apr 2013 06:50:39 +0000 X-ASF-Spam-Status: No, hits=-2000.0 required=5.0 tests=ALL_TRUSTED,NORMAL_HTTP_TO_IP,WEIRD_PORT X-Spam-Check-By: apache.org Received: from [140.211.11.8] (HELO aegis.apache.org) (140.211.11.8) by apache.org (qpsmtpd/0.29) with ESMTP; Fri, 12 Apr 2013 06:50:16 +0000 Received: from aegis.apache.org (localhost [127.0.0.1]) by aegis.apache.org (Postfix) with ESMTP id 4E9F1C0071 for ; Fri, 12 Apr 2013 06:49:54 +0000 (UTC) Date: Fri, 12 Apr 2013 06:49:30 +0000 (UTC) From: Apache Jenkins Server To: dev@lucene.apache.org Message-ID: <609901021.1884.1365749394201.JavaMail.hudson@aegis> In-Reply-To: <587991126.1720.1365705450424.JavaMail.hudson@aegis> References: <587991126.1720.1365705450424.JavaMail.hudson@aegis> Subject: [JENKINS] Lucene-Solr-Tests-trunk-java7 - Build # 3878 - Still Failing MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="----=_Part_1883_1951804682.1365749370318" X-Jenkins-Job: Lucene-Solr-Tests-trunk-java7 X-Jenkins-Result: FAILURE X-Virus-Checked: Checked by ClamAV on apache.org ------=_Part_1883_1951804682.1365749370318 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-java7/3878/ 1 tests failed. FAILED: org.apache.solr.cloud.ChaosMonkeyShardSplitTest.testDistribSearch Error Message: Wrong doc count on shard1_1 expected:<49> but was:<50> Stack Trace: java.lang.AssertionError: Wrong doc count on shard1_1 expected:<49> but was= :<50> =09at __randomizedtesting.SeedInfo.seed([22E7C16D5A479076:A3014F752D18F04A]= :0) =09at org.junit.Assert.fail(Assert.java:93) =09at org.junit.Assert.failNotEquals(Assert.java:647) =09at org.junit.Assert.assertEquals(Assert.java:128) =09at org.junit.Assert.assertEquals(Assert.java:472) =09at org.apache.solr.cloud.ChaosMonkeyShardSplitTest.doTest(ChaosMonkeySha= rdSplitTest.java:274) =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:601) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(Randomized= Runner.java:1559) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(Random= izedRunner.java:79) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(Random= izedRunner.java:737) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(Random= izedRunner.java:773) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(Random= izedRunner.java:787) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:53) =09at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRu= leSetupTeardownChained.java:50) =09at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFi= eldCacheSanity.java:51) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:46) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRul= e$1.evaluate(SystemPropertiesInvariantRule.java:55) =09at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleT= hreadAndTestName.java:49) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:70) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:48) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.= run(ThreadLeakControl.java:358) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTa= sk(ThreadLeakControl.java:782) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(Threa= dLeakControl.java:442) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(Ran= domizedRunner.java:746) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(Random= izedRunner.java:648) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(Random= izedRunner.java:682) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(Random= izedRunner.java:693) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:53) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:46) =09at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStor= eClassName.java:42) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRul= e$1.evaluate(SystemPropertiesInvariantRule.java:55) =09at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMeth= odsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) =09at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMeth= odsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRule= AssertionsRequired.java:43) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:48) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:70) =09at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIg= noreTestSuites.java:55) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.= run(ThreadLeakControl.java:358) =09at java.lang.Thread.run(Thread.java:722) Build Log: [...truncated 9201 lines...] [junit4:junit4] Suite: org.apache.solr.cloud.ChaosMonkeyShardSplitTest [junit4:junit4] 1> INFO - 2013-04-12 06:32:52.755; org.apache.solr.BaseD= istributedSearchTestCase; Setting hostContext system property: /m/ao [junit4:junit4] 1> INFO - 2013-04-12 06:32:52.760; org.apache.solr.SolrT= estCaseJ4; ###Starting testDistribSearch [junit4:junit4] 1> INFO - 2013-04-12 06:32:52.761; org.apache.solr.cloud= .ZkTestServer; STARTING ZK TEST SERVER [junit4:junit4] 1> client port:0.0.0.0/0.0.0.0:0 [junit4:junit4] 1> INFO - 2013-04-12 06:32:52.762; org.apache.solr.cloud= .ZkTestServer$ZKServerMain; Starting server [junit4:junit4] 1> INFO - 2013-04-12 06:32:52.863; org.apache.solr.cloud= .ZkTestServer; start zk server on port:46956 [junit4:junit4] 1> INFO - 2013-04-12 06:32:52.864; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 06:32:52.869; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@243157c8 name:ZooKeeperConnection Watcher:127.0.0.1:46956 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-12 06:32:52.870; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 06:32:52.870; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /solr [junit4:junit4] 1> INFO - 2013-04-12 06:32:52.891; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 06:32:52.897; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@14e33f2a name:ZooKeeperConnection Watcher:127.0.0.1:46956/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-04-12 06:32:52.897; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 06:32:52.898; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1 [junit4:junit4] 1> INFO - 2013-04-12 06:32:52.902; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1/shards [junit4:junit4] 1> INFO - 2013-04-12 06:32:52.911; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/control_collection [junit4:junit4] 1> INFO - 2013-04-12 06:32:52.913; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/control_collection/shards [junit4:junit4] 1> INFO - 2013-04-12 06:32:52.916; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/s= olrconfig-tlog.xml to /configs/conf1/solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-12 06:32:52.917; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-12 06:32:52.931; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/s= chema.xml to /configs/conf1/schema.xml [junit4:junit4] 1> INFO - 2013-04-12 06:32:52.933; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/schema.xml [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.036; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/s= topwords.txt to /configs/conf1/stopwords.txt [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.037; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/stopwords.txt [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.040; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/p= rotwords.txt to /configs/conf1/protwords.txt [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.040; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/protwords.txt [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.051; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/c= urrency.xml to /configs/conf1/currency.xml [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.052; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/currency.xml [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.055; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/o= pen-exchange-rates.json to /configs/conf1/open-exchange-rates.json [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.056; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/open-exchange-rates.json [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.059; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/m= apping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.060; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/mapping-ISOLatin1Accent.txt [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.063; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/o= ld_synonyms.txt to /configs/conf1/old_synonyms.txt [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.064; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/old_synonyms.txt [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.066; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/s= ynonyms.txt to /configs/conf1/synonyms.txt [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.067; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/synonyms.txt [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.282; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.287; org.eclipse.jetty.ser= ver.AbstractConnector; Started SocketConnector@127.0.0.1:50622 [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.288; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.289; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.290; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: /usr/home/hudson/= hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/t= est/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-13657= 48373078 [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.290; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/te= st/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-136574= 8373078/solr.xml [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.291; org.apache.solr.core.= CoreContainer; New CoreContainer 433139994 [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.292; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/usr/home/hudson/hud= son-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test= /J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-13657483= 73078/' [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.292; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/= test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1365= 748373078/' [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.358; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.359; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.360; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.360; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.361; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.361; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.362; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.362; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.363; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.364; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D120000&connTimeout=3D1= 5000&retry=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.387; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.407; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:46956/solr [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.408; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.409; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.414; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@5f34826b name:ZooKeeperConnection Watcher:127.0.0.1:46956 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.415; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.427; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D500&maxConnectionsPerHost=3D16&socketTimeout=3D120000&connTimeout=3D150= 00 [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.441; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.443; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@951dffb name:ZooKeeperConnection Watcher:127.0.0.1:46956/solr got ev= ent WatchedEvent state:SyncConnected type:None path:null path:null type:Non= e [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.443; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.450; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer/queue [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.454; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer/collection-queue-work [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.463; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.465; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:506= 22_m%2Fao [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.466; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:50622_m%2Fao [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.475; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer_elect/election [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.491; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer_elect/leader [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.493; org.apache.solr.cloud= .Overseer; Overseer (id=3D89505685357592579-127.0.0.1:50622_m%2Fao-n_000000= 0000) starting [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.506; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer/queue-work [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.518; org.apache.solr.cloud= .OverseerCollectionProcessor; Process current queue of collection creations [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.519; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /clusterstate.json [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.521; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /aliases.json [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.523; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.528; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Starting to work on the main queue [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.530; org.apache.solr.core.= CoreContainer; Creating SolrCore 'collection1' using instanceDir: /usr/home= /hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/sol= r-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljet= ty-1365748373078/collection1 [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.530; org.apache.solr.cloud= .ZkController; Check for collection zkNode:control_collection [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.531; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.531; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/control_collection [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.532; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/= test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1365= 748373078/collection1/' [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.534; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cl= oud.ChaosMonkeyShardSplitTest-controljetty-1365748373078/collection1/lib/RE= ADME' to classloader [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.534; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cl= oud.ChaosMonkeyShardSplitTest-controljetty-1365748373078/collection1/lib/cl= asses/' to classloader [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.584; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.662; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.764; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-12 06:32:53.771; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-12 06:32:54.410; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-12 06:32:54.422; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-12 06:32:54.426; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-12 06:32:54.439; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-12 06:32:54.444; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-12 06:32:54.449; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-12 06:32:54.450; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-12 06:32:54.451; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-12 06:32:54.451; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-12 06:32:54.452; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-12 06:32:54.452; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-12 06:32:54.453; org.apache.solr.core.= SolrCore; solr.NRTCachingDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-12 06:32:54.453; org.apache.solr.core.= SolrCore; [collection1] Opening new SolrCore at /usr/home/hudson/hudson-sla= ve/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./o= rg.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1365748373078/c= ollection1/, dataDir=3D./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-13= 65748372760/control/data/ [junit4:junit4] 1> INFO - 2013-04-12 06:32:54.453; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@3172cef6 [junit4:junit4] 1> INFO - 2013-04-12 06:32:54.454; org.apache.solr.core.= SolrCore; solr.NRTCachingDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-12 06:32:54.455; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/o= rg.apache.solr.cloud.ChaosMonkeyShardSplitTest-1365748372760/control/data [junit4:junit4] 1> INFO - 2013-04-12 06:32:54.456; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D./org.apache.solr.= cloud.ChaosMonkeyShardSplitTest-1365748372760/control/data/index/ [junit4:junit4] 1> WARN - 2013-04-12 06:32:54.457; org.apache.solr.core.= SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.Chaos= MonkeyShardSplitTest-1365748372760/control/data/index' doesn't exist. Creat= ing new index... [junit4:junit4] 1> INFO - 2013-04-12 06:32:54.458; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/o= rg.apache.solr.cloud.ChaosMonkeyShardSplitTest-1365748372760/control/data/i= ndex [junit4:junit4] 1> INFO - 2013-04-12 06:32:54.465; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DNRTCachingDirectory(org.apache.lucene.= store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMon= keyShardSplitTest-1365748372760/control/data/index lockFactory=3Dorg.apache= .lucene.store.NativeFSLockFactory@158a80bc; maxCacheMB=3D48.0 maxMergeSizeM= B=3D4.0),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-12 06:32:54.465; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-12 06:32:54.468; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-12 06:32:54.469; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-12 06:32:54.469; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-12 06:32:54.470; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-12 06:32:54.471; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-12 06:32:54.471; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-12 06:32:54.471; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-12 06:32:54.472; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-12 06:32:54.472; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-12 06:32:54.484; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-12 06:32:54.492; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@7b692120 main [junit4:junit4] 1> INFO - 2013-04-12 06:32:54.493; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-12 06:32:54.493; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-12 06:32:54.496; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@7b692120 main{Stan= dardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-12 06:32:54.498; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Ddown [junit4:junit4] 1> INFO - 2013-04-12 06:32:54.499; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-12 06:32:55.031; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 06:32:55.032; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D1 message=3D{ [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "core_node_name":null, [junit4:junit4] 1> "numShards":"1", [junit4:junit4] 1> "shard":null, [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"down", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"control_collection", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:50622_m%2Fao", [junit4:junit4] 1> "base_url":"http://127.0.0.1:50622/m/ao"} [junit4:junit4] 1> INFO - 2013-04-12 06:32:55.032; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Create collection control_collection with nu= mShards 1 [junit4:junit4] 1> INFO - 2013-04-12 06:32:55.032; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Assigning new node to shard=3Dshard1 [junit4:junit4] 1> INFO - 2013-04-12 06:32:55.049; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 1) [junit4:junit4] 1> INFO - 2013-04-12 06:32:55.502; org.apache.solr.core.= CoreContainer; registering core: collection1 [junit4:junit4] 1> INFO - 2013-04-12 06:32:55.502; org.apache.solr.cloud= .ZkController; Register replica - core:collection1 address:http://127.0.0.1= :50622/m/ao collection:control_collection shard:shard1 [junit4:junit4] 1> INFO - 2013-04-12 06:32:55.503; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/control_collection/leader_elec= t/shard1/election [junit4:junit4] 1> INFO - 2013-04-12 06:32:55.546; org.apache.solr.cloud= .ShardLeaderElectionContext; Running the leader process. [junit4:junit4] 1> INFO - 2013-04-12 06:32:55.557; org.apache.solr.cloud= .ShardLeaderElectionContext; Enough replicas found to continue. [junit4:junit4] 1> INFO - 2013-04-12 06:32:55.557; org.apache.solr.cloud= .ShardLeaderElectionContext; I may be the new leader - try and sync [junit4:junit4] 1> INFO - 2013-04-12 06:32:55.558; org.apache.solr.cloud= .SyncStrategy; Sync replicas to http://127.0.0.1:50622/m/ao/collection1/ [junit4:junit4] 1> INFO - 2013-04-12 06:32:55.558; org.apache.solr.cloud= .SyncStrategy; Sync Success - now sync replicas to me [junit4:junit4] 1> INFO - 2013-04-12 06:32:55.558; org.apache.solr.cloud= .SyncStrategy; http://127.0.0.1:50622/m/ao/collection1/ has no replicas [junit4:junit4] 1> INFO - 2013-04-12 06:32:55.559; org.apache.solr.cloud= .ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:50622/m/= ao/collection1/ [junit4:junit4] 1> INFO - 2013-04-12 06:32:55.559; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/control_collection/leaders/sha= rd1 [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.553; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.580; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 1) [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.592; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:50622/m/ao/collection1/ and leader i= s http://127.0.0.1:50622/m/ao/collection1/ [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.592; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dcollection1 baseURL=3Dhttp://= 127.0.0.1:50622/m/ao [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.592; org.apache.solr.cloud= .ZkController; I am the leader, no recovery necessary [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.593; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Dactive [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.593; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.594; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.596; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0 [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.597; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.597; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.615; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config: [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.616; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.619; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@10ff2933 name:ZooKeeperConnection Watcher:127.0.0.1:46956/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.619; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.620; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.622; org.apache.solr.cloud= .ChaosMonkey; monkey: init - expire sessions:true cause connection loss:tru= e [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.835; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.839; org.eclipse.jetty.ser= ver.AbstractConnector; Started SocketConnector@127.0.0.1:62829 [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.840; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.840; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.841; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: /usr/home/hudson/= hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/t= est/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-13657483766= 23 [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.841; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/te= st/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-136574837662= 3/solr.xml [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.842; org.apache.solr.core.= CoreContainer; New CoreContainer 692551756 [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.843; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/usr/home/hudson/hud= son-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test= /J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1365748376623/= ' [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.844; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/= test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1365748376= 623/' [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.910; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.910; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.911; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.912; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.912; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.913; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.913; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.914; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.914; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.915; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D120000&connTimeout=3D1= 5000&retry=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.938; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.958; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:46956/solr [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.959; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.960; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.974; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@22972900 name:ZooKeeperConnection Watcher:127.0.0.1:46956 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.975; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.977; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D500&maxConnectionsPerHost=3D16&socketTimeout=3D120000&connTimeout=3D150= 00 [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.991; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.993; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@5d5c50e9 name:ZooKeeperConnection Watcher:127.0.0.1:46956/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-04-12 06:32:56.993; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 06:32:57.004; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.007; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:628= 29_m%2Fao [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.035; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:62829_m%2Fao [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.038; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (2) [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.038; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (2) [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.038; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (2) [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.038; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 2) [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.053; org.apache.solr.core.= CoreContainer; Creating SolrCore 'collection1' using instanceDir: /usr/home= /hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/sol= r-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-136= 5748376623/collection1 [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.053; org.apache.solr.cloud= .ZkController; Check for collection zkNode:collection1 [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.054; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.054; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/collection1 [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.055; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/= test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1365748376= 623/collection1/' [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.057; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cl= oud.ChaosMonkeyShardSplitTest-jetty1-1365748376623/collection1/lib/classes/= ' to classloader [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.057; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cl= oud.ChaosMonkeyShardSplitTest-jetty1-1365748376623/collection1/lib/README' = to classloader [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.090; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.091; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D1 message=3D{ [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "core_node_name":"127.0.0.1:50622_m%2Fao_collection1= ", [junit4:junit4] 1> "numShards":"1", [junit4:junit4] 1> "shard":"shard1", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"control_collection", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:50622_m%2Fao", [junit4:junit4] 1> "base_url":"http://127.0.0.1:50622/m/ao"} [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.095; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 2) [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.095; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 2) [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.095; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 2) [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.107; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.169; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.271; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.278; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.922; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.934; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.938; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.951; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.956; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.961; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-12 06:32:58.961; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-12 06:32:58.962; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.963; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-12 06:32:58.964; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-12 06:32:58.964; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.964; org.apache.solr.core.= SolrCore; solr.NRTCachingDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.965; org.apache.solr.core.= SolrCore; [collection1] Opening new SolrCore at /usr/home/hudson/hudson-sla= ve/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./o= rg.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1365748376623/collect= ion1/, dataDir=3D./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-13657483= 72760/jetty1/ [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.965; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@3172cef6 [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.966; org.apache.solr.core.= SolrCore; solr.NRTCachingDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.967; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/o= rg.apache.solr.cloud.ChaosMonkeyShardSplitTest-1365748372760/jetty1 [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.968; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D./org.apache.solr.= cloud.ChaosMonkeyShardSplitTest-1365748372760/jetty1/index/ [junit4:junit4] 1> WARN - 2013-04-12 06:32:58.968; org.apache.solr.core.= SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.Chaos= MonkeyShardSplitTest-1365748372760/jetty1/index' doesn't exist. Creating ne= w index... [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.969; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/o= rg.apache.solr.cloud.ChaosMonkeyShardSplitTest-1365748372760/jetty1/index [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.978; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DNRTCachingDirectory(org.apache.lucene.= store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMon= keyShardSplitTest-1365748372760/jetty1/index lockFactory=3Dorg.apache.lucen= e.store.NativeFSLockFactory@155387cb; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.= 0),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.978; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.981; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.982; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.982; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.983; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.984; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.984; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.985; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.986; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.986; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-12 06:32:58.999; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-12 06:32:59.007; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@4ff76f64 main [junit4:junit4] 1> INFO - 2013-04-12 06:32:59.008; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-12 06:32:59.009; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-12 06:32:59.013; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@4ff76f64 main{Stan= dardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-12 06:32:59.016; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Ddown [junit4:junit4] 1> INFO - 2013-04-12 06:32:59.016; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-12 06:32:59.607; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 06:32:59.608; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "core_node_name":null, [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "shard":null, [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"down", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:62829_m%2Fao", [junit4:junit4] 1> "base_url":"http://127.0.0.1:62829/m/ao"} [junit4:junit4] 1> INFO - 2013-04-12 06:32:59.608; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Create collection collection1 with numShards= 2 [junit4:junit4] 1> INFO - 2013-04-12 06:32:59.608; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Assigning new node to shard=3Dshard1 [junit4:junit4] 1> INFO - 2013-04-12 06:32:59.624; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 2) [junit4:junit4] 1> INFO - 2013-04-12 06:32:59.624; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 2) [junit4:junit4] 1> INFO - 2013-04-12 06:32:59.624; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 2) [junit4:junit4] 1> INFO - 2013-04-12 06:33:00.019; org.apache.solr.core.= CoreContainer; registering core: collection1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:00.019; org.apache.solr.cloud= .ZkController; Register replica - core:collection1 address:http://127.0.0.1= :62829/m/ao collection:collection1 shard:shard1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:00.020; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1/leader_elect/shard= 1/election [junit4:junit4] 1> INFO - 2013-04-12 06:33:00.046; org.apache.solr.cloud= .ShardLeaderElectionContext; Running the leader process. [junit4:junit4] 1> INFO - 2013-04-12 06:33:00.049; org.apache.solr.cloud= .ShardLeaderElectionContext; Enough replicas found to continue. [junit4:junit4] 1> INFO - 2013-04-12 06:33:00.049; org.apache.solr.cloud= .ShardLeaderElectionContext; I may be the new leader - try and sync [junit4:junit4] 1> INFO - 2013-04-12 06:33:00.050; org.apache.solr.cloud= .SyncStrategy; Sync replicas to http://127.0.0.1:62829/m/ao/collection1/ [junit4:junit4] 1> INFO - 2013-04-12 06:33:00.050; org.apache.solr.cloud= .SyncStrategy; Sync Success - now sync replicas to me [junit4:junit4] 1> INFO - 2013-04-12 06:33:00.050; org.apache.solr.cloud= .SyncStrategy; http://127.0.0.1:62829/m/ao/collection1/ has no replicas [junit4:junit4] 1> INFO - 2013-04-12 06:33:00.051; org.apache.solr.cloud= .ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:62829/m/= ao/collection1/ [junit4:junit4] 1> INFO - 2013-04-12 06:33:00.051; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1/leaders/shard1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.128; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.182; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 2) [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.182; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 2) [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.182; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 2) [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.192; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:62829/m/ao/collection1/ and leader i= s http://127.0.0.1:62829/m/ao/collection1/ [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.192; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dcollection1 baseURL=3Dhttp://= 127.0.0.1:62829/m/ao [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.192; org.apache.solr.cloud= .ZkController; I am the leader, no recovery necessary [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.193; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Dactive [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.193; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.219; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.221; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0 [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.221; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.222; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.456; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.460; org.eclipse.jetty.ser= ver.AbstractConnector; Started SocketConnector@127.0.0.1:15572 [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.461; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.462; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.462; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: /usr/home/hudson/= hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/t= est/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-13657483812= 37 [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.463; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/te= st/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-136574838123= 7/solr.xml [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.463; org.apache.solr.core.= CoreContainer; New CoreContainer 249196468 [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.464; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/usr/home/hudson/hud= son-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test= /J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1365748381237/= ' [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.465; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/= test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1365748381= 237/' [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.534; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.535; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.535; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.536; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.537; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.537; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.538; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.538; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.539; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.539; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D120000&connTimeout=3D1= 5000&retry=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.561; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.582; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:46956/solr [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.583; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.584; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.587; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@179cd774 name:ZooKeeperConnection Watcher:127.0.0.1:46956 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.588; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.608; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D500&maxConnectionsPerHost=3D16&socketTimeout=3D120000&connTimeout=3D150= 00 [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.619; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.621; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@66130275 name:ZooKeeperConnection Watcher:127.0.0.1:46956/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.622; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 06:33:01.632; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:02.636; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:155= 72_m%2Fao [junit4:junit4] 1> INFO - 2013-04-12 06:33:02.638; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:15572_m%2Fao [junit4:junit4] 1> INFO - 2013-04-12 06:33:02.641; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-04-12 06:33:02.641; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-04-12 06:33:02.641; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-04-12 06:33:02.641; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-04-12 06:33:02.642; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 06:33:02.641; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 06:33:02.642; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 06:33:02.662; org.apache.solr.core.= CoreContainer; Creating SolrCore 'collection1' using instanceDir: /usr/home= /hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/sol= r-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-136= 5748381237/collection1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:02.663; org.apache.solr.cloud= .ZkController; Check for collection zkNode:collection1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:02.663; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-12 06:33:02.663; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/collection1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:02.665; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/= test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1365748381= 237/collection1/' [junit4:junit4] 1> INFO - 2013-04-12 06:33:02.666; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cl= oud.ChaosMonkeyShardSplitTest-jetty2-1365748381237/collection1/lib/classes/= ' to classloader [junit4:junit4] 1> INFO - 2013-04-12 06:33:02.667; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cl= oud.ChaosMonkeyShardSplitTest-jetty2-1365748381237/collection1/lib/README' = to classloader [junit4:junit4] 1> INFO - 2013-04-12 06:33:02.711; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:02.712; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "core_node_name":"127.0.0.1:62829_m%2Fao_collection1= ", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "shard":"shard1", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:62829_m%2Fao", [junit4:junit4] 1> "base_url":"http://127.0.0.1:62829/m/ao"} [junit4:junit4] 1> INFO - 2013-04-12 06:33:02.718; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-12 06:33:02.724; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 06:33:02.724; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 06:33:02.724; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 06:33:02.724; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 06:33:02.782; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-12 06:33:02.884; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-12 06:33:02.890; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-12 06:33:03.533; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-12 06:33:03.545; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-12 06:33:03.549; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-12 06:33:03.562; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-12 06:33:03.567; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-12 06:33:03.571; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-12 06:33:03.572; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-12 06:33:03.573; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-12 06:33:03.574; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-12 06:33:03.575; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-12 06:33:03.575; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-12 06:33:03.576; org.apache.solr.core.= SolrCore; solr.NRTCachingDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-12 06:33:03.576; org.apache.solr.core.= SolrCore; [collection1] Opening new SolrCore at /usr/home/hudson/hudson-sla= ve/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./o= rg.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1365748381237/collect= ion1/, dataDir=3D./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-13657483= 72760/jetty2/ [junit4:junit4] 1> INFO - 2013-04-12 06:33:03.576; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@3172cef6 [junit4:junit4] 1> INFO - 2013-04-12 06:33:03.577; org.apache.solr.core.= SolrCore; solr.NRTCachingDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-12 06:33:03.578; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/o= rg.apache.solr.cloud.ChaosMonkeyShardSplitTest-1365748372760/jetty2 [junit4:junit4] 1> INFO - 2013-04-12 06:33:03.579; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D./org.apache.solr.= cloud.ChaosMonkeyShardSplitTest-1365748372760/jetty2/index/ [junit4:junit4] 1> WARN - 2013-04-12 06:33:03.579; org.apache.solr.core.= SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.Chaos= MonkeyShardSplitTest-1365748372760/jetty2/index' doesn't exist. Creating ne= w index... [junit4:junit4] 1> INFO - 2013-04-12 06:33:03.580; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/o= rg.apache.solr.cloud.ChaosMonkeyShardSplitTest-1365748372760/jetty2/index [junit4:junit4] 1> INFO - 2013-04-12 06:33:03.586; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DNRTCachingDirectory(org.apache.lucene.= store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMon= keyShardSplitTest-1365748372760/jetty2/index lockFactory=3Dorg.apache.lucen= e.store.NativeFSLockFactory@46db9675; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.= 0),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-12 06:33:03.587; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-12 06:33:03.590; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-12 06:33:03.591; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-12 06:33:03.591; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-12 06:33:03.592; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-12 06:33:03.593; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-12 06:33:03.594; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-12 06:33:03.594; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-12 06:33:03.595; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-12 06:33:03.596; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-12 06:33:03.609; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-12 06:33:03.618; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@2da6608d main [junit4:junit4] 1> INFO - 2013-04-12 06:33:03.619; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-12 06:33:03.619; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-12 06:33:03.624; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@2da6608d main{Stan= dardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-12 06:33:03.626; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Ddown [junit4:junit4] 1> INFO - 2013-04-12 06:33:03.626; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-12 06:33:04.228; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:04.229; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "core_node_name":null, [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "shard":null, [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"down", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:15572_m%2Fao", [junit4:junit4] 1> "base_url":"http://127.0.0.1:15572/m/ao"} [junit4:junit4] 1> INFO - 2013-04-12 06:33:04.229; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Collection already exists with numShards=3D2 [junit4:junit4] 1> INFO - 2013-04-12 06:33:04.229; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Assigning new node to shard=3Dshard2 [junit4:junit4] 1> INFO - 2013-04-12 06:33:04.233; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 06:33:04.233; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 06:33:04.233; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 06:33:04.233; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 06:33:04.629; org.apache.solr.core.= CoreContainer; registering core: collection1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:04.629; org.apache.solr.cloud= .ZkController; Register replica - core:collection1 address:http://127.0.0.1= :15572/m/ao collection:collection1 shard:shard2 [junit4:junit4] 1> INFO - 2013-04-12 06:33:04.630; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1/leader_elect/shard= 2/election [junit4:junit4] 1> INFO - 2013-04-12 06:33:04.645; org.apache.solr.cloud= .ShardLeaderElectionContext; Running the leader process. [junit4:junit4] 1> INFO - 2013-04-12 06:33:04.647; org.apache.solr.cloud= .ShardLeaderElectionContext; Enough replicas found to continue. [junit4:junit4] 1> INFO - 2013-04-12 06:33:04.648; org.apache.solr.cloud= .ShardLeaderElectionContext; I may be the new leader - try and sync [junit4:junit4] 1> INFO - 2013-04-12 06:33:04.648; org.apache.solr.cloud= .SyncStrategy; Sync replicas to http://127.0.0.1:15572/m/ao/collection1/ [junit4:junit4] 1> INFO - 2013-04-12 06:33:04.648; org.apache.solr.cloud= .SyncStrategy; Sync Success - now sync replicas to me [junit4:junit4] 1> INFO - 2013-04-12 06:33:04.649; org.apache.solr.cloud= .SyncStrategy; http://127.0.0.1:15572/m/ao/collection1/ has no replicas [junit4:junit4] 1> INFO - 2013-04-12 06:33:04.649; org.apache.solr.cloud= .ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:15572/m/= ao/collection1/ [junit4:junit4] 1> INFO - 2013-04-12 06:33:04.649; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1/leaders/shard2 [junit4:junit4] 1> INFO - 2013-04-12 06:33:05.755; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:05.772; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 06:33:05.772; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 06:33:05.772; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 06:33:05.772; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 06:33:05.775; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:15572/m/ao/collection1/ and leader i= s http://127.0.0.1:15572/m/ao/collection1/ [junit4:junit4] 1> INFO - 2013-04-12 06:33:05.775; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dcollection1 baseURL=3Dhttp://= 127.0.0.1:15572/m/ao [junit4:junit4] 1> INFO - 2013-04-12 06:33:05.775; org.apache.solr.cloud= .ZkController; I am the leader, no recovery necessary [junit4:junit4] 1> INFO - 2013-04-12 06:33:05.776; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Dactive [junit4:junit4] 1> INFO - 2013-04-12 06:33:05.776; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-12 06:33:05.777; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:05.778; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0 [junit4:junit4] 1> INFO - 2013-04-12 06:33:05.779; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-12 06:33:05.780; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 06:33:06.080; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-12 06:33:06.084; org.eclipse.jetty.ser= ver.AbstractConnector; Started SocketConnector@127.0.0.1:45726 [junit4:junit4] 1> INFO - 2013-04-12 06:33:06.084; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-12 06:33:06.085; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-12 06:33:06.086; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: /usr/home/hudson/= hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/t= est/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-13657483857= 95 [junit4:junit4] 1> INFO - 2013-04-12 06:33:06.086; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/te= st/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-136574838579= 5/solr.xml [junit4:junit4] 1> INFO - 2013-04-12 06:33:06.087; org.apache.solr.core.= CoreContainer; New CoreContainer 506485395 [junit4:junit4] 1> INFO - 2013-04-12 06:33:06.088; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/usr/home/hudson/hud= son-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test= /J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1365748385795/= ' [junit4:junit4] 1> INFO - 2013-04-12 06:33:06.088; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/= test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1365748385= 795/' [junit4:junit4] 1> INFO - 2013-04-12 06:33:06.158; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-12 06:33:06.159; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-12 06:33:06.160; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-12 06:33:06.160; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:06.161; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-12 06:33:06.162; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-12 06:33:06.162; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-12 06:33:06.163; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:06.163; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-12 06:33:06.164; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D120000&connTimeout=3D1= 5000&retry=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 06:33:06.188; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-12 06:33:06.209; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:46956/solr [junit4:junit4] 1> INFO - 2013-04-12 06:33:06.210; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-12 06:33:06.211; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 06:33:06.214; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@46fe53ee name:ZooKeeperConnection Watcher:127.0.0.1:46956 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-12 06:33:06.215; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 06:33:06.218; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D500&maxConnectionsPerHost=3D16&socketTimeout=3D120000&connTimeout=3D150= 00 [junit4:junit4] 1> INFO - 2013-04-12 06:33:06.239; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 06:33:06.241; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@88509ca name:ZooKeeperConnection Watcher:127.0.0.1:46956/solr got ev= ent WatchedEvent state:SyncConnected type:None path:null path:null type:Non= e [junit4:junit4] 1> INFO - 2013-04-12 06:33:06.242; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 06:33:06.322; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:07.277; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:07.278; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "core_node_name":"127.0.0.1:15572_m%2Fao_collection1= ", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "shard":"shard2", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:15572_m%2Fao", [junit4:junit4] 1> "base_url":"http://127.0.0.1:15572/m/ao"} [junit4:junit4] 1> INFO - 2013-04-12 06:33:07.303; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 06:33:07.303; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 06:33:07.303; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 06:33:07.303; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 06:33:07.303; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 06:33:07.325; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:457= 26_m%2Fao [junit4:junit4] 1> INFO - 2013-04-12 06:33:07.327; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:45726_m%2Fao [junit4:junit4] 1> INFO - 2013-04-12 06:33:07.329; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 06:33:07.329; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 06:33:07.330; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-12 06:33:07.330; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-12 06:33:07.329; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-12 06:33:07.330; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 06:33:07.330; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 06:33:07.331; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-12 06:33:07.331; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 06:33:07.348; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-12 06:33:07.353; org.apache.solr.core.= CoreContainer; Creating SolrCore 'collection1' using instanceDir: /usr/home= /hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/sol= r-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-136= 5748385795/collection1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:07.354; org.apache.solr.cloud= .ZkController; Check for collection zkNode:collection1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:07.354; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-12 06:33:07.355; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/collection1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:07.356; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/= test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1365748385= 795/collection1/' [junit4:junit4] 1> INFO - 2013-04-12 06:33:07.358; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cl= oud.ChaosMonkeyShardSplitTest-jetty3-1365748385795/collection1/lib/README' = to classloader [junit4:junit4] 1> INFO - 2013-04-12 06:33:07.358; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cl= oud.ChaosMonkeyShardSplitTest-jetty3-1365748385795/collection1/lib/classes/= ' to classloader [junit4:junit4] 1> INFO - 2013-04-12 06:33:07.422; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-12 06:33:07.485; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-12 06:33:07.586; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-12 06:33:07.592; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.238; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.250; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.254; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.268; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.273; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.278; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-12 06:33:08.279; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-12 06:33:08.279; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.280; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-12 06:33:08.281; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-12 06:33:08.281; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.281; org.apache.solr.core.= SolrCore; solr.NRTCachingDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.282; org.apache.solr.core.= SolrCore; [collection1] Opening new SolrCore at /usr/home/hudson/hudson-sla= ve/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./o= rg.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1365748385795/collect= ion1/, dataDir=3D./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-13657483= 72760/jetty3/ [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.282; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@3172cef6 [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.283; org.apache.solr.core.= SolrCore; solr.NRTCachingDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.284; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/o= rg.apache.solr.cloud.ChaosMonkeyShardSplitTest-1365748372760/jetty3 [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.285; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D./org.apache.solr.= cloud.ChaosMonkeyShardSplitTest-1365748372760/jetty3/index/ [junit4:junit4] 1> WARN - 2013-04-12 06:33:08.285; org.apache.solr.core.= SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.Chaos= MonkeyShardSplitTest-1365748372760/jetty3/index' doesn't exist. Creating ne= w index... [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.286; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/o= rg.apache.solr.cloud.ChaosMonkeyShardSplitTest-1365748372760/jetty3/index [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.293; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DNRTCachingDirectory(org.apache.lucene.= store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMon= keyShardSplitTest-1365748372760/jetty3/index lockFactory=3Dorg.apache.lucen= e.store.NativeFSLockFactory@33ac1a4; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.0= ),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.293; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.296; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.297; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.298; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.298; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.299; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.299; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.300; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.301; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.301; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.314; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.322; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@6d0229bd main [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.323; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.324; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.328; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@6d0229bd main{Stan= dardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.331; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Ddown [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.331; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.808; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.809; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "core_node_name":null, [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "shard":null, [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"down", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:45726_m%2Fao", [junit4:junit4] 1> "base_url":"http://127.0.0.1:45726/m/ao"} [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.809; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Collection already exists with numShards=3D2 [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.809; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Assigning new node to shard=3Dshard1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.823; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.823; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.823; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.823; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 06:33:08.823; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.334; org.apache.solr.core.= CoreContainer; registering core: collection1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.334; org.apache.solr.cloud= .ZkController; Register replica - core:collection1 address:http://127.0.0.1= :45726/m/ao collection:collection1 shard:shard1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.337; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:45726/m/ao/collection1/ and leader i= s http://127.0.0.1:62829/m/ao/collection1/ [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.338; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dcollection1 baseURL=3Dhttp://= 127.0.0.1:45726/m/ao [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.338; org.apache.solr.cloud= .ZkController; Core needs to recover:collection1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.338; org.apache.solr.updat= e.DefaultSolrCoreState; Running recovery - first canceling any ongoing reco= very [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.339; org.apache.solr.cloud= .RecoveryStrategy; Starting recovery process. core=3Dcollection1 recoverin= gAfterStartup=3Dtrue [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.339; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.340; org.apache.solr.cloud= .RecoveryStrategy; ###### startupVersions=3D[] [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.340; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Drecovering [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.341; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.341; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0 [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.342; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.343; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.420; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.433; org.apache.solr.handl= er.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:45726_= m%2Fao_collection1, state: recovering, checkLive: true, onlyIfLeader: true [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.589; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.592; org.eclipse.jetty.ser= ver.AbstractConnector; Started SocketConnector@127.0.0.1:33694 [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.593; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.594; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.595; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: /usr/home/hudson/= hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/t= est/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-13657483893= 58 [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.595; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/te= st/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-136574838935= 8/solr.xml [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.596; org.apache.solr.core.= CoreContainer; New CoreContainer 1803151602 [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.597; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/usr/home/hudson/hud= son-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test= /J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1365748389358/= ' [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.598; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/= test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1365748389= 358/' [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.668; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.669; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.670; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.670; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.671; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.671; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.672; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.673; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.673; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.674; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D120000&connTimeout=3D1= 5000&retry=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.695; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.715; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:46956/solr [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.716; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.717; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.720; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@38ce4e2 name:ZooKeeperConnection Watcher:127.0.0.1:46956 got event W= atchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.721; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.739; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D500&maxConnectionsPerHost=3D16&socketTimeout=3D120000&connTimeout=3D150= 00 [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.750; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.752; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@3256a641 name:ZooKeeperConnection Watcher:127.0.0.1:46956/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.753; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 06:33:09.765; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:10.343; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:10.344; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "core_node_name":"127.0.0.1:45726_m%2Fao_collection1= ", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "shard":"shard1", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"recovering", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:45726_m%2Fao", [junit4:junit4] 1> "base_url":"http://127.0.0.1:45726/m/ao"} [junit4:junit4] 1> INFO - 2013-04-12 06:33:10.358; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 06:33:10.358; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 06:33:10.358; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 06:33:10.358; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 06:33:10.358; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 06:33:10.358; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 06:33:10.435; org.apache.solr.handl= er.admin.CoreAdminHandler; Waited coreNodeName: 127.0.0.1:45726_m%2Fao_coll= ection1, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seco= nds. [junit4:junit4] 1> INFO - 2013-04-12 06:33:10.435; org.apache.solr.servl= et.SolrDispatchFilter; [admin] webapp=3Dnull path=3D/admin/cores params=3D{= coreNodeName=3D127.0.0.1:45726_m%252Fao_collection1&state=3Drecovering&node= Name=3D127.0.0.1:45726_m%252Fao&action=3DPREPRECOVERY&checkLive=3Dtrue&core= =3Dcollection1&wt=3Djavabin&onlyIfLeader=3Dtrue&version=3D2} status=3D0 QTi= me=3D1002=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:10.769; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:336= 94_m%2Fao [junit4:junit4] 1> INFO - 2013-04-12 06:33:10.771; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:33694_m%2Fao [junit4:junit4] 1> INFO - 2013-04-12 06:33:10.773; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 06:33:10.773; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 06:33:10.773; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 06:33:10.774; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-12 06:33:10.774; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-12 06:33:10.774; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-12 06:33:10.775; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-12 06:33:10.775; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 06:33:10.775; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 06:33:10.775; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 06:33:10.782; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-12 06:33:10.783; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-12 06:33:10.788; org.apache.solr.core.= CoreContainer; Creating SolrCore 'collection1' using instanceDir: /usr/home= /hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/sol= r-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-136= 5748389358/collection1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:10.789; org.apache.solr.cloud= .ZkController; Check for collection zkNode:collection1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:10.789; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-12 06:33:10.790; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/collection1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:10.791; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/= test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1365748389= 358/collection1/' [junit4:junit4] 1> INFO - 2013-04-12 06:33:10.792; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cl= oud.ChaosMonkeyShardSplitTest-jetty4-1365748389358/collection1/lib/README' = to classloader [junit4:junit4] 1> INFO - 2013-04-12 06:33:10.793; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cl= oud.ChaosMonkeyShardSplitTest-jetty4-1365748389358/collection1/lib/classes/= ' to classloader [junit4:junit4] 1> INFO - 2013-04-12 06:33:10.842; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-12 06:33:10.905; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.006; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.012; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.668; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.679; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.684; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.697; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.703; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.708; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-12 06:33:11.709; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-12 06:33:11.709; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.710; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-12 06:33:11.711; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-12 06:33:11.711; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.712; org.apache.solr.core.= SolrCore; solr.NRTCachingDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.712; org.apache.solr.core.= SolrCore; [collection1] Opening new SolrCore at /usr/home/hudson/hudson-sla= ve/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/./o= rg.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1365748389358/collect= ion1/, dataDir=3D./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-13657483= 72760/jetty4/ [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.713; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@3172cef6 [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.713; org.apache.solr.core.= SolrCore; solr.NRTCachingDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.714; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/o= rg.apache.solr.cloud.ChaosMonkeyShardSplitTest-1365748372760/jetty4 [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.715; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D./org.apache.solr.= cloud.ChaosMonkeyShardSplitTest-1365748372760/jetty4/index/ [junit4:junit4] 1> WARN - 2013-04-12 06:33:11.716; org.apache.solr.core.= SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.Chaos= MonkeyShardSplitTest-1365748372760/jetty4/index' doesn't exist. Creating ne= w index... [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.716; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/o= rg.apache.solr.cloud.ChaosMonkeyShardSplitTest-1365748372760/jetty4/index [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.728; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DNRTCachingDirectory(org.apache.lucene.= store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMon= keyShardSplitTest-1365748372760/jetty4/index lockFactory=3Dorg.apache.lucen= e.store.NativeFSLockFactory@18edd7f6; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.= 0),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.729; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.732; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.732; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.733; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.734; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.735; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.735; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.735; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.736; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.737; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.750; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.758; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@19b13232 main [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.759; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.759; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.764; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@19b13232 main{Stan= dardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.766; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Ddown [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.767; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.862; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.863; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "core_node_name":null, [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "shard":null, [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"down", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:33694_m%2Fao", [junit4:junit4] 1> "base_url":"http://127.0.0.1:33694/m/ao"} [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.863; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Collection already exists with numShards=3D2 [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.863; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Assigning new node to shard=3Dshard2 [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.879; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.879; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.879; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.879; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.879; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 06:33:11.879; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.437; org.apache.solr.cloud= .RecoveryStrategy; Attempting to PeerSync from http://127.0.0.1:62829/m/ao/= collection1/ core=3Dcollection1 - recoveringAfterStartup=3Dtrue [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.437; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dcollection1 url=3Dhttp://127.0.0.1:45726/m/ao = START replicas=3D[http://127.0.0.1:62829/m/ao/collection1/] nUpdates=3D100 [junit4:junit4] 1> WARN - 2013-04-12 06:33:12.438; org.apache.solr.updat= e.PeerSync; no frame of reference to tell of we've missed updates [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.439; org.apache.solr.cloud= .RecoveryStrategy; PeerSync Recovery was not successful - trying replicatio= n. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.439; org.apache.solr.cloud= .RecoveryStrategy; Starting Replication Recovery. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.439; org.apache.solr.cloud= .RecoveryStrategy; Begin buffering updates. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.439; org.apache.solr.updat= e.UpdateLog; Starting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog= =3Dnull} [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.440; org.apache.solr.cloud= .RecoveryStrategy; Attempting to replicate from http://127.0.0.1:62829/m/ao= /collection1/. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.440; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.446; org.apache.solr.core.= SolrCore; [collection1] webapp=3D/m/ao path=3D/get params=3D{getVersions=3D= 100&distrib=3Dfalse&wt=3Djavabin&qt=3D/get&version=3D2} status=3D0 QTime=3D= 0=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.457; org.apache.solr.updat= e.DirectUpdateHandler2; start commit{,optimize=3Dfalse,openSearcher=3Dfalse= ,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse,prepareCommi= t=3Dfalse} [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.462; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DNRTCachingDirectory(org.apache.lucene.= store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMon= keyShardSplitTest-1365748372760/jetty1/index lockFactory=3Dorg.apache.lucen= e.store.NativeFSLockFactory@155387cb; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.= 0),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.463; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.494; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 1> =09commit{dir=3DNRTCachingDirectory(org.apache.lucene.= store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMon= keyShardSplitTest-1365748372760/jetty1/index lockFactory=3Dorg.apache.lucen= e.store.NativeFSLockFactory@155387cb; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.= 0),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> =09commit{dir=3DNRTCachingDirectory(org.apache.lucene.= store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMon= keyShardSplitTest-1365748372760/jetty1/index lockFactory=3Dorg.apache.lucen= e.store.NativeFSLockFactory@155387cb; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.= 0),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_2] [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.494; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 2[segments_2] [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.496; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@5ab93d3 realtime [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.496; org.apache.solr.updat= e.DirectUpdateHandler2; end_commit_flush [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.497; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{waitSearcher=3Dtrue&openSearcher=3Dfalse&commit=3Dtrue&wt=3Djava= bin&commit_end_point=3Dtrue&version=3D2&softCommit=3Dfalse} {commit=3D} 0 4= 0 [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.498; org.apache.solr.handl= er.ReplicationHandler; Commits will be reserved for 10000 [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.498; org.apache.solr.handl= er.SnapPuller; No value set for 'pollInterval'. Timer Task not started. [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.502; org.apache.solr.handl= er.ReplicationHandler; Commits will be reserved for 10000 [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.502; org.apache.solr.core.= SolrCore; [collection1] webapp=3D/m/ao path=3D/replication params=3D{comman= d=3Dindexversion&qt=3D/replication&wt=3Djavabin&version=3D2} status=3D0 QTi= me=3D2=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.503; org.apache.solr.handl= er.SnapPuller; Master's generation: 2 [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.503; org.apache.solr.handl= er.SnapPuller; Slave's generation: 1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.503; org.apache.solr.handl= er.SnapPuller; Starting replication process [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.507; org.apache.solr.core.= SolrCore; [collection1] webapp=3D/m/ao path=3D/replication params=3D{comman= d=3Dfilelist&qt=3D/replication&wt=3Djavabin&generation=3D2&version=3D2} sta= tus=3D0 QTime=3D1=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.508; org.apache.solr.handl= er.SnapPuller; Number of files in latest index in master: 1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.509; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/o= rg.apache.solr.cloud.ChaosMonkeyShardSplitTest-1365748372760/jetty3/index.2= 0130412023312508 [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.510; org.apache.solr.handl= er.SnapPuller; Starting download to NRTCachingDirectory(org.apache.lucene.s= tore.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tes= ts-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonk= eyShardSplitTest-1365748372760/jetty3/index.20130412023312508 lockFactory= =3Dorg.apache.lucene.store.NativeFSLockFactory@405a7ca2; maxCacheMB=3D48.0 = maxMergeSizeMB=3D4.0) fullCopy=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.513; org.apache.solr.core.= SolrCore; [collection1] webapp=3D/m/ao path=3D/replication params=3D{file= =3Dsegments_2&command=3Dfilecontent&checksum=3Dtrue&wt=3Dfilestream&qt=3D/r= eplication&generation=3D2} status=3D0 QTime=3D0=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.515; org.apache.solr.handl= er.SnapPuller; Total time taken for download : 0 secs [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.518; org.apache.solr.updat= e.DefaultSolrCoreState; Creating new IndexWriter... [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.518; org.apache.solr.updat= e.DefaultSolrCoreState; Waiting until IndexWriter is unused... core=3Dcolle= ction1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.523; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits:num=3D2 [junit4:junit4] 1> =09commit{dir=3DNRTCachingDirectory(org.apache.lucene.= store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMon= keyShardSplitTest-1365748372760/jetty3/index lockFactory=3Dorg.apache.lucen= e.store.NativeFSLockFactory@33ac1a4; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.0= ),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> =09commit{dir=3DNRTCachingDirectory(org.apache.lucene.= store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMon= keyShardSplitTest-1365748372760/jetty3/index lockFactory=3Dorg.apache.lucen= e.store.NativeFSLockFactory@33ac1a4; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.0= ),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_2] [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.523; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 2[segments_2] [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.524; org.apache.solr.updat= e.DefaultSolrCoreState; New IndexWriter is ready to be used. [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.525; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@62562960 main [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.526; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@62562960 main{Stan= dardDirectoryReader(segments_2:1:nrt)} [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.527; org.apache.solr.core.= CachingDirectoryFactory; looking to close /usr/home/hudson/hudson-slave/wor= kspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apach= e.solr.cloud.ChaosMonkeyShardSplitTest-1365748372760/jetty3/index.201304120= 23312508 [CachedDir<>] [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.527; org.apache.solr.core.= CachingDirectoryFactory; Closing directory: /usr/home/hudson/hudson-slave/w= orkspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apa= che.solr.cloud.ChaosMonkeyShardSplitTest-1365748372760/jetty3/index.2013041= 2023312508 [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.527; org.apache.solr.core.= CachingDirectoryFactory; Removing directory before core close: /usr/home/hu= dson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-c= ore/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1365748372760/j= etty3/index.20130412023312508 [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.529; org.apache.solr.cloud= .RecoveryStrategy; No replay needed. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.529; org.apache.solr.cloud= .RecoveryStrategy; Replication Recovery was successful - registering as Act= ive. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.529; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Dactive [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.529; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.531; org.apache.solr.cloud= .RecoveryStrategy; Finished recovery process. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.769; org.apache.solr.core.= CoreContainer; registering core: collection1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.769; org.apache.solr.cloud= .ZkController; Register replica - core:collection1 address:http://127.0.0.1= :33694/m/ao collection:collection1 shard:shard2 [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.797; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:33694/m/ao/collection1/ and leader i= s http://127.0.0.1:15572/m/ao/collection1/ [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.797; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dcollection1 baseURL=3Dhttp://= 127.0.0.1:33694/m/ao [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.797; org.apache.solr.cloud= .ZkController; Core needs to recover:collection1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.797; org.apache.solr.updat= e.DefaultSolrCoreState; Running recovery - first canceling any ongoing reco= very [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.798; org.apache.solr.cloud= .RecoveryStrategy; Starting recovery process. core=3Dcollection1 recoverin= gAfterStartup=3Dtrue [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.798; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.799; org.apache.solr.cloud= .RecoveryStrategy; ###### startupVersions=3D[] [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.799; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Drecovering [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.800; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.800; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0 [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.801; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.801; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.801; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.825; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.827; org.apache.solr.handl= er.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:33694_= m%2Fao_collection1, state: recovering, checkLive: true, onlyIfLeader: true [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.827; org.apache.solr.cloud= .AbstractFullDistribZkTestBase; Wait for recoveries to finish - wait 15 for= each attempt [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.828; org.apache.solr.cloud= .AbstractDistribZkTestBase; Wait for recoveries to finish - collection: col= lection1 failOnTimeout:true timeout (sec):15 [junit4:junit4] 1> INFO - 2013-04-12 06:33:12.828; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:13.384; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:13.386; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "core_node_name":"127.0.0.1:45726_m%2Fao_collection1= ", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "shard":"shard1", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:45726_m%2Fao", [junit4:junit4] 1> "base_url":"http://127.0.0.1:45726/m/ao"} [junit4:junit4] 1> INFO - 2013-04-12 06:33:13.418; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "core_node_name":"127.0.0.1:33694_m%2Fao_collection1= ", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "shard":"shard2", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"recovering", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:33694_m%2Fao", [junit4:junit4] 1> "base_url":"http://127.0.0.1:33694/m/ao"} [junit4:junit4] 1> INFO - 2013-04-12 06:33:13.438; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 06:33:13.438; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 06:33:13.438; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 06:33:13.438; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 06:33:13.438; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 06:33:13.438; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 06:33:13.828; org.apache.solr.handl= er.admin.CoreAdminHandler; Waited coreNodeName: 127.0.0.1:33694_m%2Fao_coll= ection1, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seco= nds. [junit4:junit4] 1> INFO - 2013-04-12 06:33:13.828; org.apache.solr.servl= et.SolrDispatchFilter; [admin] webapp=3Dnull path=3D/admin/cores params=3D{= coreNodeName=3D127.0.0.1:33694_m%252Fao_collection1&state=3Drecovering&node= Name=3D127.0.0.1:33694_m%252Fao&action=3DPREPRECOVERY&checkLive=3Dtrue&core= =3Dcollection1&wt=3Djavabin&onlyIfLeader=3Dtrue&version=3D2} status=3D0 QTi= me=3D1002=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:13.831; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:14.833; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.831; org.apache.solr.cloud= .RecoveryStrategy; Attempting to PeerSync from http://127.0.0.1:15572/m/ao/= collection1/ core=3Dcollection1 - recoveringAfterStartup=3Dtrue [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.831; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dcollection1 url=3Dhttp://127.0.0.1:33694/m/ao = START replicas=3D[http://127.0.0.1:15572/m/ao/collection1/] nUpdates=3D100 [junit4:junit4] 1> WARN - 2013-04-12 06:33:15.832; org.apache.solr.updat= e.PeerSync; no frame of reference to tell of we've missed updates [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.832; org.apache.solr.cloud= .RecoveryStrategy; PeerSync Recovery was not successful - trying replicatio= n. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.833; org.apache.solr.cloud= .RecoveryStrategy; Starting Replication Recovery. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.833; org.apache.solr.cloud= .RecoveryStrategy; Begin buffering updates. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.833; org.apache.solr.updat= e.UpdateLog; Starting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog= =3Dnull} [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.833; org.apache.solr.cloud= .RecoveryStrategy; Attempting to replicate from http://127.0.0.1:15572/m/ao= /collection1/. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.834; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.835; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.844; org.apache.solr.core.= SolrCore; [collection1] webapp=3D/m/ao path=3D/get params=3D{getVersions=3D= 100&distrib=3Dfalse&wt=3Djavabin&qt=3D/get&version=3D2} status=3D0 QTime=3D= 0=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.847; org.apache.solr.updat= e.DirectUpdateHandler2; start commit{,optimize=3Dfalse,openSearcher=3Dfalse= ,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse,prepareCommi= t=3Dfalse} [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.852; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DNRTCachingDirectory(org.apache.lucene.= store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMon= keyShardSplitTest-1365748372760/jetty2/index lockFactory=3Dorg.apache.lucen= e.store.NativeFSLockFactory@46db9675; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.= 0),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.853; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.857; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 1> =09commit{dir=3DNRTCachingDirectory(org.apache.lucene.= store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMon= keyShardSplitTest-1365748372760/jetty2/index lockFactory=3Dorg.apache.lucen= e.store.NativeFSLockFactory@46db9675; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.= 0),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> =09commit{dir=3DNRTCachingDirectory(org.apache.lucene.= store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMon= keyShardSplitTest-1365748372760/jetty2/index lockFactory=3Dorg.apache.lucen= e.store.NativeFSLockFactory@46db9675; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.= 0),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_2] [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.858; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 2[segments_2] [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.860; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@1207eb63 realtime [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.860; org.apache.solr.updat= e.DirectUpdateHandler2; end_commit_flush [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.860; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{waitSearcher=3Dtrue&openSearcher=3Dfalse&commit=3Dtrue&wt=3Djava= bin&commit_end_point=3Dtrue&version=3D2&softCommit=3Dfalse} {commit=3D} 0 1= 3 [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.862; org.apache.solr.handl= er.ReplicationHandler; Commits will be reserved for 10000 [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.862; org.apache.solr.handl= er.SnapPuller; No value set for 'pollInterval'. Timer Task not started. [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.864; org.apache.solr.handl= er.ReplicationHandler; Commits will be reserved for 10000 [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.865; org.apache.solr.core.= SolrCore; [collection1] webapp=3D/m/ao path=3D/replication params=3D{comman= d=3Dindexversion&qt=3D/replication&wt=3Djavabin&version=3D2} status=3D0 QTi= me=3D1=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.865; org.apache.solr.handl= er.SnapPuller; Master's generation: 2 [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.866; org.apache.solr.handl= er.SnapPuller; Slave's generation: 1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.866; org.apache.solr.handl= er.SnapPuller; Starting replication process [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.869; org.apache.solr.core.= SolrCore; [collection1] webapp=3D/m/ao path=3D/replication params=3D{comman= d=3Dfilelist&qt=3D/replication&wt=3Djavabin&generation=3D2&version=3D2} sta= tus=3D0 QTime=3D1=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.870; org.apache.solr.handl= er.SnapPuller; Number of files in latest index in master: 1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.872; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/o= rg.apache.solr.cloud.ChaosMonkeyShardSplitTest-1365748372760/jetty4/index.2= 0130412023315870 [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.872; org.apache.solr.handl= er.SnapPuller; Starting download to NRTCachingDirectory(org.apache.lucene.s= tore.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tes= ts-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonk= eyShardSplitTest-1365748372760/jetty4/index.20130412023315870 lockFactory= =3Dorg.apache.lucene.store.NativeFSLockFactory@7ad45b6f; maxCacheMB=3D48.0 = maxMergeSizeMB=3D4.0) fullCopy=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.876; org.apache.solr.core.= SolrCore; [collection1] webapp=3D/m/ao path=3D/replication params=3D{file= =3Dsegments_2&command=3Dfilecontent&checksum=3Dtrue&wt=3Dfilestream&qt=3D/r= eplication&generation=3D2} status=3D0 QTime=3D0=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.878; org.apache.solr.handl= er.SnapPuller; Total time taken for download : 0 secs [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.880; org.apache.solr.updat= e.DefaultSolrCoreState; Creating new IndexWriter... [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.880; org.apache.solr.updat= e.DefaultSolrCoreState; Waiting until IndexWriter is unused... core=3Dcolle= ction1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.885; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits:num=3D2 [junit4:junit4] 1> =09commit{dir=3DNRTCachingDirectory(org.apache.lucene.= store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMon= keyShardSplitTest-1365748372760/jetty4/index lockFactory=3Dorg.apache.lucen= e.store.NativeFSLockFactory@18edd7f6; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.= 0),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> =09commit{dir=3DNRTCachingDirectory(org.apache.lucene.= store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMon= keyShardSplitTest-1365748372760/jetty4/index lockFactory=3Dorg.apache.lucen= e.store.NativeFSLockFactory@18edd7f6; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.= 0),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_2] [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.886; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 2[segments_2] [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.886; org.apache.solr.updat= e.DefaultSolrCoreState; New IndexWriter is ready to be used. [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.887; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@6ae24d54 main [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.889; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@6ae24d54 main{Stan= dardDirectoryReader(segments_2:1:nrt)} [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.889; org.apache.solr.core.= CachingDirectoryFactory; looking to close /usr/home/hudson/hudson-slave/wor= kspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apach= e.solr.cloud.ChaosMonkeyShardSplitTest-1365748372760/jetty4/index.201304120= 23315870 [CachedDir<>] [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.890; org.apache.solr.core.= CachingDirectoryFactory; Closing directory: /usr/home/hudson/hudson-slave/w= orkspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apa= che.solr.cloud.ChaosMonkeyShardSplitTest-1365748372760/jetty4/index.2013041= 2023315870 [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.890; org.apache.solr.core.= CachingDirectoryFactory; Removing directory before core close: /usr/home/hu= dson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-c= ore/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1365748372760/j= etty4/index.20130412023315870 [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.891; org.apache.solr.cloud= .RecoveryStrategy; No replay needed. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.892; org.apache.solr.cloud= .RecoveryStrategy; Replication Recovery was successful - registering as Act= ive. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.892; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Dactive [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.892; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-12 06:33:15.894; org.apache.solr.cloud= .RecoveryStrategy; Finished recovery process. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.446; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.447; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "core_node_name":"127.0.0.1:33694_m%2Fao_collection1= ", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "shard":"shard2", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:33694_m%2Fao", [junit4:junit4] 1> "base_url":"http://127.0.0.1:33694/m/ao"} [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.473; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.473; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.473; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.473; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.473; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.473; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.837; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.838; org.apache.solr.cloud= .AbstractDistribZkTestBase; Recoveries finished - collection: collection1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.850; org.apache.solr.updat= e.DirectUpdateHandler2; start commit{,optimize=3Dfalse,openSearcher=3Dtrue,= waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse,prepareCommit= =3Dfalse} [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.855; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DNRTCachingDirectory(org.apache.lucene.= store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMon= keyShardSplitTest-1365748372760/control/data/index lockFactory=3Dorg.apache= .lucene.store.NativeFSLockFactory@158a80bc; maxCacheMB=3D48.0 maxMergeSizeM= B=3D4.0),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.856; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.888; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 1> =09commit{dir=3DNRTCachingDirectory(org.apache.lucene.= store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMon= keyShardSplitTest-1365748372760/control/data/index lockFactory=3Dorg.apache= .lucene.store.NativeFSLockFactory@158a80bc; maxCacheMB=3D48.0 maxMergeSizeM= B=3D4.0),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> =09commit{dir=3DNRTCachingDirectory(org.apache.lucene.= store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMon= keyShardSplitTest-1365748372760/control/data/index lockFactory=3Dorg.apache= .lucene.store.NativeFSLockFactory@158a80bc; maxCacheMB=3D48.0 maxMergeSizeM= B=3D4.0),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_2] [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.888; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 2[segments_2] [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.890; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@28fdebb3 main [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.891; org.apache.solr.updat= e.DirectUpdateHandler2; end_commit_flush [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.892; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@28fdebb3 main{Stan= dardDirectoryReader(segments_2:1:nrt)} [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.893; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{waitSearcher=3Dtrue&commit=3Dtrue&wt=3Djavabin&version=3D2&softC= ommit=3Dfalse} {commit=3D} 0 43 [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.906; org.apache.solr.updat= e.DirectUpdateHandler2; start commit{,optimize=3Dfalse,openSearcher=3Dtrue,= waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse,prepareCommit= =3Dfalse} [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.920; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 1> =09commit{dir=3DNRTCachingDirectory(org.apache.lucene.= store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMon= keyShardSplitTest-1365748372760/jetty1/index lockFactory=3Dorg.apache.lucen= e.store.NativeFSLockFactory@155387cb; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.= 0),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_2] [junit4:junit4] 1> =09commit{dir=3DNRTCachingDirectory(org.apache.lucene.= store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMon= keyShardSplitTest-1365748372760/jetty1/index lockFactory=3Dorg.apache.lucen= e.store.NativeFSLockFactory@155387cb; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.= 0),segFN=3Dsegments_3,generation=3D3,filenames=3D[segments_3] [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.920; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 3[segments_3] [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.921; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@517c0865 main [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.922; org.apache.solr.updat= e.DirectUpdateHandler2; end_commit_flush [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.923; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@517c0865 main{Stan= dardDirectoryReader(segments_2:1:nrt)} [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.924; org.apache.solr.updat= e.SolrCmdDistributor; Distrib commit to:[StdNode: http://127.0.0.1:45726/m/= ao/collection1/, StdNode: http://127.0.0.1:15572/m/ao/collection1/, StdNode= : http://127.0.0.1:33694/m/ao/collection1/] params:commit_end_point=3Dtrue&= commit=3Dtrue&softCommit=3Dfalse&waitSearcher=3Dtrue&expungeDeletes=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.927; org.apache.solr.updat= e.DirectUpdateHandler2; start commit{,optimize=3Dfalse,openSearcher=3Dtrue,= waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse,prepareCommit= =3Dfalse} [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.936; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 1> =09commit{dir=3DNRTCachingDirectory(org.apache.lucene.= store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMon= keyShardSplitTest-1365748372760/jetty2/index lockFactory=3Dorg.apache.lucen= e.store.NativeFSLockFactory@46db9675; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.= 0),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_2] [junit4:junit4] 1> =09commit{dir=3DNRTCachingDirectory(org.apache.lucene.= store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMon= keyShardSplitTest-1365748372760/jetty2/index lockFactory=3Dorg.apache.lucen= e.store.NativeFSLockFactory@46db9675; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.= 0),segFN=3Dsegments_3,generation=3D3,filenames=3D[segments_3] [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.937; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 3[segments_3] [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.939; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@6eb2c860 main [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.939; org.apache.solr.updat= e.DirectUpdateHandler2; end_commit_flush [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.940; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@6eb2c860 main{Stan= dardDirectoryReader(segments_2:1:nrt)} [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.941; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{waitSearcher=3Dtrue&commit=3Dtrue&wt=3Djavabin&expungeDeletes=3D= false&commit_end_point=3Dtrue&version=3D2&softCommit=3Dfalse} {commit=3D} 0= 14 [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.943; org.apache.solr.updat= e.DirectUpdateHandler2; start commit{,optimize=3Dfalse,openSearcher=3Dtrue,= waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse,prepareCommit= =3Dfalse} [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.945; org.apache.solr.updat= e.DirectUpdateHandler2; start commit{,optimize=3Dfalse,openSearcher=3Dtrue,= waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse,prepareCommit= =3Dfalse} [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.958; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 1> =09commit{dir=3DNRTCachingDirectory(org.apache.lucene.= store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMon= keyShardSplitTest-1365748372760/jetty3/index lockFactory=3Dorg.apache.lucen= e.store.NativeFSLockFactory@33ac1a4; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.0= ),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_2] [junit4:junit4] 1> =09commit{dir=3DNRTCachingDirectory(org.apache.lucene.= store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMon= keyShardSplitTest-1365748372760/jetty3/index lockFactory=3Dorg.apache.lucen= e.store.NativeFSLockFactory@33ac1a4; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.0= ),segFN=3Dsegments_3,generation=3D3,filenames=3D[segments_3] [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.959; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 1> =09commit{dir=3DNRTCachingDirectory(org.apache.lucene.= store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMon= keyShardSplitTest-1365748372760/jetty4/index lockFactory=3Dorg.apache.lucen= e.store.NativeFSLockFactory@18edd7f6; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.= 0),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_2] [junit4:junit4] 1> =09commit{dir=3DNRTCachingDirectory(org.apache.lucene.= store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Te= sts-trunk-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMon= keyShardSplitTest-1365748372760/jetty4/index lockFactory=3Dorg.apache.lucen= e.store.NativeFSLockFactory@18edd7f6; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.= 0),segFN=3Dsegments_3,generation=3D3,filenames=3D[segments_3] [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.959; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 3[segments_3] [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.960; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 3[segments_3] [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.963; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@23d3f467 main [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.963; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@2b8e060 main [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.963; org.apache.solr.updat= e.DirectUpdateHandler2; end_commit_flush [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.964; org.apache.solr.updat= e.DirectUpdateHandler2; end_commit_flush [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.964; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@23d3f467 main{Stan= dardDirectoryReader(segments_2:1:nrt)} [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.965; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@2b8e060 main{Stand= ardDirectoryReader(segments_2:1:nrt)} [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.965; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{waitSearcher=3Dtrue&commit=3Dtrue&wt=3Djavabin&expungeDeletes=3D= false&commit_end_point=3Dtrue&version=3D2&softCommit=3Dfalse} {commit=3D} 0= 22 [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.966; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{waitSearcher=3Dtrue&commit=3Dtrue&wt=3Djavabin&expungeDeletes=3D= false&commit_end_point=3Dtrue&version=3D2&softCommit=3Dfalse} {commit=3D} 0= 21 [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.967; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{waitSearcher=3Dtrue&commit=3Dtrue&wt=3Djavabin&version=3D2&softC= ommit=3Dfalse} {commit=3D} 0 62 [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.968; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.971; org.apache.solr.core.= SolrCore; [collection1] webapp=3D/m/ao path=3D/select params=3D{tests=3Dche= ckShardConsistency&q=3D*:*&distrib=3Dfalse&wt=3Djavabin&version=3D2&rows=3D= 0} hits=3D0 status=3D0 QTime=3D0=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.974; org.apache.solr.core.= SolrCore; [collection1] webapp=3D/m/ao path=3D/select params=3D{tests=3Dche= ckShardConsistency&q=3D*:*&distrib=3Dfalse&wt=3Djavabin&version=3D2&rows=3D= 0} hits=3D0 status=3D0 QTime=3D1=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.976; org.apache.solr.core.= SolrCore; [collection1] webapp=3D/m/ao path=3D/select params=3D{tests=3Dche= ckShardConsistency&q=3D*:*&distrib=3Dfalse&wt=3Djavabin&version=3D2&rows=3D= 0} hits=3D0 status=3D0 QTime=3D0=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:16.979; org.apache.solr.core.= SolrCore; [collection1] webapp=3D/m/ao path=3D/select params=3D{tests=3Dche= ckShardConsistency&q=3D*:*&distrib=3Dfalse&wt=3Djavabin&version=3D2&rows=3D= 0} hits=3D0 status=3D0 QTime=3D1=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:18.981; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 06:33:18.984; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@42048907 name:ZooKeeperConnection Watcher:127.0.0.1:46956 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-12 06:33:18.984; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> / (2) [junit4:junit4] 1> DATA: [junit4:junit4] 1> =20 [junit4:junit4] 1> /solr (7) [junit4:junit4] 1> /solr/configs (1) [junit4:junit4] 1> /solr/configs/conf1 (9) [junit4:junit4] 1> /solr/configs/conf1/mapping-ISOLatin1Accent.txt (0= ) [junit4:junit4] 1> DATA: ...supressed... [junit4:junit4] 1> /solr/configs/conf1/currency.xml (0) [junit4:junit4] 1> DATA: ...supressed... [junit4:junit4] 1> /solr/configs/conf1/protwords.txt (0) [junit4:junit4] 1> DATA: ...supressed... [junit4:junit4] 1> /solr/configs/conf1/synonyms.txt (0) [junit4:junit4] 1> DATA: ...supressed... [junit4:junit4] 1> /solr/configs/conf1/old_synonyms.txt (0) [junit4:junit4] 1> DATA: ...supressed... [junit4:junit4] 1> /solr/configs/conf1/solrconfig.xml (0) [junit4:junit4] 1> DATA: ...supressed... [junit4:junit4] 1> /solr/configs/conf1/stopwords.txt (0) [junit4:junit4] 1> DATA: ...supressed... [junit4:junit4] 1> /solr/configs/conf1/open-exchange-rates.json (0) [junit4:junit4] 1> DATA: [junit4:junit4] 1> { [junit4:junit4] 1> "disclaimer": "This data is not real, it was= synthetically created to match currency.xml. It is modeled after the data= format available from openexchangerates.org. See https://openexchangerate= s.org/documentation for details", [junit4:junit4] 1> "license": "http://www.apache.org/licenses/L= ICENSE-2.0", [junit4:junit4] 1> "timestamp": 1332070464, [junit4:junit4] 1> =20 [junit4:junit4] 1> =20 [junit4:junit4] 1> "IMPORTANT NOTE": "In order for tests to wor= k, this data must be kept in sync with ./currency.xml", [junit4:junit4] 1> =20 [junit4:junit4] 1> =20 [junit4:junit4] 1> "base": "USD", [junit4:junit4] 1> "rates": { [junit4:junit4] 1> "USD": 1, [junit4:junit4] 1> "JPY": 81.29, [junit4:junit4] 1> "EUR": 2.5, [junit4:junit4] 1> "GBP": 0.5, [junit4:junit4] 1> "MXN": 2.0 [junit4:junit4] 1> } [junit4:junit4] 1> } [junit4:junit4] 1> =20 [junit4:junit4] 1> /solr/configs/conf1/schema.xml (0) [junit4:junit4] 1> DATA: ...supressed... [junit4:junit4] 1> /solr/clusterstate.json (0) [junit4:junit4] 1> DATA: [junit4:junit4] 1> { [junit4:junit4] 1> "collection1":{ [junit4:junit4] 1> "shards":{ [junit4:junit4] 1> "shard1":{ [junit4:junit4] 1> "range":"80000000-ffffffff", [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "replicas":{ [junit4:junit4] 1> "127.0.0.1:62829_m%2Fao_collection1":{ [junit4:junit4] 1> "shard":"shard1", [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "node_name":"127.0.0.1:62829_m%2Fao"= , [junit4:junit4] 1> "base_url":"http://127.0.0.1:62829/m= /ao", [junit4:junit4] 1> "leader":"true"}, [junit4:junit4] 1> "127.0.0.1:45726_m%2Fao_collection1":{ [junit4:junit4] 1> "shard":"shard1", [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "node_name":"127.0.0.1:45726_m%2Fao"= , [junit4:junit4] 1> "base_url":"http://127.0.0.1:45726/m= /ao"}}}, [junit4:junit4] 1> "shard2":{ [junit4:junit4] 1> "range":"0-7fffffff", [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "replicas":{ [junit4:junit4] 1> "127.0.0.1:15572_m%2Fao_collection1":{ [junit4:junit4] 1> "shard":"shard2", [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "node_name":"127.0.0.1:15572_m%2Fao"= , [junit4:junit4] 1> "base_url":"http://127.0.0.1:15572/m= /ao", [junit4:junit4] 1> "leader":"true"}, [junit4:junit4] 1> "127.0.0.1:33694_m%2Fao_collection1":{ [junit4:junit4] 1> "shard":"shard2", [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "node_name":"127.0.0.1:33694_m%2Fao"= , [junit4:junit4] 1> "base_url":"http://127.0.0.1:33694/m= /ao"}}}}, [junit4:junit4] 1> "router":"compositeId"}, [junit4:junit4] 1> "control_collection":{ [junit4:junit4] 1> "shards":{"shard1":{ [junit4:junit4] 1> "range":"80000000-7fffffff", [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "replicas":{"127.0.0.1:50622_m%2Fao_coll= ection1":{ [junit4:junit4] 1> "shard":"shard1", [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"control_collection", [junit4:junit4] 1> "node_name":"127.0.0.1:50622_m%2Fao"= , [junit4:junit4] 1> "base_url":"http://127.0.0.1:50622/m= /ao", [junit4:junit4] 1> "leader":"true"}}}}, [junit4:junit4] 1> "router":"compositeId"}} [junit4:junit4] 1> /solr/aliases.json (0) [junit4:junit4] 1> /solr/live_nodes (5) [junit4:junit4] 1> /solr/live_nodes/127.0.0.1:15572_m%2Fao (0) [junit4:junit4] 1> /solr/live_nodes/127.0.0.1:62829_m%2Fao (0) [junit4:junit4] 1> /solr/live_nodes/127.0.0.1:50622_m%2Fao (0) [junit4:junit4] 1> /solr/live_nodes/127.0.0.1:45726_m%2Fao (0) [junit4:junit4] 1> /solr/live_nodes/127.0.0.1:33694_m%2Fao (0) [junit4:junit4] 1> /solr/overseer (3) [junit4:junit4] 1> DATA: [junit4:junit4] 1> =20 [junit4:junit4] 1> /solr/overseer/queue (0) [junit4:junit4] 1> /solr/overseer/queue-work (0) [junit4:junit4] 1> /solr/overseer/collection-queue-work (0) [junit4:junit4] 1> /solr/collections (2) [junit4:junit4] 1> /solr/collections/collection1 (3) [junit4:junit4] 1> DATA: [junit4:junit4] 1> {"configName":"conf1"} [junit4:junit4] 1> /solr/collections/collection1/shards (0) [junit4:junit4] 1> /solr/collections/collection1/leader_elect (2) [junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard1= (1) [junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard= 1/election (2) [junit4:junit4] 1> /solr/collections/collection1/leader_elect/shar= d1/election/89505685357592586-127.0.0.1:45726_m%2Fao_collection1-n_00000000= 01 (0) [junit4:junit4] 1> /solr/collections/collection1/leader_elect/shar= d1/election/89505685357592582-127.0.0.1:62829_m%2Fao_collection1-n_00000000= 00 (0) [junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard2= (1) [junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard= 2/election (2) [junit4:junit4] 1> /solr/collections/collection1/leader_elect/shar= d2/election/89505685357592588-127.0.0.1:33694_m%2Fao_collection1-n_00000000= 01 (0) [junit4:junit4] 1> /solr/collections/collection1/leader_elect/shar= d2/election/89505685357592584-127.0.0.1:15572_m%2Fao_collection1-n_00000000= 00 (0) [junit4:junit4] 1> /solr/collections/collection1/leaders (2) [junit4:junit4] 1> /solr/collections/collection1/leaders/shard1 (0) [junit4:junit4] 1> DATA: [junit4:junit4] 1> { [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "node_name":"127.0.0.1:62829_m%2Fao", [junit4:junit4] 1> "base_url":"http://127.0.0.1:62829/m/ao"} [junit4:junit4] 1> /solr/collections/collection1/leaders/shard2 (0) [junit4:junit4] 1> DATA: [junit4:junit4] 1> { [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "node_name":"127.0.0.1:15572_m%2Fao", [junit4:junit4] 1> "base_url":"http://127.0.0.1:15572/m/ao"} [junit4:junit4] 1> /solr/collections/control_collection (3) [junit4:junit4] 1> DATA: [junit4:junit4] 1> {"configName":"conf1"} [junit4:junit4] 1> /solr/collections/control_collection/shards (0) [junit4:junit4] 1> /solr/collections/control_collection/leader_elect = (1) [junit4:junit4] 1> /solr/collections/control_collection/leader_elect= /shard1 (1) [junit4:junit4] 1> /solr/collections/control_collection/leader_elec= t/shard1/election (1) [junit4:junit4] 1> /solr/collections/control_collection/leader_ele= ct/shard1/election/89505685357592579-127.0.0.1:50622_m%2Fao_collection1-n_0= 000000000 (0) [junit4:junit4] 1> /solr/collections/control_collection/leaders (1) [junit4:junit4] 1> /solr/collections/control_collection/leaders/shar= d1 (0) [junit4:junit4] 1> DATA: [junit4:junit4] 1> { [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "node_name":"127.0.0.1:50622_m%2Fao", [junit4:junit4] 1> "base_url":"http://127.0.0.1:50622/m/ao"} [junit4:junit4] 1> /solr/overseer_elect (2) [junit4:junit4] 1> /solr/overseer_elect/election (5) [junit4:junit4] 1> /solr/overseer_elect/election/89505685357592582-12= 7.0.0.1:62829_m%2Fao-n_0000000001 (0) [junit4:junit4] 1> /solr/overseer_elect/election/89505685357592584-12= 7.0.0.1:15572_m%2Fao-n_0000000002 (0) [junit4:junit4] 1> /solr/overseer_elect/election/89505685357592579-12= 7.0.0.1:50622_m%2Fao-n_0000000000 (0) [junit4:junit4] 1> /solr/overseer_elect/election/89505685357592588-12= 7.0.0.1:33694_m%2Fao-n_0000000004 (0) [junit4:junit4] 1> /solr/overseer_elect/election/89505685357592586-12= 7.0.0.1:45726_m%2Fao-n_0000000003 (0) [junit4:junit4] 1> /solr/overseer_elect/leader (0) [junit4:junit4] 1> DATA: [junit4:junit4] 1> {"id":"89505685357592579-127.0.0.1:50622_m%2Fao= -n_0000000000"} [junit4:junit4] 1> /zookeeper (1) [junit4:junit4] 1> DATA: [junit4:junit4] 1> =20 [junit4:junit4] 1>=20 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.126; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{update.distrib=3DFROMLEADER&_version_=3D-1432090993354604544&upd= ate.from=3Dhttp://127.0.0.1:62829/m/ao/collection1/&wt=3Djavabin&version=3D= 2} {deleteByQuery=3D*:* (-1432090993354604544)} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.131; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{update.distrib=3DFROMLEADER&_version_=3D-1432090993359847424&upd= ate.from=3Dhttp://127.0.0.1:15572/m/ao/collection1/&wt=3Djavabin&version=3D= 2} {deleteByQuery=3D*:* (-1432090993359847424)} 0 3 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.132; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{update.distrib=3DTOLEADER&wt=3Djavabin&version=3D2} {deleteByQue= ry=3D*:* (-1432090993359847424)} 0 8 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.132; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{wt=3Djavabin&version=3D2} {deleteByQuery=3D*:* (-143209099335460= 4544)} 0 14 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.138; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{wt=3Djavabin&version=3D2} {add=3D[0 (1432090993371381760)]} 0 3 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.148; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{distrib.from=3Dhttp://127.0.0.1:62829/m/ao/collection1/&update.d= istrib=3DFROMLEADER&wt=3Djavabin&version=3D2} {add=3D[0 (143209099337872179= 2)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.148; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{distrib.from=3Dhttp://127.0.0.1:15572/m/ao/collection1/&update.d= istrib=3DTOLEADER&wt=3Djavabin&version=3D2} {add=3D[0 (1432090993378721792)= ]} 0 6 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.149; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{wt=3Djavabin&version=3D2} {add=3D[0]} 0 9 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.153; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{wt=3Djavabin&version=3D2} {add=3D[1 (1432090993389207552)]} 0 1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.160; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{distrib.from=3Dhttp://127.0.0.1:62829/m/ao/collection1/&update.d= istrib=3DFROMLEADER&wt=3Djavabin&version=3D2} {add=3D[1 (143209099339340185= 6)]} 0 1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.160; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{wt=3Djavabin&version=3D2} {add=3D[1 (1432090993393401856)]} 0 4 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.164; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{wt=3Djavabin&version=3D2} {add=3D[2 (1432090993400741888)]} 0 1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.173; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{distrib.from=3Dhttp://127.0.0.1:15572/m/ao/collection1/&update.d= istrib=3DFROMLEADER&wt=3Djavabin&version=3D2} {add=3D[2 (143209099340493619= 2)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.173; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{wt=3Djavabin&version=3D2} {add=3D[2 (1432090993404936192)]} 0 6 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.177; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{wt=3Djavabin&version=3D2} {add=3D[3 (1432090993414373376)]} 0 1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.184; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{distrib.from=3Dhttp://127.0.0.1:15572/m/ao/collection1/&update.d= istrib=3DFROMLEADER&wt=3Djavabin&version=3D2} {add=3D[3 (143209099341856768= 0)]} 0 1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.184; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{wt=3Djavabin&version=3D2} {add=3D[3 (1432090993418567680)]} 0 4 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.188; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{wt=3Djavabin&version=3D2} {add=3D[4 (1432090993425907712)]} 0 1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.194; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{distrib.from=3Dhttp://127.0.0.1:62829/m/ao/collection1/&update.d= istrib=3DFROMLEADER&wt=3Djavabin&version=3D2} {add=3D[4 (143209099342905344= 0)]} 0 1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.194; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{wt=3Djavabin&version=3D2} {add=3D[4 (1432090993429053440)]} 0 4 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.198; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{wt=3Djavabin&version=3D2} {add=3D[5 (1432090993436393472)]} 0 1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.204; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{distrib.from=3Dhttp://127.0.0.1:15572/m/ao/collection1/&update.d= istrib=3DFROMLEADER&wt=3Djavabin&version=3D2} {add=3D[5 (143209099343953920= 0)]} 0 1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.204; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{wt=3Djavabin&version=3D2} {add=3D[5 (1432090993439539200)]} 0 4 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.208; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{wt=3Djavabin&version=3D2} {add=3D[6 (1432090993446879232)]} 0 1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.217; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{distrib.from=3Dhttp://127.0.0.1:15572/m/ao/collection1/&update.d= istrib=3DFROMLEADER&wt=3Djavabin&version=3D2} {add=3D[6 (143209099345317068= 8)]} 0 1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.218; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{distrib.from=3Dhttp://127.0.0.1:62829/m/ao/collection1/&update.d= istrib=3DTOLEADER&wt=3Djavabin&version=3D2} {add=3D[6 (1432090993453170688)= ]} 0 5 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.218; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{wt=3Djavabin&version=3D2} {add=3D[6]} 0 7 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.222; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{wt=3Djavabin&version=3D2} {add=3D[7 (1432090993461559296)]} 0 1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.230; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{distrib.from=3Dhttp://127.0.0.1:15572/m/ao/collection1/&update.d= istrib=3DFROMLEADER&wt=3Djavabin&version=3D2} {add=3D[7 (143209099346680217= 6)]} 0 1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.231; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{distrib.from=3Dhttp://127.0.0.1:62829/m/ao/collection1/&update.d= istrib=3DTOLEADER&wt=3Djavabin&version=3D2} {add=3D[7 (1432090993466802176)= ]} 0 4 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.231; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{wt=3Djavabin&version=3D2} {add=3D[7]} 0 6 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.235; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{wt=3Djavabin&version=3D2} {add=3D[8 (1432090993475190784)]} 0 1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.242; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{distrib.from=3Dhttp://127.0.0.1:62829/m/ao/collection1/&update.d= istrib=3DFROMLEADER&wt=3Djavabin&version=3D2} {add=3D[8 (143209099347938508= 8)]} 0 1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.242; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{wt=3Djavabin&version=3D2} {add=3D[8 (1432090993479385088)]} 0 4 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.246; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{wt=3Djavabin&version=3D2} {add=3D[9 (1432090993486725120)]} 0 1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.256; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{distrib.from=3Dhttp://127.0.0.1:15572/m/ao/collection1/&update.d= istrib=3DFROMLEADER&wt=3Djavabin&version=3D2} {add=3D[9 (143209099349406515= 2)]} 0 1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.256; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{distrib.from=3Dhttp://127.0.0.1:62829/m/ao/collection1/&update.d= istrib=3DTOLEADER&wt=3Djavabin&version=3D2} {add=3D[9 (1432090993494065152)= ]} 0 4 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.257; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{wt=3Djavabin&version=3D2} {add=3D[9]} 0 8 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.261; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{wt=3Djavabin&version=3D2} {add=3D[10 (1432090993502453760)]} 0 1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.270; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{distrib.from=3Dhttp://127.0.0.1:62829/m/ao/collection1/&update.d= istrib=3DFROMLEADER&wt=3Djavabin&version=3D2} {add=3D[10 (14320909935087452= 16)]} 0 1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.270; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{distrib.from=3Dhttp://127.0.0.1:15572/m/ao/collection1/&update.d= istrib=3DTOLEADER&wt=3Djavabin&version=3D2} {add=3D[10 (1432090993508745216= )]} 0 4 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.271; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{wt=3Djavabin&version=3D2} {add=3D[10]} 0 7 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.275; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/update= params=3D{wt=3Djavabin&version=3D2} {add=3D[11 (1432090993517133824)]} 0 1 [junit4:junit4] 1> INFO - 2013-04-12 06:33:19.283; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D/m/ao path=3D/up [...truncated too long message...] riter with IndexWriterCloser [junit4:junit4] 1> ERROR - 2013-04-12 06:35:18.561; org.apache.solr.updat= e.TransactionLog; Error: Forcing close of tlog{file=3D./org.apache.solr.clo= ud.ChaosMonkeyShardSplitTest-1365748372760/jetty4/tlog/tlog.000000000000000= 0003 refcount=3D1} [junit4:junit4] 1> ERROR - 2013-04-12 06:35:18.561; org.apache.solr.updat= e.TransactionLog; Error: Forcing close of tlog{file=3D./org.apache.solr.clo= ud.ChaosMonkeyShardSplitTest-1365748372760/jetty4/tlog/tlog.000000000000000= 0001 refcount=3D1} [junit4:junit4] 1> INFO - 2013-04-12 06:35:18.565; org.apache.solr.core.= SolrCore; [collection1] Closing main searcher on request. [junit4:junit4] 1> INFO - 2013-04-12 06:35:18.566; org.apache.solr.core.= CachingDirectoryFactory; Closing NRTCachingDirectoryFactory - 2 directories= currently being tracked [junit4:junit4] 1> INFO - 2013-04-12 06:35:18.567; org.apache.solr.core.= CachingDirectoryFactory; looking to close /usr/home/hudson/hudson-slave/wor= kspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apach= e.solr.cloud.ChaosMonkeyShardSplitTest-1365748372760/jetty4 [CachedDir<>] [junit4:junit4] 1> INFO - 2013-04-12 06:35:18.567; org.apache.solr.core.= CachingDirectoryFactory; Closing directory: /usr/home/hudson/hudson-slave/w= orkspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apa= che.solr.cloud.ChaosMonkeyShardSplitTest-1365748372760/jetty4 [junit4:junit4] 1> INFO - 2013-04-12 06:35:18.567; org.apache.solr.core.= CachingDirectoryFactory; looking to close /usr/home/hudson/hudson-slave/wor= kspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apach= e.solr.cloud.ChaosMonkeyShardSplitTest-1365748372760/jetty4/index [CachedDi= r<>] [junit4:junit4] 1> INFO - 2013-04-12 06:35:18.568; org.apache.solr.core.= CachingDirectoryFactory; Closing directory: /usr/home/hudson/hudson-slave/w= orkspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J0/org.apa= che.solr.cloud.ChaosMonkeyShardSplitTest-1365748372760/jetty4/index [junit4:junit4] 1> INFO - 2013-04-12 06:35:18.568; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1/leaders/shard2 [junit4:junit4] 1> WARN - 2013-04-12 06:35:18.569; org.apache.solr.cloud= .LeaderElector$1;=20 [junit4:junit4] 1> org.apache.zookeeper.KeeperException$SessionExpiredExc= eption: KeeperErrorCode =3D Session expired for /collections/collection1/le= ader_elect/shard2/election/89505685357592588-127.0.0.1:33694_m%2Fao_collect= ion1-n_0000000001 [junit4:junit4] 1> =09at org.apache.zookeeper.KeeperException.create(Keep= erException.java:127) [junit4:junit4] 1> =09at org.apache.zookeeper.KeeperException.create(Keep= erException.java:51) [junit4:junit4] 1> =09at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.= java:873) [junit4:junit4] 1> =09at org.apache.solr.common.cloud.SolrZkClient$2.exec= ute(SolrZkClient.java:152) [junit4:junit4] 1> =09at org.apache.solr.common.cloud.SolrZkClient$2.exec= ute(SolrZkClient.java:149) [junit4:junit4] 1> =09at org.apache.solr.common.cloud.ZkCmdExecutor.retry= Operation(ZkCmdExecutor.java:65) [junit4:junit4] 1> =09at org.apache.solr.common.cloud.SolrZkClient.delete= (SolrZkClient.java:149) [junit4:junit4] 1> =09at org.apache.solr.cloud.ElectionContext.cancelElec= tion(ElectionContext.java:63) [junit4:junit4] 1> =09at org.apache.solr.cloud.ShardLeaderElectionContext= .runLeaderProcess(ElectionContext.java:246) [junit4:junit4] 1> =09at org.apache.solr.cloud.LeaderElector.runIamLeader= Process(LeaderElector.java:156) [junit4:junit4] 1> =09at org.apache.solr.cloud.LeaderElector.checkIfIamLe= ader(LeaderElector.java:100) [junit4:junit4] 1> =09at org.apache.solr.cloud.LeaderElector.access$000(L= eaderElector.java:55) [junit4:junit4] 1> =09at org.apache.solr.cloud.LeaderElector$1.process(Le= aderElector.java:129) [junit4:junit4] 1> =09at org.apache.zookeeper.ClientCnxn$EventThread.proc= essEvent(ClientCnxn.java:519) [junit4:junit4] 1> =09at org.apache.zookeeper.ClientCnxn$EventThread.run(= ClientCnxn.java:495) [junit4:junit4] 1> INFO - 2013-04-12 06:35:18.569; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 3) [junit4:junit4] 1> WARN - 2013-04-12 06:35:18.570; org.apache.solr.commo= n.cloud.ZkStateReader$2; ZooKeeper watch triggered, but Solr cannot talk to= ZK [junit4:junit4] 1> WARN - 2013-04-12 06:35:18.570; org.apache.solr.commo= n.cloud.ZkStateReader$3; ZooKeeper watch triggered, but Solr cannot talk to= ZK [junit4:junit4] 1> INFO - 2013-04-12 06:35:18.570; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> WARN - 2013-04-12 06:35:18.571; org.apache.solr.commo= n.cloud.ZkStateReader$2; ZooKeeper watch triggered, but Solr cannot talk to= ZK [junit4:junit4] 1> WARN - 2013-04-12 06:35:18.571; org.apache.solr.cloud= .LeaderElector$1;=20 [junit4:junit4] 1> org.apache.zookeeper.KeeperException$SessionExpiredExc= eption: KeeperErrorCode =3D Session expired for /overseer_elect/election [junit4:junit4] 1> =09at org.apache.zookeeper.KeeperException.create(Keep= erException.java:127) [junit4:junit4] 1> =09at org.apache.zookeeper.KeeperException.create(Keep= erException.java:51) [junit4:junit4] 1> =09at org.apache.zookeeper.ZooKeeper.getChildren(ZooKe= eper.java:1468) [junit4:junit4] 1> =09at org.apache.solr.common.cloud.SolrZkClient$6.exec= ute(SolrZkClient.java:235) [junit4:junit4] 1> =09at org.apache.solr.common.cloud.SolrZkClient$6.exec= ute(SolrZkClient.java:232) [junit4:junit4] 1> =09at org.apache.solr.common.cloud.ZkCmdExecutor.retry= Operation(ZkCmdExecutor.java:65) [junit4:junit4] 1> =09at org.apache.solr.common.cloud.SolrZkClient.getChi= ldren(SolrZkClient.java:232) [junit4:junit4] 1> =09at org.apache.solr.cloud.LeaderElector.checkIfIamLe= ader(LeaderElector.java:84) [junit4:junit4] 1> =09at org.apache.solr.cloud.LeaderElector.access$000(L= eaderElector.java:55) [junit4:junit4] 1> =09at org.apache.solr.cloud.LeaderElector$1.process(Le= aderElector.java:129) [junit4:junit4] 1> =09at org.apache.zookeeper.ClientCnxn$EventThread.proc= essEvent(ClientCnxn.java:519) [junit4:junit4] 1> =09at org.apache.zookeeper.ClientCnxn$EventThread.run(= ClientCnxn.java:495) [junit4:junit4] 2> NOTE: test params are: codec=3DLucene42: {timestamp=3D= PostingsFormat(name=3DDirect), range_facet_l=3DPostingsFormat(name=3DDirect= ), id=3DPostingsFormat(name=3DMemory doPackFST=3D true), range_facet_sl=3DP= ostingsFormat(name=3DTestBloomFilteredLucene41Postings), range_facet_si=3DL= ucene41(blocksize=3D128), _version_=3DPostingsFormat(name=3DDirect), multiD= efault=3DLucene41(blocksize=3D128), rnd_b=3DPostingsFormat(name=3DMemory do= PackFST=3D true), intDefault=3DPostingsFormat(name=3DDirect)}, docValues:{t= imestamp=3DDocValuesFormat(name=3DDisk)}, sim=3DRandomSimilarityProvider(qu= eryNorm=3Dtrue,coord=3Dcrazy): {}, locale=3Dth, timezone=3DAmerica/Anguilla [junit4:junit4] 2> NOTE: FreeBSD 9.0-RELEASE amd64/Oracle Corporation 1.7= .0_17 (64-bit)/cpus=3D16,threads=3D3,free=3D215336480,total=3D352321536 [junit4:junit4] 2> NOTE: All tests run in this JVM: [SuggesterTest, WordB= reakSolrSpellCheckerTest, TestRemoteStreaming, ScriptEngineTest, PeerSyncTe= st, TestFastWriter, TestPropInjectDefaults, SolrCoreTest, MBeansHandlerTest= , TestSearchPerf, QueryElevationComponentTest, TestRealTimeGet, ExternalFil= eFieldSortTest, TestSolrIndexConfig, TestLMDirichletSimilarityFactory, Over= seerTest, ResourceLoaderTest, CircularListTest, TestPhraseSuggestions, Shar= dSplitTest, DirectSolrConnectionTest, MoreLikeThisHandlerTest, TestTrie, Ba= sicFunctionalityTest, SyncSliceTest, TestReversedWildcardFilterFactory, Tes= tIBSimilarityFactory, SliceStateUpdateTest, DistributedSpellCheckComponentT= est, TestFunctionQuery, AlternateDirectoryTest, SoftAutoCommitTest, Distrib= utedQueryElevationComponentTest, TestValueSourceCache, BadComponentTest, Te= stSolrQueryParser, TestPluginEnable, TestExtendedDismaxParser, RegexBoostPr= ocessorTest, TestQuerySenderListener, QueryResultKeyTest, IndexSchemaTest, = DocumentBuilderTest, TestFastLRUCache, ZkControllerTest, TestSolrDeletionPo= licy2, JsonLoaderTest, SpatialFilterTest, ChaosMonkeyShardSplitTest] [junit4:junit4] Completed on J0 in 146.45s, 1 test, 1 failure <<< FAILURES! [...truncated 520 lines...] BUILD FAILED /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/build= .xml:375: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/build= .xml:355: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/build= .xml:39: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/= build.xml:183: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/= common-build.xml:438: The following error occurred while executing this lin= e: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/lucen= e/common-build.xml:1231: The following error occurred while executing this = line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/lucen= e/common-build.xml:875: There were test failures: 289 suites, 1200 tests, 1= failure, 27 ignored (8 assumptions) Total time: 59 minutes 28 seconds Build step 'Invoke Ant' marked build as failure Archiving artifacts Recording test results Email was triggered for: Failure Sending email for trigger: Failure ------=_Part_1883_1951804682.1365749370318 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_1883_1951804682.1365749370318--