lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Christine Poerschke (BLOOMBERG/ LONDON)" <cpoersc...@bloomberg.net>
Subject Re: [JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.8.0_60-ea-b21) - Build # 13356 - Failure!
Date Fri, 10 Jul 2015 19:18:51 GMT
Hi Shalin,

Oops, not sure why i didn't see your ticket, will mark my SOLR-7774 as duplicate then.

commitWithin of 10 ms and 45 s timeout for all nodes to have committed, seems quite generous for the test, though yes, it could still fail.

The changes i proposed were only to fairly check all nodes i.e. they all get 45s to have committed the extra document. Previously whatever node the cloudClient talked to, that node got the 45s timeout but if the cloudClient node had really quickly committed then the remaining nodes would not be given the full 45s to commit the extra document.

Thanks,
Christine

----- Original Message -----
From: shalinmangar@gmail.com
To: Christine Poerschke (BLOOMBERG/ LONDON), dev@lucene.apache.org
At: Jul 10 2015 20:06:54

There's https://issues.apache.org/jira/browse/SOLR-6225 already

This is a bad test, IMO. It asserts that a commitWithin completes
within some wall clock time which can fail due to a variety of reasons
not limited to the fact that an individual commitWithin doesn't commit
within the given time but only schedules a commit *at or after* the
given time value.

On Sat, Jul 11, 2015 at 12:22 AM, Christine Poerschke (BLOOMBERG/
LONDON) <cpoerschke@bloomberg.net> wrote:
> Hello. Just raised https://issues.apache.org/jira/i#browse/SOLR-7774 related to this. Thanks.
>
> ----- Original Message -----
> From: dev@lucene.apache.org
> To: dev@lucene.apache.org
> At: Jul  7 2015 06:26:54
>
> Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/13356/
> Java: 32bit/jdk1.8.0_60-ea-b21 -server -XX:+UseSerialGC
>
> 1 tests failed.
> FAILED:  org.apache.solr.cloud.BasicDistributedZkTest.test
>
> Error Message:
> commitWithin did not work on node: http://127.0.0.1:39708/collection1 expected:<68> but was:<67>
>
> Stack Trace:
> java.lang.AssertionError: commitWithin did not work on node: http://127.0.0.1:39708/collection1 expected:<68> but was:<67>
>     at __randomizedtesting.SeedInfo.seed([15383A2C337A83D5:9D6C05F69D86EE2D]:0)
>     at org.junit.Assert.fail(Assert.java:93)
>     at org.junit.Assert.failNotEquals(Assert.java:647)
>     at org.junit.Assert.assertEquals(Assert.java:128)
>     at org.junit.Assert.assertEquals(Assert.java:472)
>     at org.apache.solr.cloud.BasicDistributedZkTest.test(BasicDistributedZkTest.java:332)
>     at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>     at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
>     at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>     at java.lang.reflect.Method.invoke(Method.java:497)
>     at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1627)
>     at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:836)
>     at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:872)
>     at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:886)
>     at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:960)
>     at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:935)
>     at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
>     at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
>     at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
>     at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
>     at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
>     at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
>     at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
>     at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
>     at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
>     at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
>     at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:845)
>     at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:747)
>     at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:781)
>     at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:792)
>     at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
>     at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
>     at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
>     at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
>     at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
>     at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
>     at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
>     at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
>     at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
>     at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
>     at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:54)
>     at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
>     at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
>     at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
>     at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
>     at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
>     at java.lang.Thread.run(Thread.java:745)
>
>
>
>
> Build Log:
> [...truncated 10121 lines...]
>    [junit4] Suite: org.apache.solr.cloud.BasicDistributedZkTest
>    [junit4]   2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/init-core-data-001
>    [junit4]   2> 566411 INFO  (SUITE-BasicDistributedZkTest-seed#[15383A2C337A83D5]-worker) [    ] o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /
>    [junit4]   2> 566412 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
>    [junit4]   2> 566412 INFO  (Thread-1547) [    ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
>    [junit4]   2> 566412 INFO  (Thread-1547) [    ] o.a.s.c.ZkTestServer Starting server
>    [junit4]   2> 566512 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.ZkTestServer start zk server on port:39983
>    [junit4]   2> 566512 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
>    [junit4]   2> 566513 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
>    [junit4]   2> 566514 INFO  (zkCallback-545-thread-1) [    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@36e11c name:ZooKeeperConnection Watcher:127.0.0.1:39983 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
>    [junit4]   2> 566514 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
>    [junit4]   2> 566515 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
>    [junit4]   2> 566515 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.SolrZkClient makePath: /solr
>    [junit4]   2> 566516 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
>    [junit4]   2> 566516 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
>    [junit4]   2> 566517 INFO  (zkCallback-546-thread-1) [    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@bfeecd name:ZooKeeperConnection Watcher:127.0.0.1:39983/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
>    [junit4]   2> 566517 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
>    [junit4]   2> 566517 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
>    [junit4]   2> 566517 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1
>    [junit4]   2> 566518 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/shards
>    [junit4]   2> 566519 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection
>    [junit4]   2> 566520 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/shards
>    [junit4]   2> 566520 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
>    [junit4]   2> 566520 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/solrconfig.xml
>    [junit4]   2> 566521 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
>    [junit4]   2> 566522 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/schema.xml
>    [junit4]   2> 566523 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
>    [junit4]   2> 566523 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
>    [junit4]   2> 566523 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
>    [junit4]   2> 566524 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/stopwords.txt
>    [junit4]   2> 566525 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
>    [junit4]   2> 566525 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/protwords.txt
>    [junit4]   2> 566525 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
>    [junit4]   2> 566526 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/currency.xml
>    [junit4]   2> 566526 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
>    [junit4]   2> 566526 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/enumsConfig.xml
>    [junit4]   2> 566527 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
>    [junit4]   2> 566527 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/open-exchange-rates.json
>    [junit4]   2> 566528 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
>    [junit4]   2> 566528 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
>    [junit4]   2> 566529 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
>    [junit4]   2> 566529 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/old_synonyms.txt
>    [junit4]   2> 566529 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
>    [junit4]   2> 566530 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/synonyms.txt
>    [junit4]   2> 566587 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/control-001/cores/collection1
>    [junit4]   2> 566588 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.e.j.s.Server jetty-9.2.11.v20150529
>    [junit4]   2> 566589 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@11527f{/,null,AVAILABLE}
>    [junit4]   2> 566592 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.e.j.s.ServerConnector Started ServerConnector@b7a71a{HTTP/1.1}{127.0.0.1:41721}
>    [junit4]   2> 566592 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.e.j.s.Server Started @568491ms
>    [junit4]   2> 566592 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/tempDir-001/control/data, hostContext=/, hostPort=41721, coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/control-001/cores}
>    [junit4]   2> 566593 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init(): sun.misc.Launcher$AppClassLoader@e2f2a
>    [junit4]   2> 566593 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/control-001/'
>    [junit4]   2> 566606 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.SolrXmlConfig Loading container configuration from /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/control-001/solr.xml
>    [junit4]   2> 566611 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.CoresLocator Config-defined core root directory: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/control-001/cores
>    [junit4]   2> 566611 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.CoreContainer New CoreContainer 28101962
>    [junit4]   2> 566611 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.CoreContainer Loading cores into CoreContainer [instanceDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/control-001/]
>    [junit4]   2> 566611 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.CoreContainer loading shared library: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/control-001/lib
>    [junit4]   2> 566611 WARN  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.SolrResourceLoader Can't find (or read) directory to add to classloader: lib (resolved as: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/control-001/lib).
>    [junit4]   2> 566618 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.h.c.HttpShardHandlerFactory created with socketTimeout : 90000,urlScheme : ,connTimeout : 15000,maxConnectionsPerHost : 20,maxConnections : 10000,corePoolSize : 0,maximumPoolSize : 2147483647,maxThreadIdleTime : 5,sizeOfQueue : -1,fairnessPolicy : false,useRetries : false,
>    [junit4]   2> 566619 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
>    [junit4]   2> 566620 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
>    [junit4]   2> 566620 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.l.LogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
>    [junit4]   2> 566620 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:39983/solr
>    [junit4]   2> 566620 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.ZkController zkHost includes chroot
>    [junit4]   2> 566621 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
>    [junit4]   2> 566625 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
>    [junit4]   2> 566625 INFO  (zkCallback-548-thread-1) [    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@181c22e name:ZooKeeperConnection Watcher:127.0.0.1:39983 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
>    [junit4]   2> 566626 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
>    [junit4]   2> 566626 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
>    [junit4]   2> 566627 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:41721_    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
>    [junit4]   2> 566628 INFO  (zkCallback-549-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@110b459 name:ZooKeeperConnection Watcher:127.0.0.1:39983/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
>    [junit4]   2> 566628 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:41721_    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
>    [junit4]   2> 566629 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:41721_    ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue
>    [junit4]   2> 566630 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:41721_    ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-queue-work
>    [junit4]   2> 566631 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:41721_    ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-running
>    [junit4]   2> 566632 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:41721_    ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-completed
>    [junit4]   2> 566633 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:41721_    ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-failure
>    [junit4]   2> 566634 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:41721_    ] o.a.s.c.c.SolrZkClient makePath: /live_nodes
>    [junit4]   2> 566634 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:41721_    ] o.a.s.c.c.SolrZkClient makePath: /aliases.json
>    [junit4]   2> 566635 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:41721_    ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json
>    [junit4]   2> 566635 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:41721_    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41721_
>    [junit4]   2> 566636 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:41721_    ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/127.0.0.1:41721_
>    [junit4]   2> 566636 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:41721_    ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect
>    [junit4]   2> 566637 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:41721_    ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/election
>    [junit4]   2> 566637 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:41721_    ] o.a.s.c.Overseer Overseer (id=null) closing
>    [junit4]   2> 566637 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:41721_    ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/94125804181192707-127.0.0.1:41721_-n_0000000000
>    [junit4]   2> 566638 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:41721_    ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:41721_
>    [junit4]   2> 566638 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:41721_    ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader
>    [junit4]   2> 566639 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:41721_    ] o.a.s.c.Overseer Overseer (id=94125804181192707-127.0.0.1:41721_-n_0000000000) starting
>    [junit4]   2> 566640 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:41721_    ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue-work
>    [junit4]   2> 566642 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:41721_    ] o.a.s.c.OverseerAutoReplicaFailoverThread Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000
>    [junit4]   2> 566642 INFO  (OverseerCollectionProcessor-94125804181192707-127.0.0.1:41721_-n_0000000000) [n:127.0.0.1:41721_    ] o.a.s.c.OverseerCollectionProcessor Process current queue of collection creations
>    [junit4]   2> 566642 INFO  (OverseerStateUpdate-94125804181192707-127.0.0.1:41721_-n_0000000000) [n:127.0.0.1:41721_    ] o.a.s.c.Overseer Starting to work on the main queue
>    [junit4]   2> 566642 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:41721_    ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
>    [junit4]   2> 566645 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:41721_    ] o.a.s.c.CoreContainer No authentication plugin used.
>    [junit4]   2> 566645 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:41721_    ] o.a.s.c.CoreContainer Security conf doesn't exist. Skipping setup for authorization module.
>    [junit4]   2> 566645 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:41721_    ] o.a.s.c.CoresLocator Looking for core definitions underneath /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/control-001/cores
>    [junit4]   2> 566646 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:41721_    ] o.a.s.c.SolrCore Created CoreDescriptor: {name=collection1, config=solrconfig.xml, transient=false, schema=schema.xml, loadOnStartup=true, instanceDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/control-001/cores/collection1, collection=control_collection, absoluteInstDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/control-001/cores/collection1/, coreNodeName=, dataDir=data/, shard=}
>    [junit4]   2> 566646 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:41721_    ] o.a.s.c.CoresLocator Found core collection1 in /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/control-001/cores/collection1/
>    [junit4]   2> 566646 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:41721_    ] o.a.s.c.CoresLocator Found 1 core definitions
>    [junit4]   2> 566647 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection   x:collection1] o.a.s.c.ZkController publishing state=down
>    [junit4]   2> 566647 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection   x:collection1] o.a.s.c.ZkController numShards not found on descriptor - reading it from system property
>    [junit4]   2> 566647 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:41721_    ] o.a.s.s.SolrDispatchFilter user.dir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2
>    [junit4]   2> 566647 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:41721_    ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init() done
>    [junit4]   2> 566647 INFO  (zkCallback-549-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_    ] o.a.s.c.DistributedQueue NodeChildrenChanged fired on path /overseer/queue state SyncConnected
>    [junit4]   2> 566647 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection   x:collection1] o.a.s.c.ZkController look for our core node name
>    [junit4]   2> 566648 INFO  (OverseerStateUpdate-94125804181192707-127.0.0.1:41721_-n_0000000000) [n:127.0.0.1:41721_    ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
>    [junit4]   2>   "core":"collection1",
>    [junit4]   2>   "roles":null,
>    [junit4]   2>   "base_url":"http://127.0.0.1:41721",
>    [junit4]   2>   "node_name":"127.0.0.1:41721_",
>    [junit4]   2>   "numShards":"1",
>    [junit4]   2>   "state":"down",
>    [junit4]   2>   "shard":null,
>    [junit4]   2>   "collection":"control_collection",
>    [junit4]   2>   "operation":"state"} current state version: 0
>    [junit4]   2> 566648 INFO  (OverseerStateUpdate-94125804181192707-127.0.0.1:41721_-n_0000000000) [n:127.0.0.1:41721_    ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
>    [junit4]   2>   "core":"collection1",
>    [junit4]   2>   "roles":null,
>    [junit4]   2>   "base_url":"http://127.0.0.1:41721",
>    [junit4]   2>   "node_name":"127.0.0.1:41721_",
>    [junit4]   2>   "numShards":"1",
>    [junit4]   2>   "state":"down",
>    [junit4]   2>   "shard":null,
>    [junit4]   2>   "collection":"control_collection",
>    [junit4]   2>   "operation":"state"}
>    [junit4]   2> 566648 INFO  (OverseerStateUpdate-94125804181192707-127.0.0.1:41721_-n_0000000000) [n:127.0.0.1:41721_    ] o.a.s.c.o.ClusterStateMutator building a new cName: control_collection
>    [junit4]   2> 566648 INFO  (OverseerStateUpdate-94125804181192707-127.0.0.1:41721_-n_0000000000) [n:127.0.0.1:41721_    ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
>    [junit4]   2> 566649 INFO  (zkCallback-549-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_    ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
>    [junit4]   2> 566649 INFO  (zkCallback-549-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_    ] o.a.s.c.c.ZkStateReader Updated cluster state version to 1
>    [junit4]   2> 567647 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection   x:collection1] o.a.s.c.ZkController waiting to find shard id in clusterstate for collection1
>    [junit4]   2> 567648 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection   x:collection1] o.a.s.c.ZkController Check for collection zkNode:control_collection
>    [junit4]   2> 567648 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection   x:collection1] o.a.s.c.ZkController Collection zkNode exists
>    [junit4]   2> 567648 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection   x:collection1] o.a.s.c.c.ZkStateReader Load collection config from:/collections/control_collection
>    [junit4]   2> 567648 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection   x:collection1] o.a.s.c.c.ZkStateReader path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
>    [junit4]   2> 567648 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection   x:collection1] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/control-001/cores/collection1/'
>    [junit4]   2> 567656 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection   x:collection1] o.a.s.c.Config loaded config solrconfig.xml with version 0
>    [junit4]   2> 567659 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection   x:collection1] o.a.s.c.SolrConfig current version of requestparams : -1
>    [junit4]   2> 567662 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection   x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.0.0
>    [junit4]   2> 567674 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection   x:collection1] o.a.s.c.Config Loaded SolrConfig: solrconfig.xml
>    [junit4]   2> 567675 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection   x:collection1] o.a.s.s.IndexSchema Reading Solr Schema from /configs/conf1/schema.xml
>    [junit4]   2> 567678 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection   x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
>    [junit4]   2> 567758 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection   x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
>    [junit4]   2> 567764 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection   x:collection1] o.a.s.s.IndexSchema default search field in schema is text
>    [junit4]   2> 567765 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection   x:collection1] o.a.s.s.IndexSchema unique key field: id
>    [junit4]   2> 567770 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection   x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
>    [junit4]   2> 567772 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection   x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
>    [junit4]   2> 567773 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection   x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
>    [junit4]   2> 567774 WARN  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection   x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Unknown key IMPORTANT NOTE
>    [junit4]   2> 567774 WARN  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection   x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Expected key, got STRING
>    [junit4]   2> 567774 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection   x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
>    [junit4]   2> 567774 WARN  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection   x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Unknown key IMPORTANT NOTE
>    [junit4]   2> 567775 WARN  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection   x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Expected key, got STRING
>    [junit4]   2> 567775 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection   x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection control_collection
>    [junit4]   2> 567775 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore org.apache.solr.core.MockDirectoryFactory
>    [junit4]   2> 567775 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/control-001/cores/collection1/], dataDir=[null]
>    [junit4]   2> 567775 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@72c79a
>    [junit4]   2> 567776 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/control-001/cores/collection1/data
>    [junit4]   2> 567776 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore New index directory detected: old=null new=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/control-001/cores/collection1/data/index/
>    [junit4]   2> 567776 WARN  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [collection1] Solr index directory '/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/control-001/cores/collection1/data/index' doesn't exist. Creating new index...
>    [junit4]   2> 567776 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/control-001/cores/collection1/data/index
>    [junit4]   2> 567777 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=39, maxMergeAtOnceExplicit=39, maxMergedSegmentMB=7.0263671875, floorSegmentMB=0.828125, forceMergeDeletesPctAllowed=19.782225088363447, segmentsPerTier=40.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
>    [junit4]   2> 567777 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore SolrDeletionPolicy.onCommit: commits: num=1
>    [junit4]   2>     commit{dir=MockDirectoryWrapper(RAMDirectory@c4a02d lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1a3897a),segFN=segments_1,generation=1}
>    [junit4]   2> 567777 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore newest commit generation = 1
>    [junit4]   2> 567778 INFO  (OldIndexDirectoryCleanupThreadForCore-collection1) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore Looking for old index directories to cleanup for core collection1 in /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/control-001/cores/collection1/data/
>    [junit4]   2> 567778 WARN  (OldIndexDirectoryCleanupThreadForCore-collection1) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.DirectoryFactory /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/control-001/cores/collection1/data/ does not point to a valid data directory; skipping clean-up of old index directories.
>    [junit4]   2> 567781 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "nodistrib"
>    [junit4]   2> 567781 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "dedupe"
>    [junit4]   2> 567781 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
>    [junit4]   2> 567781 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "stored_sig"
>    [junit4]   2> 567781 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
>    [junit4]   2> 567781 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
>    [junit4]   2> 567782 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
>    [junit4]   2> 567782 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
>    [junit4]   2> 567782 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore no updateRequestProcessorChain defined as default, creating implicit default
>    [junit4]   2> 567784 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
>    [junit4]   2> 567785 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
>    [junit4]   2> 567786 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
>    [junit4]   2> 567786 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
>    [junit4]   2> 567789 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.RequestHandlers Registered paths: /admin/mbeans,standard,/update/csv,/update/json/docs,/admin/luke,/admin/segments,/get,/admin/system,/replication,/admin/properties,/config,/schema,/admin/plugins,/admin/logging,/update/json,/admin/threads,/admin/ping,/update,/admin/file
>    [junit4]   2> 567789 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
>    [junit4]   2> 567790 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
>    [junit4]   2> 567790 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
>    [junit4]   2> 567791 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore Hard AutoCommit: disabled
>    [junit4]   2> 567791 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore Soft AutoCommit: disabled
>    [junit4]   2> 567792 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1461354382, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
>    [junit4]   2> 567792 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore SolrDeletionPolicy.onInit: commits: num=1
>    [junit4]   2>     commit{dir=MockDirectoryWrapper(RAMDirectory@c4a02d lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1a3897a),segFN=segments_1,generation=1}
>    [junit4]   2> 567792 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore newest commit generation = 1
>    [junit4]   2> 567792 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@d5a8b1[collection1] main
>    [junit4]   2> 567792 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.c.ZkStateReader Load collection config from:/collections/control_collection
>    [junit4]   2> 567793 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.c.ZkStateReader path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
>    [junit4]   2> 567793 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
>    [junit4]   2> 567793 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
>    [junit4]   2> 567793 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.RestManager Initializing RestManager with initArgs: {}
>    [junit4]   2> 567793 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
>    [junit4]   2> 567794 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage No data found for znode /configs/conf1/_rest_managed.json
>    [junit4]   2> 567794 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
>    [junit4]   2> 567794 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.RestManager Initializing 0 registered ManagedResources
>    [junit4]   2> 567794 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for  10000
>    [junit4]   2> 567794 INFO  (searcherExecutor-1907-thread-1-processing-n:127.0.0.1:41721_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@d5a8b1[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
>    [junit4]   2> 567794 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Looking up max value of version field to seed version buckets
>    [junit4]   2> 567795 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.VersionInfo Refreshing highest value of _version_ for 65536 version buckets from index
>    [junit4]   2> 567795 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.VersionInfo No terms found for _version_, cannot seed version bucket highest value from index
>    [junit4]   2> 567795 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1506012868348215296
>    [junit4]   2> 567797 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Took 2 ms to seed version buckets with highest version 1506012868348215296
>    [junit4]   2> 567797 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController watch zkdir /configs/conf1
>    [junit4]   2> 567797 INFO  (coreLoadExecutor-1906-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CoreContainer registering core: collection1
>    [junit4]   2> 567797 INFO  (coreZkRegister-1900-thread-1-processing-n:127.0.0.1:41721_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController Register replica - core:collection1 address:http://127.0.0.1:41721 collection:control_collection shard:shard1
>    [junit4]   2> 567798 INFO  (coreZkRegister-1900-thread-1-processing-n:127.0.0.1:41721_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/leader_elect/shard1/election
>    [junit4]   2> 567799 INFO  (coreZkRegister-1900-thread-1-processing-n:127.0.0.1:41721_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.LeaderElector Joined leadership election with path: /collections/control_collection/leader_elect/shard1/election/94125804181192707-core_node1-n_0000000000
>    [junit4]   2> 567799 INFO  (coreZkRegister-1900-thread-1-processing-n:127.0.0.1:41721_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Running the leader process for shard shard1
>    [junit4]   2> 567800 INFO  (zkCallback-549-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_    ] o.a.s.c.DistributedQueue NodeChildrenChanged fired on path /overseer/queue state SyncConnected
>    [junit4]   2> 567800 INFO  (coreZkRegister-1900-thread-1-processing-n:127.0.0.1:41721_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
>    [junit4]   2> 567800 INFO  (coreZkRegister-1900-thread-1-processing-n:127.0.0.1:41721_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
>    [junit4]   2> 567800 INFO  (coreZkRegister-1900-thread-1-processing-n:127.0.0.1:41721_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:41721/collection1/
>    [junit4]   2> 567800 INFO  (OverseerStateUpdate-94125804181192707-127.0.0.1:41721_-n_0000000000) [n:127.0.0.1:41721_    ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
>    [junit4]   2>   "operation":"leader",
>    [junit4]   2>   "shard":"shard1",
>    [junit4]   2>   "collection":"control_collection"} current state version: 1
>    [junit4]   2> 567800 INFO  (coreZkRegister-1900-thread-1-processing-n:127.0.0.1:41721_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
>    [junit4]   2> 567801 INFO  (coreZkRegister-1900-thread-1-processing-n:127.0.0.1:41721_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy http://127.0.0.1:41721/collection1/ has no replicas
>    [junit4]   2> 567801 INFO  (coreZkRegister-1900-thread-1-processing-n:127.0.0.1:41721_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:41721/collection1/ shard1
>    [junit4]   2> 567801 INFO  (coreZkRegister-1900-thread-1-processing-n:127.0.0.1:41721_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/leaders/shard1
>    [junit4]   2> 567803 INFO  (zkCallback-549-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_    ] o.a.s.c.DistributedQueue NodeChildrenChanged fired on path /overseer/queue state SyncConnected
>    [junit4]   2> 567803 INFO  (OverseerStateUpdate-94125804181192707-127.0.0.1:41721_-n_0000000000) [n:127.0.0.1:41721_    ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
>    [junit4]   2>   "operation":"leader",
>    [junit4]   2>   "shard":"shard1",
>    [junit4]   2>   "collection":"control_collection",
>    [junit4]   2>   "base_url":"http://127.0.0.1:41721",
>    [junit4]   2>   "core":"collection1",
>    [junit4]   2>   "state":"active"} current state version: 1
>    [junit4]   2> 567904 INFO  (zkCallback-549-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_    ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
>    [junit4]   2> 567905 INFO  (zkCallback-549-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_    ] o.a.s.c.c.ZkStateReader Updated cluster state version to 2
>    [junit4]   2> 567953 INFO  (coreZkRegister-1900-thread-1-processing-n:127.0.0.1:41721_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController We are http://127.0.0.1:41721/collection1/ and leader is http://127.0.0.1:41721/collection1/
>    [junit4]   2> 567954 INFO  (coreZkRegister-1900-thread-1-processing-n:127.0.0.1:41721_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:41721
>    [junit4]   2> 567954 INFO  (coreZkRegister-1900-thread-1-processing-n:127.0.0.1:41721_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary
>    [junit4]   2> 567954 INFO  (coreZkRegister-1900-thread-1-processing-n:127.0.0.1:41721_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController publishing state=active
>    [junit4]   2> 567954 INFO  (coreZkRegister-1900-thread-1-processing-n:127.0.0.1:41721_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:41721_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController numShards not found on descriptor - reading it from system property
>    [junit4]   2> 567955 INFO  (zkCallback-549-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_    ] o.a.s.c.DistributedQueue NodeChildrenChanged fired on path /overseer/queue state SyncConnected
>    [junit4]   2> 567955 INFO  (OverseerStateUpdate-94125804181192707-127.0.0.1:41721_-n_0000000000) [n:127.0.0.1:41721_    ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
>    [junit4]   2>   "core":"collection1",
>    [junit4]   2>   "core_node_name":"core_node1",
>    [junit4]   2>   "roles":null,
>    [junit4]   2>   "base_url":"http://127.0.0.1:41721",
>    [junit4]   2>   "node_name":"127.0.0.1:41721_",
>    [junit4]   2>   "numShards":"1",
>    [junit4]   2>   "state":"active",
>    [junit4]   2>   "shard":"shard1",
>    [junit4]   2>   "collection":"control_collection",
>    [junit4]   2>   "operation":"state"} current state version: 2
>    [junit4]   2> 567956 INFO  (OverseerStateUpdate-94125804181192707-127.0.0.1:41721_-n_0000000000) [n:127.0.0.1:41721_    ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
>    [junit4]   2>   "core":"collection1",
>    [junit4]   2>   "core_node_name":"core_node1",
>    [junit4]   2>   "roles":null,
>    [junit4]   2>   "base_url":"http://127.0.0.1:41721",
>    [junit4]   2>   "node_name":"127.0.0.1:41721_",
>    [junit4]   2>   "numShards":"1",
>    [junit4]   2>   "state":"active",
>    [junit4]   2>   "shard":"shard1",
>    [junit4]   2>   "collection":"control_collection",
>    [junit4]   2>   "operation":"state"}
>    [junit4]   2> 568057 INFO  (zkCallback-549-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_    ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
>    [junit4]   2> 568057 INFO  (zkCallback-549-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_    ] o.a.s.c.c.ZkStateReader Updated cluster state version to 3
>    [junit4]   2> 568148 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
>    [junit4]   2> 568149 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
>    [junit4]   2> 568150 INFO  (zkCallback-551-thread-1) [    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@18c4c8a name:ZooKeeperConnection Watcher:127.0.0.1:39983/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
>    [junit4]   2> 568150 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
>    [junit4]   2> 568151 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
>    [junit4]   2> 568151 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
>    [junit4]   2> 568152 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.ChaosMonkey monkey: init - expire sessions:false cause connection loss:false
>    [junit4]   2> 568235 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/shard-1-001/cores/collection1
>    [junit4]   2> 568236 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 1 in directory /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/shard-1-001
>    [junit4]   2> 568236 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.e.j.s.Server jetty-9.2.11.v20150529
>    [junit4]   2> 568238 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1d3aa12{/,null,AVAILABLE}
>    [junit4]   2> 568238 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.e.j.s.ServerConnector Started ServerConnector@cfc1a{HTTP/1.1}{127.0.0.1:39708}
>    [junit4]   2> 568238 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.e.j.s.Server Started @570137ms
>    [junit4]   2> 568238 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/tempDir-001/jetty1, solrconfig=solrconfig.xml, hostContext=/, hostPort=39708, coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/shard-1-001/cores}
>    [junit4]   2> 568239 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init(): sun.misc.Launcher$AppClassLoader@e2f2a
>    [junit4]   2> 568239 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/shard-1-001/'
>    [junit4]   2> 568252 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.SolrXmlConfig Loading container configuration from /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/shard-1-001/solr.xml
>    [junit4]   2> 568257 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.CoresLocator Config-defined core root directory: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/shard-1-001/cores
>    [junit4]   2> 568257 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.CoreContainer New CoreContainer 24044445
>    [junit4]   2> 568257 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.CoreContainer Loading cores into CoreContainer [instanceDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/shard-1-001/]
>    [junit4]   2> 568257 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.CoreContainer loading shared library: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/shard-1-001/lib
>    [junit4]   2> 568257 WARN  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.SolrResourceLoader Can't find (or read) directory to add to classloader: lib (resolved as: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/shard-1-001/lib).
>    [junit4]   2> 568264 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.h.c.HttpShardHandlerFactory created with socketTimeout : 90000,urlScheme : ,connTimeout : 15000,maxConnectionsPerHost : 20,maxConnections : 10000,corePoolSize : 0,maximumPoolSize : 2147483647,maxThreadIdleTime : 5,sizeOfQueue : -1,fairnessPolicy : false,useRetries : false,
>    [junit4]   2> 568265 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
>    [junit4]   2> 568266 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
>    [junit4]   2> 568266 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.l.LogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
>    [junit4]   2> 568266 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:39983/solr
>    [junit4]   2> 568266 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.ZkController zkHost includes chroot
>    [junit4]   2> 568267 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
>    [junit4]   2> 568267 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
>    [junit4]   2> 568268 INFO  (zkCallback-553-thread-1) [    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@975714 name:ZooKeeperConnection Watcher:127.0.0.1:39983 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
>    [junit4]   2> 568268 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
>    [junit4]   2> 568269 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
>    [junit4]   2> 568269 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:39708_    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
>    [junit4]   2> 568270 INFO  (zkCallback-554-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@106d449 name:ZooKeeperConnection Watcher:127.0.0.1:39983/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
>    [junit4]   2> 568270 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:39708_    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
>    [junit4]   2> 568272 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:39708_    ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
>    [junit4]   2> 569274 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:39708_    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39708_
>    [junit4]   2> 569274 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:39708_    ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/127.0.0.1:39708_
>    [junit4]   2> 569275 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:39708_    ] o.a.s.c.Overseer Overseer (id=null) closing
>    [junit4]   2> 569276 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:39708_    ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/94125804181192710-127.0.0.1:39708_-n_0000000001
>    [junit4]   2> 569276 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:39708_    ] o.a.s.c.LeaderElector Watching path /overseer_elect/election/94125804181192707-127.0.0.1:41721_-n_0000000000 to know if I could be the leader
>    [junit4]   2> 569276 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:39708_    ] o.a.s.c.CoreContainer No authentication plugin used.
>    [junit4]   2> 569276 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:39708_    ] o.a.s.c.CoreContainer Security conf doesn't exist. Skipping setup for authorization module.
>    [junit4]   2> 569277 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:39708_    ] o.a.s.c.CoresLocator Looking for core definitions underneath /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/shard-1-001/cores
>    [junit4]   2> 569277 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:39708_    ] o.a.s.c.SolrCore Created CoreDescriptor: {name=collection1, config=solrconfig.xml, transient=false, schema=schema.xml, loadOnStartup=true, instanceDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/shard-1-001/cores/collection1, collection=collection1, absoluteInstDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/shard-1-001/cores/collection1/, coreNodeName=, dataDir=data/, shard=}
>    [junit4]   2> 569278 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:39708_    ] o.a.s.c.CoresLocator Found core collection1 in /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/shard-1-001/cores/collection1/
>    [junit4]   2> 569278 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:39708_    ] o.a.s.c.CoresLocator Found 1 core definitions
>    [junit4]   2> 569279 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1   x:collection1] o.a.s.c.ZkController publishing state=down
>    [junit4]   2> 569279 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:39708_    ] o.a.s.s.SolrDispatchFilter user.dir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2
>    [junit4]   2> 569279 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:39708_    ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init() done
>    [junit4]   2> 569279 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1   x:collection1] o.a.s.c.ZkController numShards not found on descriptor - reading it from system property
>    [junit4]   2> 569279 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1   x:collection1] o.a.s.c.ZkController look for our core node name
>    [junit4]   2> 569279 INFO  (zkCallback-549-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_    ] o.a.s.c.DistributedQueue NodeChildrenChanged fired on path /overseer/queue state SyncConnected
>    [junit4]   2> 569280 INFO  (OverseerStateUpdate-94125804181192707-127.0.0.1:41721_-n_0000000000) [n:127.0.0.1:41721_    ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
>    [junit4]   2>   "core":"collection1",
>    [junit4]   2>   "roles":null,
>    [junit4]   2>   "base_url":"http://127.0.0.1:39708",
>    [junit4]   2>   "node_name":"127.0.0.1:39708_",
>    [junit4]   2>   "numShards":"2",
>    [junit4]   2>   "state":"down",
>    [junit4]   2>   "shard":null,
>    [junit4]   2>   "collection":"collection1",
>    [junit4]   2>   "operation":"state"} current state version: 3
>    [junit4]   2> 569280 INFO  (OverseerStateUpdate-94125804181192707-127.0.0.1:41721_-n_0000000000) [n:127.0.0.1:41721_    ] o.a.s.c.o.ReplicaMutator Update state numShards=2 message={
>    [junit4]   2>   "core":"collection1",
>    [junit4]   2>   "roles":null,
>    [junit4]   2>   "base_url":"http://127.0.0.1:39708",
>    [junit4]   2>   "node_name":"127.0.0.1:39708_",
>    [junit4]   2>   "numShards":"2",
>    [junit4]   2>   "state":"down",
>    [junit4]   2>   "shard":null,
>    [junit4]   2>   "collection":"collection1",
>    [junit4]   2>   "operation":"state"}
>    [junit4]   2> 569280 INFO  (OverseerStateUpdate-94125804181192707-127.0.0.1:41721_-n_0000000000) [n:127.0.0.1:41721_    ] o.a.s.c.o.ClusterStateMutator building a new cName: collection1
>    [junit4]   2> 569280 INFO  (OverseerStateUpdate-94125804181192707-127.0.0.1:41721_-n_0000000000) [n:127.0.0.1:41721_    ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2
>    [junit4]   2> 569381 INFO  (zkCallback-551-thread-1) [    ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
>    [junit4]   2> 569381 INFO  (zkCallback-554-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_    ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
>    [junit4]   2> 569381 INFO  (zkCallback-549-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_    ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
>    [junit4]   2> 569382 INFO  (zkCallback-551-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated cluster state version to 4
>    [junit4]   2> 569382 INFO  (zkCallback-554-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_    ] o.a.s.c.c.ZkStateReader Updated cluster state version to 4
>    [junit4]   2> 569382 INFO  (zkCallback-549-thread-1-processing-n:127.0.0.1:41721_) [n:127.0.0.1:41721_    ] o.a.s.c.c.ZkStateReader Updated cluster state version to 4
>    [junit4]   2> 570279 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1   x:collection1] o.a.s.c.ZkController waiting to find shard id in clusterstate for collection1
>    [junit4]   2> 570279 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1   x:collection1] o.a.s.c.ZkController Check for collection zkNode:collection1
>    [junit4]   2> 570280 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1   x:collection1] o.a.s.c.ZkController Collection zkNode exists
>    [junit4]   2> 570280 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1   x:collection1] o.a.s.c.c.ZkStateReader Load collection config from:/collections/collection1
>    [junit4]   2> 570280 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1   x:collection1] o.a.s.c.c.ZkStateReader path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
>    [junit4]   2> 570280 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1   x:collection1] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/shard-1-001/cores/collection1/'
>    [junit4]   2> 570288 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1   x:collection1] o.a.s.c.Config loaded config solrconfig.xml with version 0
>    [junit4]   2> 570292 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1   x:collection1] o.a.s.c.SolrConfig current version of requestparams : -1
>    [junit4]   2> 570295 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1   x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.0.0
>    [junit4]   2> 570315 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1   x:collection1] o.a.s.c.Config Loaded SolrConfig: solrconfig.xml
>    [junit4]   2> 570316 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1   x:collection1] o.a.s.s.IndexSchema Reading Solr Schema from /configs/conf1/schema.xml
>    [junit4]   2> 570319 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1   x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
>    [junit4]   2> 570414 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1   x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
>    [junit4]   2> 570418 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1   x:collection1] o.a.s.s.IndexSchema default search field in schema is text
>    [junit4]   2> 570419 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1   x:collection1] o.a.s.s.IndexSchema unique key field: id
>    [junit4]   2> 570423 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1   x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
>    [junit4]   2> 570424 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1   x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
>    [junit4]   2> 570425 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1   x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
>    [junit4]   2> 570425 WARN  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1   x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Unknown key IMPORTANT NOTE
>    [junit4]   2> 570426 WARN  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1   x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Expected key, got STRING
>    [junit4]   2> 570426 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1   x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
>    [junit4]   2> 570426 WARN  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1   x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Unknown key IMPORTANT NOTE
>    [junit4]   2> 570426 WARN  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1   x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Expected key, got STRING
>    [junit4]   2> 570426 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1   x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1
>    [junit4]   2> 570426 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.SolrCore org.apache.solr.core.MockDirectoryFactory
>    [junit4]   2> 570427 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/shard-1-001/cores/collection1/], dataDir=[null]
>    [junit4]   2> 570427 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@72c79a
>    [junit4]   2> 570427 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/shard-1-001/cores/collection1/data
>    [junit4]   2> 570428 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.SolrCore New index directory detected: old=null new=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/shard-1-001/cores/collection1/data/index/
>    [junit4]   2> 570428 WARN  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.SolrCore [collection1] Solr index directory '/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/shard-1-001/cores/collection1/data/index' doesn't exist. Creating new index...
>    [junit4]   2> 570428 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/shard-1-001/cores/collection1/data/index
>    [junit4]   2> 570428 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=39, maxMergeAtOnceExplicit=39, maxMergedSegmentMB=7.0263671875, floorSegmentMB=0.828125, forceMergeDeletesPctAllowed=19.782225088363447, segmentsPerTier=40.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
>    [junit4]   2> 570429 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.SolrCore SolrDeletionPolicy.onCommit: commits: num=1
>    [junit4]   2>     commit{dir=MockDirectoryWrapper(RAMDirectory@1c2d0fb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@a5b03e),segFN=segments_1,generation=1}
>    [junit4]   2> 570429 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.SolrCore newest commit generation = 1
>    [junit4]   2> 570429 INFO  (OldIndexDirectoryCleanupThreadForCore-collection1) [n:127.0.0.1:39708_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.SolrCore Looking for old index directories to cleanup for core collection1 in /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/shard-1-001/cores/collection1/data/
>    [junit4]   2> 570429 WARN  (OldIndexDirectoryCleanupThreadForCore-collection1) [n:127.0.0.1:39708_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.DirectoryFactory /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/shard-1-001/cores/collection1/data/ does not point to a valid data directory; skipping clean-up of old index directories.
>    [junit4]   2> 570432 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "nodistrib"
>    [junit4]   2> 570432 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "dedupe"
>    [junit4]   2> 570432 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
>    [junit4]   2> 570432 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "stored_sig"
>    [junit4]   2> 570432 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
>    [junit4]   2> 570432 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
>    [junit4]   2> 570432 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
>    [junit4]   2> 570432 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
>    [junit4]   2> 570432 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.SolrCore no updateRequestProcessorChain defined as default, creating implicit default
>    [junit4]   2> 570434 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
>    [junit4]   2> 570435 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
>    [junit4]   2> 570435 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
>    [junit4]   2> 570436 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
>    [junit4]   2> 570438 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.RequestHandlers Registered paths: /admin/mbeans,standard,/update/csv,/update/json/docs,/admin/luke,/admin/segments,/get,/admin/system,/replication,/admin/properties,/config,/schema,/admin/plugins,/admin/logging,/update/json,/admin/threads,/admin/ping,/update,/admin/file
>    [junit4]   2> 570439 INFO  (coreLoadExecutor-1917-thread-1-processing-n:127.0.0.1:39708_) [n:127.0.0.1:39708_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.SolrCore Using default statsCache cache: org.apa
>
> [...truncated too long message...]
>
> ion1] Closing main searcher on request.
>    [junit4]   2> 594440 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:50106_ c:collection1 s:shard1 r:core_node4 x:collection1] o.a.s.c.CachingDirectoryFactory Closing MockDirectoryFactory - 2 directories currently being tracked
>    [junit4]   2> 594440 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:50106_ c:collection1 s:shard1 r:core_node4 x:collection1] o.a.s.c.CachingDirectoryFactory looking to close /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/shard-4-001/cores/collection1/data/index [CachedDir<<refCount=0;path=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/shard-4-001/cores/collection1/data/index;done=false>>]
>    [junit4]   2> 594440 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:50106_ c:collection1 s:shard1 r:core_node4 x:collection1] o.a.s.c.CachingDirectoryFactory Closing directory: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/shard-4-001/cores/collection1/data/index
>    [junit4]   2> 594441 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:50106_ c:collection1 s:shard1 r:core_node4 x:collection1] o.a.s.c.CachingDirectoryFactory looking to close /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/shard-4-001/cores/collection1/data [CachedDir<<refCount=0;path=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/shard-4-001/cores/collection1/data;done=false>>]
>    [junit4]   2> 594441 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:50106_ c:collection1 s:shard1 r:core_node4 x:collection1] o.a.s.c.CachingDirectoryFactory Closing directory: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001/shard-4-001/cores/collection1/data
>    [junit4]   2> 594442 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:50106_ c:collection1 s:shard1 r:core_node4 x:collection1] o.a.s.c.Overseer Overseer (id=94125804181192716-127.0.0.1:50106_-n_0000000004) closing
>    [junit4]   2> 594442 INFO  (OverseerStateUpdate-94125804181192716-127.0.0.1:50106_-n_0000000004) [n:127.0.0.1:50106_    ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:50106_
>    [junit4]   2> 594442 WARN  (zkCallback-564-thread-3-processing-n:127.0.0.1:50106_) [n:127.0.0.1:50106_    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK
>    [junit4]   2> 594443 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.e.j.s.ServerConnector Stopped ServerConnector@119b9e0{HTTP/1.1}{127.0.0.1:0}
>    [junit4]   2> 594443 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [    ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@1814557{/,null,UNAVAILABLE}
>    [junit4]   2> 594444 INFO  (TEST-BasicDistributedZkTest.test-seed#[15383A2C337A83D5]) [n:127.0.0.1:50106_ c:collection1 s:shard1 r:core_node4 x:collection1] o.a.s.c.ZkTestServer connecting to 127.0.0.1:39983 39983
>    [junit4]   2> 594456 INFO  (Thread-1547) [    ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:39983 39983
>    [junit4]   2> 594456 WARN  (Thread-1547) [    ] o.a.s.c.ZkTestServer Watch limit violations:
>    [junit4]   2> Maximum concurrent create/delete watches above limit:
>    [junit4]   2>
>    [junit4]   2>     7    /solr/aliases.json
>    [junit4]   2>     7    /solr/clusterstate.json
>    [junit4]   2>     5    /solr/configs/conf1
>    [junit4]   2>
>    [junit4]   2> Maximum concurrent children watches above limit:
>    [junit4]   2>
>    [junit4]   2>     7    /solr/live_nodes
>    [junit4]   2>     5    /solr/overseer/queue
>    [junit4]   2>     5    /solr/overseer/collection-queue-work
>    [junit4]   2>
>    [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=BasicDistributedZkTest -Dtests.method=test -Dtests.seed=15383A2C337A83D5 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=sl_SI -Dtests.timezone=Asia/Pyongyang -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
>    [junit4] FAILURE 28.1s J2 | BasicDistributedZkTest.test <<<
>    [junit4]    > Throwable #1: java.lang.AssertionError: commitWithin did not work on node: http://127.0.0.1:39708/collection1 expected:<68> but was:<67>
>    [junit4]    >     at __randomizedtesting.SeedInfo.seed([15383A2C337A83D5:9D6C05F69D86EE2D]:0)
>    [junit4]    >     at org.apache.solr.cloud.BasicDistributedZkTest.test(BasicDistributedZkTest.java:332)
>    [junit4]    >     at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:960)
>    [junit4]    >     at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:935)
>    [junit4]    >     at java.lang.Thread.run(Thread.java:745)
>    [junit4]   2> 594463 INFO  (SUITE-BasicDistributedZkTest-seed#[15383A2C337A83D5]-worker) [n:127.0.0.1:50106_ c:collection1 s:shard1 r:core_node4 x:collection1] o.a.s.SolrTestCaseJ4 ###deleteCore
>    [junit4]   2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.BasicDistributedZkTest_15383A2C337A83D5-001
>    [junit4]   2> Jul 07, 2015 5:10:19 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
>    [junit4]   2> WARNING: Will linger awaiting termination of 2 leaked thread(s).
>    [junit4]   2> NOTE: test params are: codec=Lucene53, sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=sl_SI, timezone=Asia/Pyongyang
>    [junit4]   2> NOTE: Linux 3.16.0-41-generic i386/Oracle Corporation 1.8.0_60-ea (32-bit)/cpus=12,threads=1,free=98578064,total=233742336
>    [junit4]   2> NOTE: All tests run in this JVM: [DistributedVersionInfoTest, TestReload, AutoCommitTest, ChangedSchemaMergeTest, TestNoOpRegenerator, TestExtendedDismaxParser, ResponseLogComponentTest, TestGroupingSearch, TestCopyFieldCollectionResource, TestTrie, TestBM25SimilarityFactory, OutputWriterTest, TestUniqueKeyFieldResource, TestQueryUtils, BadIndexSchemaTest, DistributedQueryElevationComponentTest, DirectUpdateHandlerOptimizeTest, HdfsCollectionsAPIDistributedZkTest, TestFieldCollectionResource, TestFieldTypeResource, TestSmileRequest, DistribJoinFromCollectionTest, TestReloadAndDeleteDocs, DistributedQueryComponentCustomSortTest, RecoveryZkTest, StatsComponentTest, HdfsLockFactoryTest, TestInitParams, TestSchemaSimilarityResource, TestBinaryResponseWriter, TestSolrQueryParser, TestDynamicFieldCollectionResource, PolyFieldTest, SampleTest, TestDocSet, SolrCoreCheckLockOnStartupTest, BinaryUpdateRequestHandlerTest, TestSolrConfigHandlerConcurrent, SimpleCollectionCreateDeleteTest, DistanceUnitsTest, AddBlockUpdateTest, ActionThrottleTest, SuggesterTest, HdfsDirectoryTest, TestSearcherReuse, DeleteReplicaTest, LeaderElectionTest, QueryEqualityTest, TestManagedStopFilterFactory, BasicDistributedZk2Test, CursorPagingTest, QueryParsingTest, CircularListTest, TestMiniSolrCloudClusterSSL, TestQuerySenderNoQuery, TestStressRecovery, TestQueryTypes, TestSolrCloudWithKerberosAlt, TestSolrXml, PluginInfoTest, TestExactStatsCache, TestSolrQueryParserDefaultOperatorResource, SharedFSAutoReplicaFailoverTest, TestManagedResource, FileBasedSpellCheckerTest, TestSolr4Spatial2, DistributedFacetPivotSmallAdvancedTest, TestCSVResponseWriter, OverseerTest, AsyncMigrateRouteKeyTest, StressHdfsTest, HdfsBasicDistributedZk2Test, ReplicationFactorTest, TestPerFieldSimilarity, TestRequestStatusCollectionAPI, SOLR749Test, TestReqParamsAPI, SearchHandlerTest, SpellCheckCollatorTest, BasicDistributedZkTest]
>    [junit4] Completed [194/514] on J2 in 28.83s, 1 test, 1 failure <<< FAILURES!
>
> [...truncated 1002 lines...]
> BUILD FAILED
> /home/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:526: The following error occurred while executing this line:
> /home/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:474: The following error occurred while executing this line:
> /home/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:61: The following error occurred while executing this line:
> /home/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:39: The following error occurred while executing this line:
> /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:230: The following error occurred while executing this line:
> /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:513: The following error occurred while executing this line:
> /home/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1426: The following error occurred while executing this line:
> /home/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:981: There were test failures: 514 suites, 2022 tests, 1 failure, 59 ignored (25 assumptions)
>
> Total time: 46 minutes 24 seconds
> Build step 'Invoke Ant' marked build as failure
> Archiving artifacts
> Recording test results
> Email was triggered for: Failure - Any
> Sending email for trigger: Failure - Any
>
>
>
> ----------------------------
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
> For additional commands, e-mail: dev-help@lucene.apache.org
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
> For additional commands, e-mail: dev-help@lucene.apache.org
>



-- 
Regards,
Shalin Shekhar Mangar.

Mime
View raw message