You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2015/12/07 14:58:48 UTC
[JENKINS] Lucene-Solr-NightlyTests-5.4 - Build # 11 - Still Failing
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-5.4/11/
1 tests failed.
FAILED: org.apache.solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR
Error Message:
There are still nodes recoverying - waited for 330 seconds
Stack Trace:
java.lang.AssertionError: There are still nodes recoverying - waited for 330 seconds
at __randomizedtesting.SeedInfo.seed([978B2AF96872E167:4901448453D08394]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:175)
at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:136)
at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:131)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.waitForRecoveriesToFinish(AbstractFullDistribZkTestBase.java:831)
at org.apache.solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR(LeaderInitiatedRecoveryOnShardRestartTest.java:104)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1764)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:871)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:921)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:964)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:939)
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:367)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:809)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:460)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:880)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:781)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:816)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:827)
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:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
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:367)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 11303 lines...]
[junit4] Suite: org.apache.solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest
[junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/init-core-data-001
[junit4] 2> 2729892 INFO (SUITE-LeaderInitiatedRecoveryOnShardRestartTest-seed#[978B2AF96872E167]-worker) [ ] o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /
[junit4] 2> 2729895 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 2729896 INFO (Thread-18470) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2729896 INFO (Thread-18470) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 2729996 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.ZkTestServer start zk server on port:37391
[junit4] 2> 2729996 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 2729997 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2729999 INFO (zkCallback-1331-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@73f8184f name:ZooKeeperConnection Watcher:127.0.0.1:37391 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2729999 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2730000 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 2730000 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr
[junit4] 2> 2730003 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 2730003 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2730004 INFO (zkCallback-1332-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@3920eba3 name:ZooKeeperConnection Watcher:127.0.0.1:37391/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2730004 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2730004 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 2730004 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1
[junit4] 2> 2730006 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/shards
[junit4] 2> 2730007 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection
[junit4] 2> 2730008 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/shards
[junit4] 2> 2730010 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 2730010 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 2730012 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 2730012 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/schema.xml
[junit4] 2> 2730014 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 2730014 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 2730016 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 2730016 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/stopwords.txt
[junit4] 2> 2730017 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 2730018 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/protwords.txt
[junit4] 2> 2730019 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 2730019 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/currency.xml
[junit4] 2> 2730021 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 2730021 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 2730023 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 2730023 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 2730024 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 2730024 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 2730026 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 2730026 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 2730027 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 2730028 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/synonyms.txt
[junit4] 2> 2730320 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/control-001/cores/collection1
[junit4] 2> 2730321 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.e.j.s.Server jetty-9.2.13.v20150730
[junit4] 2> 2730323 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@7ae6e8b6{/,null,AVAILABLE}
[junit4] 2> 2730323 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.e.j.s.ServerConnector Started ServerConnector@7c68df11{HTTP/1.1}{127.0.0.1:33219}
[junit4] 2> 2730323 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.e.j.s.Server Started @2733719ms
[junit4] 2> 2730323 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/control-001/cores, solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/tempDir-001/control/data, hostPort=33219}
[junit4] 2> 2730324 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init(): sun.misc.Launcher$AppClassLoader@7b3cb2c6
[junit4] 2> 2730324 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/control-001'
[junit4] 2> 2730324 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2730324 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find system property or JNDI)
[junit4] 2> 2730324 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 2730325 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2730326 INFO (zkCallback-1333-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@6ee18d2d name:ZooKeeperConnection Watcher:127.0.0.1:37391/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2730326 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2730326 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 2730327 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 2730328 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/control-001/solr.xml
[junit4] 2> 2730342 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.CorePropertiesLocator Config-defined core root directory: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/control-001/cores
[junit4] 2> 2730342 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.CoreContainer New CoreContainer 1187170167
[junit4] 2> 2730342 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.CoreContainer Loading cores into CoreContainer [instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/control-001]
[junit4] 2> 2730342 WARN (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.CoreContainer Couldn't add files from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/control-001/lib to classpath: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/control-001/lib
[junit4] 2> 2730342 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] 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> 2730344 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2730344 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2730344 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.l.LogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2730344 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37391/solr
[junit4] 2> 2730344 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.ZkController zkHost includes chroot
[junit4] 2> 2730344 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 2730345 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2730346 INFO (zkCallback-1335-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@7da649eb name:ZooKeeperConnection Watcher:127.0.0.1:37391 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2730346 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2730347 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 2730348 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:33219_ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2730349 INFO (zkCallback-1336-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@d8558ec name:ZooKeeperConnection Watcher:127.0.0.1:37391/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2730350 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:33219_ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2730351 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:33219_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue
[junit4] 2> 2730352 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:33219_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-queue-work
[junit4] 2> 2730355 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:33219_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-running
[junit4] 2> 2730357 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:33219_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-completed
[junit4] 2> 2730358 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:33219_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-failure
[junit4] 2> 2730360 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:33219_ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes
[junit4] 2> 2730361 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:33219_ ] o.a.s.c.c.SolrZkClient makePath: /aliases.json
[junit4] 2> 2730362 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:33219_ ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json
[junit4] 2> 2730364 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:33219_ ] o.a.s.c.c.SolrZkClient makePath: /security.json
[junit4] 2> 2730365 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:33219_ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:33219_
[junit4] 2> 2730365 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:33219_ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/127.0.0.1:33219_
[junit4] 2> 2730366 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:33219_ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect
[junit4] 2> 2730368 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:33219_ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/election
[junit4] 2> 2730369 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:33219_ ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 2730369 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:33219_ ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/94994105589497860-127.0.0.1:33219_-n_0000000000
[junit4] 2> 2730369 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:33219_ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:33219_
[junit4] 2> 2730370 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:33219_ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader
[junit4] 2> 2730371 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:33219_ ] o.a.s.c.Overseer Overseer (id=94994105589497860-127.0.0.1:33219_-n_0000000000) starting
[junit4] 2> 2730373 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:33219_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue-work
[junit4] 2> 2730378 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:33219_ ] o.a.s.c.OverseerAutoReplicaFailoverThread Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 2730379 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:33219_ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 2730379 INFO (OverseerCollectionConfigSetProcessor-94994105589497860-127.0.0.1:33219_-n_0000000000) [n:127.0.0.1:33219_ ] o.a.s.c.OverseerTaskProcessor Process current queue of overseer operations
[junit4] 2> 2730379 INFO (OverseerStateUpdate-94994105589497860-127.0.0.1:33219_-n_0000000000) [n:127.0.0.1:33219_ ] o.a.s.c.Overseer Starting to work on the main queue
[junit4] 2> 2730393 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:33219_ ] o.a.s.c.CoreContainer Security conf doesn't exist. Skipping setup for authorization module.
[junit4] 2> 2730394 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:33219_ ] o.a.s.c.CoreContainer No authentication plugin used.
[junit4] 2> 2730394 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:33219_ ] o.a.s.c.CorePropertiesLocator Looking for core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/control-001/cores
[junit4] 2> 2730395 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:33219_ ] o.a.s.c.CoreDescriptor Created CoreDescriptor: {shard=, transient=false, config=solrconfig.xml, schema=schema.xml, loadOnStartup=true, collection=control_collection, coreNodeName=, name=collection1, dataDir=data/, configSetProperties=configsetprops.json, absoluteInstDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/control-001/cores/collection1/, instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/control-001/cores/collection1}
[junit4] 2> 2730396 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:33219_ ] o.a.s.c.CorePropertiesLocator Found core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/control-001/cores/collection1/
[junit4] 2> 2730396 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:33219_ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions
[junit4] 2> 2730396 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:33219_ ] o.a.s.s.SolrDispatchFilter user.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1
[junit4] 2> 2730397 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:33219_ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init() done
[junit4] 2> 2730397 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection x:collection1] o.a.s.c.ZkController publishing state=down
[junit4] 2> 2730397 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection x:collection1] o.a.s.c.ZkController numShards not found on descriptor - reading it from system property
[junit4] 2> 2730398 INFO (OverseerStateUpdate-94994105589497860-127.0.0.1:33219_-n_0000000000) [n:127.0.0.1:33219_ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "collection":"control_collection",
[junit4] 2> "node_name":"127.0.0.1:33219_",
[junit4] 2> "base_url":"http://127.0.0.1:33219",
[junit4] 2> "shard":null,
[junit4] 2> "operation":"state",
[junit4] 2> "numShards":"1",
[junit4] 2> "roles":null,
[junit4] 2> "core":"collection1",
[junit4] 2> "state":"down"} current state version: 0
[junit4] 2> 2730398 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection x:collection1] o.a.s.c.ZkController look for our core node name
[junit4] 2> 2730399 INFO (OverseerStateUpdate-94994105589497860-127.0.0.1:33219_-n_0000000000) [n:127.0.0.1:33219_ ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
[junit4] 2> "collection":"control_collection",
[junit4] 2> "node_name":"127.0.0.1:33219_",
[junit4] 2> "base_url":"http://127.0.0.1:33219",
[junit4] 2> "shard":null,
[junit4] 2> "operation":"state",
[junit4] 2> "numShards":"1",
[junit4] 2> "roles":null,
[junit4] 2> "core":"collection1",
[junit4] 2> "state":"down"}
[junit4] 2> 2730399 INFO (OverseerStateUpdate-94994105589497860-127.0.0.1:33219_-n_0000000000) [n:127.0.0.1:33219_ ] o.a.s.c.o.ClusterStateMutator building a new cName: control_collection
[junit4] 2> 2730399 INFO (OverseerStateUpdate-94994105589497860-127.0.0.1:33219_-n_0000000000) [n:127.0.0.1:33219_ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 2730401 INFO (zkCallback-1336-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ ] 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> 2731399 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection x:collection1] o.a.s.c.ZkController waiting to find shard id in clusterstate for collection1
[junit4] 2> 2731399 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection x:collection1] o.a.s.c.ZkController Check for collection zkNode:control_collection
[junit4] 2> 2731400 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection x:collection1] o.a.s.c.ZkController Collection zkNode exists
[junit4] 2> 2731400 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection x:collection1] o.a.s.c.c.ZkStateReader Load collection config from:/collections/control_collection
[junit4] 2> 2731400 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection x:collection1] o.a.s.c.c.ZkStateReader path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2731401 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection x:collection1] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/control-001/cores/collection1'
[junit4] 2> 2731401 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection x:collection1] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2731401 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection x:collection1] o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find system property or JNDI)
[junit4] 2> 2731403 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection x:collection1] o.a.s.c.Config loaded config solrconfig.xml with version 0
[junit4] 2> 2731409 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection x:collection1] o.a.s.c.SolrConfig current version of requestparams : -1
[junit4] 2> 2731424 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 5.4.0
[junit4] 2> 2731452 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection x:collection1] o.a.s.c.SolrConfig Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2731459 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 2731726 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 2731734 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection x:collection1] o.a.s.s.IndexSchema default search field in schema is text
[junit4] 2> 2731736 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection x:collection1] o.a.s.s.IndexSchema unique key field: id
[junit4] 2> 2731744 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
[junit4] 2> 2731747 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
[junit4] 2> 2731750 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2731751 WARN (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Unknown key IMPORTANT NOTE
[junit4] 2> 2731751 WARN (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Expected key, got STRING
[junit4] 2> 2731751 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2731752 WARN (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Unknown key IMPORTANT NOTE
[junit4] 2> 2731752 WARN (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Expected key, got STRING
[junit4] 2> 2731753 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection x:collection1] o.a.s.c.ConfigSetProperties Did not find ConfigSet properties, assuming default properties: Can't find resource 'configsetprops.json' in classpath or '/configs/conf1', cwd=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1
[junit4] 2> 2731753 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection control_collection
[junit4] 2> 2731753 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2731753 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/control-001/cores/collection1], dataDir=[null]
[junit4] 2> 2731753 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ 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@592dc527
[junit4] 2> 2731754 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/control-001/cores/collection1/data
[junit4] 2> 2731754 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore New index directory detected: old=null new=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/control-001/cores/collection1/data/index/
[junit4] 2> 2731754 WARN (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [collection1] Solr index directory '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/control-001/cores/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 2731754 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/control-001/cores/collection1/data/index
[junit4] 2> 2731754 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ 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=10, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=8.9189453125, floorSegmentMB=0.5751953125, forceMergeDeletesPctAllowed=4.994656391226272, segmentsPerTier=16.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.639023521237896
[junit4] 2> 2731755 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=RawDirectoryWrapper(RAMDirectory@73633b5e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@77ced380),segFN=segments_1,generation=1}
[junit4] 2> 2731755 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 1
[junit4] 2> 2731755 INFO (OldIndexDirectoryCleanupThreadForCore-collection1) [n:127.0.0.1:33219_ 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 /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/control-001/cores/collection1/data/
[junit4] 2> 2731756 WARN (OldIndexDirectoryCleanupThreadForCore-collection1) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.DirectoryFactory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/control-001/cores/collection1/data/ does not point to a valid data directory; skipping clean-up of old index directories.
[junit4] 2> 2731759 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 2731759 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "dedupe"
[junit4] 2> 2731759 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 2731759 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 2731759 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 2731759 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ 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> 2731759 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ 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> 2731760 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ 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> 2731760 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ 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> 2731760 WARN (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,args = {defaults={a=A,b=B}}}
[junit4] 2> 2731762 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 2731764 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 2731765 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 2731766 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 2731769 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.RequestHandlers Registered paths: /admin/segments,/admin/ping,/admin/logging,/admin/system,/update/json/docs,/get,/schema,/replication,/update,/admin/file,/admin/luke,/admin/plugins,/config,/update/csv,/admin/properties,standard,/admin/threads,/admin/mbeans,/dump,/update/json
[junit4] 2> 2731771 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ 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> 2731771 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ 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> 2731771 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ 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> 2731772 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2731772 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2731772 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@46c38031
[junit4] 2> 2731773 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=RawDirectoryWrapper(RAMDirectory@73633b5e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@77ced380),segFN=segments_1,generation=1}
[junit4] 2> 2731773 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 1
[junit4] 2> 2731773 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@2b5ba797[collection1] main
[junit4] 2> 2731773 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ 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> 2731774 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ 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> 2731774 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ 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> 2731774 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2731774 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.RestManager Initializing RestManager with initArgs: {}
[junit4] 2> 2731774 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ 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> 2731775 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ 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> 2731775 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ 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> 2731775 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.RestManager Initializing 0 registered ManagedResources
[junit4] 2> 2731775 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 2731775 INFO (searcherExecutor-5831-thread-1-processing-c:control_collection n:127.0.0.1:33219_ r:core_node1 s:shard1 x:collection1) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@2b5ba797[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2731776 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ 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> 2731776 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ 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> 2731776 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ 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> 2731776 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ 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 1519905691402240000
[junit4] 2> 2731778 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Took 2.0ms to seed version buckets with highest version 1519905691402240000
[junit4] 2> 2731778 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController watch zkdir /configs/conf1
[junit4] 2> 2731778 INFO (coreLoadExecutor-5830-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CoreContainer registering core: collection1
[junit4] 2> 2731779 INFO (coreZkRegister-5824-thread-1-processing-c:control_collection n:127.0.0.1:33219_ r:core_node1 s:shard1 x:collection1) [n:127.0.0.1:33219_ 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:33219 collection:control_collection shard:shard1
[junit4] 2> 2731779 INFO (coreZkRegister-5824-thread-1-processing-c:control_collection n:127.0.0.1:33219_ r:core_node1 s:shard1 x:collection1) [n:127.0.0.1:33219_ 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> 2731783 INFO (coreZkRegister-5824-thread-1-processing-c:control_collection n:127.0.0.1:33219_ r:core_node1 s:shard1 x:collection1) [n:127.0.0.1:33219_ 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/94994105589497860-core_node1-n_0000000000
[junit4] 2> 2731783 INFO (coreZkRegister-5824-thread-1-processing-c:control_collection n:127.0.0.1:33219_ r:core_node1 s:shard1 x:collection1) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Running the leader process for shard shard1
[junit4] 2> 2731785 INFO (coreZkRegister-5824-thread-1-processing-c:control_collection n:127.0.0.1:33219_ r:core_node1 s:shard1 x:collection1) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2731785 INFO (coreZkRegister-5824-thread-1-processing-c:control_collection n:127.0.0.1:33219_ r:core_node1 s:shard1 x:collection1) [n:127.0.0.1:33219_ 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> 2731785 INFO (OverseerStateUpdate-94994105589497860-127.0.0.1:33219_-n_0000000000) [n:127.0.0.1:33219_ ] 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> 2731785 INFO (coreZkRegister-5824-thread-1-processing-c:control_collection n:127.0.0.1:33219_ r:core_node1 s:shard1 x:collection1) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:33219/collection1/
[junit4] 2> 2731785 INFO (coreZkRegister-5824-thread-1-processing-c:control_collection n:127.0.0.1:33219_ r:core_node1 s:shard1 x:collection1) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 2731785 INFO (coreZkRegister-5824-thread-1-processing-c:control_collection n:127.0.0.1:33219_ r:core_node1 s:shard1 x:collection1) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy http://127.0.0.1:33219/collection1/ has no replicas
[junit4] 2> 2731786 INFO (coreZkRegister-5824-thread-1-processing-c:control_collection n:127.0.0.1:33219_ r:core_node1 s:shard1 x:collection1) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 2731788 INFO (coreZkRegister-5824-thread-1-processing-c:control_collection n:127.0.0.1:33219_ r:core_node1 s:shard1 x:collection1) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node
[junit4] 2> 2731790 INFO (coreZkRegister-5824-thread-1-processing-c:control_collection n:127.0.0.1:33219_ r:core_node1 s:shard1 x:collection1) [n:127.0.0.1:33219_ 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:33219/collection1/ shard1
[junit4] 2> 2731791 INFO (OverseerStateUpdate-94994105589497860-127.0.0.1:33219_-n_0000000000) [n:127.0.0.1:33219_ ] 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:33219",
[junit4] 2> "core":"collection1",
[junit4] 2> "state":"active"} current state version: 1
[junit4] 2> 2731893 INFO (zkCallback-1336-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ ] 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> 2731898 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 2731899 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2731900 INFO (zkCallback-1338-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@409447bd name:ZooKeeperConnection Watcher:127.0.0.1:37391/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2731900 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2731900 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 2731900 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 2731902 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.ChaosMonkey monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 2731941 INFO (coreZkRegister-5824-thread-1-processing-c:control_collection n:127.0.0.1:33219_ r:core_node1 s:shard1 x:collection1) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController We are http://127.0.0.1:33219/collection1/ and leader is http://127.0.0.1:33219/collection1/
[junit4] 2> 2731941 INFO (coreZkRegister-5824-thread-1-processing-c:control_collection n:127.0.0.1:33219_ r:core_node1 s:shard1 x:collection1) [n:127.0.0.1:33219_ 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:33219
[junit4] 2> 2731942 INFO (coreZkRegister-5824-thread-1-processing-c:control_collection n:127.0.0.1:33219_ r:core_node1 s:shard1 x:collection1) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2731942 INFO (coreZkRegister-5824-thread-1-processing-c:control_collection n:127.0.0.1:33219_ r:core_node1 s:shard1 x:collection1) [n:127.0.0.1:33219_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController publishing state=active
[junit4] 2> 2731942 INFO (coreZkRegister-5824-thread-1-processing-c:control_collection n:127.0.0.1:33219_ r:core_node1 s:shard1 x:collection1) [n:127.0.0.1:33219_ 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> 2731943 INFO (OverseerStateUpdate-94994105589497860-127.0.0.1:33219_-n_0000000000) [n:127.0.0.1:33219_ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "collection":"control_collection",
[junit4] 2> "node_name":"127.0.0.1:33219_",
[junit4] 2> "base_url":"http://127.0.0.1:33219",
[junit4] 2> "shard":"shard1",
[junit4] 2> "operation":"state",
[junit4] 2> "numShards":"1",
[junit4] 2> "roles":null,
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "core":"collection1",
[junit4] 2> "state":"active"} current state version: 2
[junit4] 2> 2731944 INFO (OverseerStateUpdate-94994105589497860-127.0.0.1:33219_-n_0000000000) [n:127.0.0.1:33219_ ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
[junit4] 2> "collection":"control_collection",
[junit4] 2> "node_name":"127.0.0.1:33219_",
[junit4] 2> "base_url":"http://127.0.0.1:33219",
[junit4] 2> "shard":"shard1",
[junit4] 2> "operation":"state",
[junit4] 2> "numShards":"1",
[junit4] 2> "roles":null,
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "core":"collection1",
[junit4] 2> "state":"active"}
[junit4] 2> 2732046 INFO (zkCallback-1338-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: 1)
[junit4] 2> 2732046 INFO (zkCallback-1336-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ ] 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> 2732188 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/shard-1-001/cores/collection1
[junit4] 2> 2732188 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 1 in directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/shard-1-001
[junit4] 2> 2732189 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.e.j.s.Server jetty-9.2.13.v20150730
[junit4] 2> 2732191 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@197929ac{/,null,AVAILABLE}
[junit4] 2> 2732192 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.e.j.s.ServerConnector Started ServerConnector@5ce74fac{HTTP/1.1}{127.0.0.1:40054}
[junit4] 2> 2732192 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.e.j.s.Server Started @2735588ms
[junit4] 2> 2732192 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/, hostPort=40054, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/shard-1-001/cores, solrconfig=solrconfig.xml, solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/tempDir-001/jetty1}
[junit4] 2> 2732192 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init(): sun.misc.Launcher$AppClassLoader@7b3cb2c6
[junit4] 2> 2732192 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/shard-1-001'
[junit4] 2> 2732192 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2732192 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find system property or JNDI)
[junit4] 2> 2732193 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 2732193 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2732194 INFO (zkCallback-1339-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@8c8c591 name:ZooKeeperConnection Watcher:127.0.0.1:37391/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2732194 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2732195 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 2732196 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 2732196 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/shard-1-001/solr.xml
[junit4] 2> 2732211 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.CorePropertiesLocator Config-defined core root directory: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/shard-1-001/cores
[junit4] 2> 2732211 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.CoreContainer New CoreContainer 1118430221
[junit4] 2> 2732211 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.CoreContainer Loading cores into CoreContainer [instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/shard-1-001]
[junit4] 2> 2732211 WARN (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.CoreContainer Couldn't add files from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/shard-1-001/lib to classpath: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/shard-1-001/lib
[junit4] 2> 2732211 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] 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> 2732213 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2732213 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2732213 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.l.LogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2732213 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37391/solr
[junit4] 2> 2732213 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.ZkController zkHost includes chroot
[junit4] 2> 2732213 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 2732214 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2732216 INFO (zkCallback-1341-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@25d5d8db name:ZooKeeperConnection Watcher:127.0.0.1:37391 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2732216 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2732216 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 2732219 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:40054_ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2732220 INFO (zkCallback-1342-thread-1-processing-n:127.0.0.1:40054_) [n:127.0.0.1:40054_ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@40ffa68a name:ZooKeeperConnection Watcher:127.0.0.1:37391/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2732220 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:40054_ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2732225 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:40054_ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 2733230 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:40054_ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40054_
[junit4] 2> 2733230 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:40054_ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/127.0.0.1:40054_
[junit4] 2> 2733231 INFO (zkCallback-1338-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4] 2> 2733231 INFO (zkCallback-1342-thread-1-processing-n:127.0.0.1:40054_) [n:127.0.0.1:40054_ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4] 2> 2733232 INFO (zkCallback-1336-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4] 2> 2733234 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:40054_ ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 2733234 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:40054_ ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/94994105589497864-127.0.0.1:40054_-n_0000000001
[junit4] 2> 2733235 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:40054_ ] o.a.s.c.LeaderElector Watching path /overseer_elect/election/94994105589497860-127.0.0.1:33219_-n_0000000000 to know if I could be the leader
[junit4] 2> 2733244 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:40054_ ] o.a.s.c.CoreContainer Security conf doesn't exist. Skipping setup for authorization module.
[junit4] 2> 2733244 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:40054_ ] o.a.s.c.CoreContainer No authentication plugin used.
[junit4] 2> 2733245 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:40054_ ] o.a.s.c.CorePropertiesLocator Looking for core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/shard-1-001/cores
[junit4] 2> 2733246 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:40054_ ] o.a.s.c.CoreDescriptor Created CoreDescriptor: {transient=false, shard=, configSetProperties=configsetprops.json, loadOnStartup=true, schema=schema.xml, coreNodeName=, dataDir=data/, instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/shard-1-001/cores/collection1, name=collection1, collection=collection1, absoluteInstDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/shard-1-001/cores/collection1/, config=solrconfig.xml}
[junit4] 2> 2733246 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:40054_ ] o.a.s.c.CorePropertiesLocator Found core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/shard-1-001/cores/collection1/
[junit4] 2> 2733246 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:40054_ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions
[junit4] 2> 2733247 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:40054_ ] o.a.s.s.SolrDispatchFilter user.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1
[junit4] 2> 2733247 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:40054_ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init() done
[junit4] 2> 2733247 INFO (coreLoadExecutor-5841-thread-1-processing-n:127.0.0.1:40054_) [n:127.0.0.1:40054_ c:collection1 x:collection1] o.a.s.c.ZkController publishing state=down
[junit4] 2> 2733247 INFO (coreLoadExecutor-5841-thread-1-processing-n:127.0.0.1:40054_) [n:127.0.0.1:40054_ c:collection1 x:collection1] o.a.s.c.ZkController numShards not found on descriptor - reading it from system property
[junit4] 2> 2733249 INFO (OverseerStateUpdate-94994105589497860-127.0.0.1:33219_-n_0000000000) [n:127.0.0.1:33219_ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "collection":"collection1",
[junit4] 2> "node_name":"127.0.0.1:40054_",
[junit4] 2> "base_url":"http://127.0.0.1:40054",
[junit4] 2> "shard":null,
[junit4] 2> "operation":"state",
[junit4] 2> "numShards":"1",
[junit4] 2> "roles":null,
[junit4] 2> "core":"collection1",
[junit4] 2> "state":"down"} current state version: 3
[junit4] 2> 2733249 INFO (OverseerStateUpdate-94994105589497860-127.0.0.1:33219_-n_0000000000) [n:127.0.0.1:33219_ ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
[junit4] 2> "collection":"collection1",
[junit4] 2> "node_name":"127.0.0.1:40054_",
[junit4] 2> "base_url":"http://127.0.0.1:40054",
[junit4] 2> "shard":null,
[junit4] 2> "operation":"state",
[junit4] 2> "numShards":"1",
[junit4] 2> "roles":null,
[junit4] 2> "core":"collection1",
[junit4] 2> "state":"down"}
[junit4] 2> 2733249 INFO (coreLoadExecutor-5841-thread-1-processing-n:127.0.0.1:40054_) [n:127.0.0.1:40054_ c:collection1 x:collection1] o.a.s.c.ZkController look for our core node name
[junit4] 2> 2733250 INFO (OverseerStateUpdate-94994105589497860-127.0.0.1:33219_-n_0000000000) [n:127.0.0.1:33219_ ] o.a.s.c.o.ClusterStateMutator building a new cName: collection1
[junit4] 2> 2733250 INFO (OverseerStateUpdate-94994105589497860-127.0.0.1:33219_-n_0000000000) [n:127.0.0.1:33219_ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 2733352 INFO (zkCallback-1342-thread-1-processing-n:127.0.0.1:40054_) [n:127.0.0.1:40054_ ] 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> 2733352 INFO (zkCallback-1336-thread-1-processing-n:127.0.0.1:33219_) [n:127.0.0.1:33219_ ] 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> 2733352 INFO (zkCallback-1338-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> 2734251 INFO (coreLoadExecutor-5841-thread-1-processing-n:127.0.0.1:40054_) [n:127.0.0.1:40054_ c:collection1 x:collection1] o.a.s.c.ZkController waiting to find shard id in clusterstate for collection1
[junit4] 2> 2734251 INFO (coreLoadExecutor-5841-thread-1-processing-n:127.0.0.1:40054_) [n:127.0.0.1:40054_ c:collection1 x:collection1] o.a.s.c.ZkController Check for collection zkNode:collection1
[junit4] 2> 2734251 INFO (coreLoadExecutor-5841-thread-1-processing-n:127.0.0.1:40054_) [n:127.0.0.1:40054_ c:collection1 x:collection1] o.a.s.c.ZkController Collection zkNode exists
[junit4] 2> 2734251 INFO (coreLoadExecutor-5841-thread-1-processing-n:127.0.0.1:40054_) [n:127.0.0.1:40054_ c:collection1 x:collection1] o.a.s.c.c.ZkStateReader Load collection config from:/collections/collection1
[junit4] 2> 2734252 INFO (coreLoadExecutor-5841-thread-1-processing-n:127.0.0.1:40054_) [n:127.0.0.1:40054_ c:collection1 x:collection1] o.a.s.c.c.ZkStateReader path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2734252 INFO (coreLoadExecutor-5841-thread-1-processing-n:127.0.0.1:40054_) [n:127.0.0.1:40054_ c:collection1 x:collection1] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001/shard-1-001/cores/collection1'
[junit4] 2> 2734252 INFO (coreLoadExecutor-5841-thread-1-processing-n:127.0.0.1:40054_) [n:127.0.0.1:40054_ c:collection1 x:collection1] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2734252 INFO (coreLoadExecutor-5841-thread-1-processing-n:127.0.0.1:40054_) [n:127.0.0.1:40054_ c:collection1 x:collection1] o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find system property or JNDI)
[junit4] 2> 2734254 INFO (coreLoadExecutor-5841-thread-1-processing-n:127.0.0.1:40054_) [n:127.0.0.1:40054_ c:collection1 x:collection1] o.a.s.c.Config loaded config solrconfig.xml with version 0
[junit4] 2> 2734259 INFO (coreLoadExecutor-5841-thread-1-processing-n:127.0.0.1:40054_) [n:127.0.0.1:40054_ c:collection1 x:collection1] o.a.s.c.SolrConfig current version of requestparams : -1
[junit4] 2> 2734273 INFO (coreLoadExecutor-5841-thread-1-processing-n:127.0.0.1:40054_) [n:127.0.0.1:40054_ c:collection1 x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 5.4.0
[junit4] 2> 2734301 INFO (coreLoadExecutor-5841-thread-1-processing-n:127.0.0.1:40054_) [n:127.0.0.1:40054_ c:collection1 x:collection1] o.a.s.c.SolrConfig Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2734308 INFO (coreLoadExecutor-5841-thread-1-processing-n:127.0.0.1:40054_) [n:127.0.0.1:40054_ c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 2734586 INFO (coreLoadExecutor-5841-thread-1-processing-n:127.0.0.1:40054_) [n:127.0.0.1:40054_ c:collection1 x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 2734594 INFO (cor
[...truncated too long message...]
AVAILABLE}
[junit4] 2> 3148090 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[978B2AF96872E167]) [n:127.0.0.1:35848_ c:all_in_lir s:shard1 r:core_node3 x:all_in_lir_shard1_replica2] o.a.s.c.ZkTestServer connecting to 127.0.0.1:37391 37391
[junit4] 2> 3148257 INFO (Thread-18470) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:37391 37391
[junit4] 2> 3148259 WARN (Thread-18470) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 11 /solr/aliases.json
[junit4] 2> 10 /solr/configs/conf1
[junit4] 2> 10 /solr/security.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 11 /solr/clusterstate.json
[junit4] 2> 5 /solr/overseer_elect/election/94994105589497860-127.0.0.1:33219_-n_0000000000
[junit4] 2> 2 /solr/collections/collection1/leader_elect/shard1/election/94994105589497880-core_node2-n_0000000006
[junit4] 2> 2 /solr/overseer_elect/election/94994105589497880-127.0.0.1:35443_-n_0000000007
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 11 /solr/collections
[junit4] 2> 5 /solr/live_nodes
[junit4] 2> 3 /solr/overseer/collection-queue-work
[junit4] 2> 3 /solr/overseer/queue
[junit4] 2> 2 /solr/overseer/queue-work
[junit4] 2>
[junit4] 2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=LeaderInitiatedRecoveryOnShardRestartTest -Dtests.method=testRestartWithAllInLIR -Dtests.seed=978B2AF96872E167 -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/x1/jenkins/lucene-data/enwiki.random.lines.txt -Dtests.locale=ar_SD -Dtests.timezone=Africa/Kampala -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] FAILURE 418s J1 | LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR <<<
[junit4] > Throwable #1: java.lang.AssertionError: There are still nodes recoverying - waited for 330 seconds
[junit4] > at __randomizedtesting.SeedInfo.seed([978B2AF96872E167:4901448453D08394]:0)
[junit4] > at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:175)
[junit4] > at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:136)
[junit4] > at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:131)
[junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.waitForRecoveriesToFinish(AbstractFullDistribZkTestBase.java:831)
[junit4] > at org.apache.solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR(LeaderInitiatedRecoveryOnShardRestartTest.java:104)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:964)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:939)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 3148263 INFO (SUITE-LeaderInitiatedRecoveryOnShardRestartTest-seed#[978B2AF96872E167]-worker) [n:127.0.0.1:35848_ c:all_in_lir s:shard1 r:core_node3 x:all_in_lir_shard1_replica2] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_978B2AF96872E167-001
[junit4] 2> Dec 07, 2015 1:37:17 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene54): {}, docValues:{}, sim=DefaultSimilarity, locale=ar_SD, timezone=Africa/Kampala
[junit4] 2> NOTE: Linux 3.13.0-52-generic amd64/Oracle Corporation 1.7.0_80 (64-bit)/cpus=4,threads=1,free=159289408,total=524288000
[junit4] 2> NOTE: All tests run in this JVM: [DistributedVersionInfoTest, TestNonDefinedSimilarityFactory, TestSerializedLuceneMatchVersion, NumericFieldsTest, BitVectorTest, SpellPossibilityIteratorTest, TestCopyFieldCollectionResource, MigrateRouteKeyTest, BigEndianAscendingWordDeserializerTest, TestBlobHandler, TestLeaderInitiatedRecoveryThread, ShardRoutingTest, TermsComponentTest, TestWordDelimiterFilterFactory, SolrPluginUtilsTest, TestSolrDynamicMBean, TestBM25SimilarityFactory, DeleteReplicaTest, TestDFRSimilarityFactory, TestSolrCloudWithKerberosAlt, TestDistributedStatsComponentCardinality, SoftAutoCommitTest, TestJettySolrRunner, UpdateRequestProcessorFactoryTest, HdfsChaosMonkeyNothingIsSafeTest, SmileWriterTest, TestDistributedMissingSort, TestCrossCoreJoin, TestOverriddenPrefixQueryForCustomFieldType, TestHashPartitioner, TestFieldTypeResource, TestStressUserVersions, TestRestManager, HdfsNNFailoverTest, TestQuerySenderListener, BadCopyFieldTest, TestDynamicFieldResource, FullHLLTest, SuggestComponentTest, AddBlockUpdateTest, HighlighterTest, TestStandardQParsers, SimpleMLTQParserTest, HdfsBasicDistributedZk2Test, TestManagedSchemaFieldTypeResource, TestCollationFieldDocValues, DocValuesTest, SolrInfoMBeanTest, BufferStoreTest, LoggingHandlerTest, TestManagedSchemaFieldResource, RestartWhileUpdatingTest, ZkControllerTest, SpellCheckCollatorTest, ChaosMonkeySafeLeaderTest, TestStressVersions, SecurityConfHandlerTest, ZkSolrClientTest, TestConfigSetsAPIZkFailure, UUIDUpdateProcessorFallbackTest, DistributedTermsComponentTest, TestSolrCoreProperties, TestExpandComponent, TimeZoneUtilsTest, DistributedFacetPivotLongTailTest, TestFreeTextSuggestions, SolrIndexSplitterTest, TestSurroundQueryParser, PKIAuthenticationIntegrationTest, ShardRoutingCustomTest, TestExactStatsCache, DOMUtilTest, TestLFUCache, MinimalSchemaTest, SimplePostToolTest, TestSolr4Spatial2, TestSimpleQParserPlugin, SolrCmdDistributorTest, TestAnalyzeInfixSuggestions, UniqFieldsUpdateProcessorFactoryTest, CSVRequestHandlerTest, RequestLoggingTest, TestSortingResponseWriter, DistribDocExpirationUpdateProcessorTest, TestLMJelinekMercerSimilarityFactory, SolrTestCaseJ4Test, BasicDistributedZkTest, BasicDistributedZk2Test, UnloadDistributedZkTest, CollectionsAPIDistributedZkTest, FullSolrCloudDistribCmdsTest, TestZkChroot, TestRandomDVFaceting, TestDistributedGrouping, DistributedSpellCheckComponentTest, TestReload, TestCoreContainer, SimpleFacetsTest, SolrCoreTest, SpellCheckComponentTest, PeerSyncTest, BadIndexSchemaTest, ConvertedLegacyTest, TestFiltering, BasicFunctionalityTest, DirectUpdateHandlerTest, TestIndexSearcher, CurrencyFieldOpenExchangeTest, AnalysisAfterCoreReloadTest, SignatureUpdateProcessorFactoryTest, SuggesterFSTTest, SolrRequestParserTest, TestStressLucene, TestTrie, PolyFieldTest, SchemaVersionSpecificBehaviorTest, TestPseudoReturnFields, TestUpdate, DirectUpdateHandlerOptimizeTest, SortByFunctionTest, DocValuesMultiTest, TestSolrDeletionPolicy1, DebugComponentTest, LukeRequestHandlerTest, TestReversedWildcardFilterFactory, TestQueryTypes, FileBasedSpellCheckerTest, DocumentBuilderTest, TermVectorComponentTest, RequiredFieldsTest, FieldAnalysisRequestHandlerTest, FastVectorHighlighterTest, RegexBoostProcessorTest, TestCollationField, MBeansHandlerTest, TestPartialUpdateDeduplication, TestComponentsName, TestBinaryResponseWriter, TestSolrIndexConfig, CopyFieldTest, SolrIndexConfigTest, TestSolrDeletionPolicy2, MultiTermTest, SampleTest, TestDocSet, TestBinaryField, TestSearchPerf, TestConfig, ExternalFileFieldSortTest, DirectSolrConnectionTest, NotRequiredUniqueKeyTest, TestPhraseSuggestions, TestCharFilters, TestCodecSupport, TestSweetSpotSimilarityFactory, TestLMDirichletSimilarityFactory, TestIBSimilarityFactory, TestFastOutputStream, ScriptEngineTest, OpenExchangeRatesOrgProviderTest, TestFastLRUCache, DateMathParserTest, ChaosMonkeyNothingIsSafeTest, TestHighlightDedupGrouping, TestTolerantSearch, TestEmbeddedSolrServerConstructors, ActionThrottleTest, AsyncCallRequestStatusResponseTest, CollectionStateFormat2Test, DeleteInactiveReplicaTest, ForceLeaderTest, LeaderInitiatedRecoveryOnShardRestartTest]
[junit4] Completed [431/551] on J1 in 418.90s, 1 test, 1 failure <<< FAILURES!
[...truncated 413 lines...]
BUILD FAILED
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/build.xml:799: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/build.xml:736: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/build.xml:59: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build.xml:233: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/common-build.xml:526: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/common-build.xml:1452: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/common-build.xml:1006: There were test failures: 551 suites (7 ignored), 2177 tests, 1 failure, 32 ignored (18 assumptions) [seed: 978B2AF96872E167]
Total time: 197 minutes 57 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
No prior successful build to compare, so performing full copy of artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any
[JENKINS] Lucene-Solr-NightlyTests-5.4 - Build # 13 - Still Failing
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-5.4/13/
All tests passed
Build Log:
[...truncated 10257 lines...]
[junit4] JVM J1: stdout was not empty, see: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/temp/junit4-J1-20151209_114511_655.sysout
[junit4] >>> JVM J1: stdout (verbatim) ----
[junit4] java.lang.OutOfMemoryError: GC overhead limit exceeded
[junit4] Dumping heap to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/heapdumps/java_pid27186.hprof ...
[junit4] Heap dump file created [608564001 bytes in 10.943 secs]
[junit4] <<< JVM J1: EOF ----
[junit4] JVM J1: stderr was not empty, see: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/temp/junit4-J1-20151209_114511_655.syserr
[junit4] >>> JVM J1: stderr (verbatim) ----
[junit4] WARN: Unhandled exception in event serialization. -> java.lang.OutOfMemoryError: GC overhead limit exceeded
[junit4] at sun.nio.cs.StreamEncoder.write(StreamEncoder.java:133)
[junit4] at java.io.OutputStreamWriter.write(OutputStreamWriter.java:220)
[junit4] at com.carrotsearch.ant.tasks.junit4.gson.stream.JsonWriter.string(JsonWriter.java:571)
[junit4] at com.carrotsearch.ant.tasks.junit4.gson.stream.JsonWriter.value(JsonWriter.java:414)
[junit4] at com.carrotsearch.ant.tasks.junit4.events.AbstractEvent.writeBinaryProperty(AbstractEvent.java:36)
[junit4] at com.carrotsearch.ant.tasks.junit4.events.AppendStdErrEvent.serialize(AppendStdErrEvent.java:30)
[junit4] at com.carrotsearch.ant.tasks.junit4.events.Serializer$2.run(Serializer.java:101)
[junit4] at com.carrotsearch.ant.tasks.junit4.events.Serializer$2.run(Serializer.java:96)
[junit4] at java.security.AccessController.doPrivileged(Native Method)
[junit4] at com.carrotsearch.ant.tasks.junit4.events.Serializer.flushQueue(Serializer.java:96)
[junit4] at com.carrotsearch.ant.tasks.junit4.events.Serializer.serialize(Serializer.java:81)
[junit4] at com.carrotsearch.ant.tasks.junit4.slave.SlaveMain$3$2.write(SlaveMain.java:457)
[junit4] at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
[junit4] at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
[junit4] at java.io.PrintStream.flush(PrintStream.java:338)
[junit4] at java.io.FilterOutputStream.flush(FilterOutputStream.java:140)
[junit4] at java.io.PrintStream.write(PrintStream.java:482)
[junit4] at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
[junit4] at sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:291)
[junit4] at sun.nio.cs.StreamEncoder.implFlush(StreamEncoder.java:295)
[junit4] at sun.nio.cs.StreamEncoder.flush(StreamEncoder.java:141)
[junit4] at java.io.OutputStreamWriter.flush(OutputStreamWriter.java:229)
[junit4] at org.apache.log4j.helpers.QuietWriter.flush(QuietWriter.java:59)
[junit4] at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:324)
[junit4] at org.apache.log4j.WriterAppender.append(WriterAppender.java:162)
[junit4] at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251)
[junit4] at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:66)
[junit4] at org.apache.log4j.Category.callAppenders(Category.java:206)
[junit4] at org.apache.log4j.Category.forcedLog(Category.java:391)
[junit4] at org.apache.log4j.Category.log(Category.java:856)
[junit4] at org.slf4j.impl.Log4jLoggerAdapter.info(Log4jLoggerAdapter.java:304)
[junit4] at org.apache.solr.update.processor.UpdateRequestProcessorChain.init(UpdateRequestProcessorChain.java:123)
[junit4] <<< JVM J1: EOF ----
[...truncated 1329 lines...]
[junit4] ERROR: JVM J1 ended with an exception, command line: /x1/jenkins/jenkins-slave/tools/hudson.model.JDK/latest1.7/jre/bin/java -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/heapdumps -XX:MaxPermSize=192m -ea -esa -Dtests.prefix=tests -Dtests.seed=C6403DC63F98B458 -Xmx512M -Dtests.iters= -Dtests.verbose=false -Dtests.infostream=false -Dtests.codec=random -Dtests.postingsformat=random -Dtests.docvaluesformat=random -Dtests.locale=random -Dtests.timezone=random -Dtests.directory=random -Dtests.linedocsfile=/x1/jenkins/lucene-data/enwiki.random.lines.txt -Dtests.luceneMatchVersion=5.4.0 -Dtests.cleanthreads=perClass -Djava.util.logging.config.file=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/tools/junit4/logging.properties -Dtests.nightly=true -Dtests.weekly=false -Dtests.monster=false -Dtests.slow=true -Dtests.asserts=true -Dtests.multiplier=2 -DtempDir=./temp -Djava.io.tmpdir=./temp -Djunit4.tempDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/temp -Dcommon.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene -Dclover.db.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/build/clover/db -Djava.security.policy=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/tools/junit4/solr-tests.policy -Dtests.LUCENE_VERSION=5.4.0 -Djetty.testMode=1 -Djetty.insecurerandom=1 -Dsolr.directoryFactory=org.apache.solr.core.MockDirectoryFactory -Djava.awt.headless=true -Djdk.map.althashing.threshold=0 -Djunit4.childvm.cwd=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J1 -Djunit4.childvm.id=1 -Djunit4.childvm.count=3 -Dtests.leaveTemporary=false -Dtests.filterstacks=true -Djava.security.manager=org.apache.lucene.util.TestSecurityManager -Dfile.encoding=US-ASCII -classpath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/classes/test:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-test-framework/classes/java:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/test-framework/lib/junit4-ant-2.3.1.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/build/test-framework/classes/java:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/build/codecs/classes/java:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-solrj/classes/java:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/classes/java:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/build/analysis/common/lucene-analyzers-common-5.4.0-SNAPSHOT.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/build/analysis/kuromoji/lucene-analyzers-kuromoji-5.4.0-SNAPSHOT.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/build/analysis/phonetic/lucene-analyzers-phonetic-5.4.0-SNAPSHOT.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/build/codecs/lucene-codecs-5.4.0-SNAPSHOT.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/build/backward-codecs/lucene-backward-codecs-5.4.0-SNAPSHOT.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/build/highlighter/lucene-highlighter-5.4.0-SNAPSHOT.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/build/memory/lucene-memory-5.4.0-SNAPSHOT.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/build/misc/lucene-misc-5.4.0-SNAPSHOT.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/build/spatial/lucene-spatial-5.4.0-SNAPSHOT.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/build/expressions/lucene-expressions-5.4.0-SNAPSHOT.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/build/suggest/lucene-suggest-5.4.0-SNAPSHOT.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/build/grouping/lucene-grouping-5.4.0-SNAPSHOT.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/build/queries/lucene-queries-5.4.0-SNAPSHOT.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/build/queryparser/lucene-queryparser-5.4.0-SNAPSHOT.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/build/join/lucene-join-5.4.0-SNAPSHOT.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/build/sandbox/lucene-sandbox-5.4.0-SNAPSHOT.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/lib/antlr4-runtime-4.5.1-1.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/lib/asm-5.0.4.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/lib/asm-commons-5.0.4.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/lib/commons-cli-1.2.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/lib/commons-codec-1.10.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/lib/commons-collections-3.2.2.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/lib/commons-configuration-1.6.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/lib/commons-exec-1.3.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/lib/commons-fileupload-1.2.1.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/lib/commons-lang-2.6.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/lib/concurrentlinkedhashmap-lru-1.2.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/lib/dom4j-1.6.1.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/lib/guava-14.0.1.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/lib/hadoop-annotations-2.6.0.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/lib/hadoop-auth-2.6.0.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/lib/hadoop-common-2.6.0.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/lib/hadoop-hdfs-2.6.0.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/lib/hppc-0.7.1.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/lib/htrace-core-3.0.4.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/lib/jackson-core-2.5.4.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/lib/jackson-dataformat-smile-2.5.4.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/lib/jcl-over-slf4j-1.7.7.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/lib/joda-time-2.2.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/lib/log4j-1.2.17.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/lib/org.restlet-2.3.0.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/lib/org.restlet.ext.servlet-2.3.0.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/lib/protobuf-java-2.5.0.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/lib/slf4j-log4j12-1.7.7.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/lib/spatial4j-0.5.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/lib/t-digest-3.1.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/solrj/lib/commons-io-2.4.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/solrj/lib/httpclient-4.4.1.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/solrj/lib/httpcore-4.4.1.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/solrj/lib/httpmime-4.4.1.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/solrj/lib/jcl-over-slf4j-1.7.7.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/solrj/lib/noggit-0.6.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/solrj/lib/slf4j-api-1.7.7.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/solrj/lib/stax2-api-3.1.4.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/solrj/lib/woodstox-core-asl-4.4.1.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/solrj/lib/zookeeper-3.4.6.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/server/lib/javax.servlet-api-3.1.0.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/server/lib/jetty-continuation-9.2.13.v20150730.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/server/lib/jetty-deploy-9.2.13.v20150730.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/server/lib/jetty-http-9.2.13.v20150730.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/server/lib/jetty-io-9.2.13.v20150730.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/server/lib/jetty-jmx-9.2.13.v20150730.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/server/lib/jetty-rewrite-9.2.13.v20150730.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/server/lib/jetty-security-9.2.13.v20150730.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/server/lib/jetty-server-9.2.13.v20150730.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/server/lib/jetty-servlet-9.2.13.v20150730.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/server/lib/jetty-servlets-9.2.13.v20150730.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/server/lib/jetty-util-9.2.13.v20150730.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/server/lib/jetty-webapp-9.2.13.v20150730.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/server/lib/jetty-xml-9.2.13.v20150730.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/example/example-DIH/solr/db/lib/derby-10.9.1.0.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/example/example-DIH/solr/db/lib/hsqldb-1.8.0.10.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/build/core/classes/java:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/test-framework/lib/junit-4.10.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/test-framework/lib/randomizedtesting-runner-2.3.1.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/antlr-2.7.7.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/antlr4-runtime-4.5.1-1.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/apacheds-core-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/apacheds-core-api-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/apacheds-core-avl-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/apacheds-core-shared-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/apacheds-i18n-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/apacheds-interceptor-kerberos-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/apacheds-interceptors-admin-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/apacheds-interceptors-authn-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/apacheds-interceptors-authz-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/apacheds-interceptors-changelog-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/apacheds-interceptors-collective-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/apacheds-interceptors-event-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/apacheds-interceptors-exception-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/apacheds-interceptors-journal-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/apacheds-interceptors-normalization-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/apacheds-interceptors-operational-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/apacheds-interceptors-referral-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/apacheds-interceptors-schema-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/apacheds-interceptors-subtree-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/apacheds-interceptors-trigger-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/apacheds-jdbm-partition-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/apacheds-jdbm1-2.0.0-M2.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/apacheds-kerberos-codec-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/apacheds-ldif-partition-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/apacheds-mavibot-partition-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/apacheds-protocol-kerberos-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/apacheds-protocol-ldap-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/apacheds-protocol-shared-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/apacheds-xdbm-partition-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/api-all-1.0.0-M20.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/bcprov-jdk15-1.45.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/cglib-nodep-2.2.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/commons-collections-3.2.2.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/commons-math3-3.4.1.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/easymock-3.0.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/ehcache-core-2.4.4.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/hadoop-common-2.6.0-tests.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/hadoop-hdfs-2.6.0-tests.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/hadoop-minikdc-2.6.0.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/jackson-annotations-2.5.4.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/jackson-databind-2.5.4.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/jersey-core-1.9.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/jersey-server-1.9.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/jetty-6.1.26.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/jetty-util-6.1.26.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/mina-core-2.0.0-M5.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/test-lib/objenesis-1.2.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/build/analysis/icu/lucene-analyzers-icu-5.4.0-SNAPSHOT.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/contrib/solr-analysis-extras/classes/java:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/contrib/analysis-extras/lib/icu4j-54.1.jar:/home/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-launcher.jar:/x1/jenkins/.ant/lib/ivy-2.3.0.jar:/home/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-antlr.jar:/home/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-apache-regexp.jar:/home/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-apache-resolver.jar:/home/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-commons-net.jar:/home/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-jmf.jar:/home/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-apache-oro.jar:/home/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-apache-xalan2.jar:/home/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-commons-logging.jar:/home/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-jsch.jar:/home/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-junit4.jar:/home/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-javamail.jar:/home/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-jai.jar:/home/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-jdepend.jar:/home/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-junit.jar:/home/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-apache-bsf.jar:/home/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-swing.jar:/home/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant.jar:/home/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-netrexx.jar:/home/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-apache-bcel.jar:/home/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-testutil.jar:/home/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-apache-log4j.jar:/x1/jenkins/jenkins-slave/tools/hudson.model.JDK/latest1.7/lib/tools.jar:/x1/jenkins/.ivy2/cache/com.carrotsearch.randomizedtesting/junit4-ant/jars/junit4-ant-2.3.1.jar com.carrotsearch.ant.tasks.junit4.slave.SlaveMainSafe -eventsfile /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/temp/junit4-J1-20151209_114511_655.events @/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/temp/junit4-J1-20151209_114511_655.suites -stdin
[junit4] ERROR: JVM J1 ended with an exception: Quit event not received from the forked process? This may indicate JVM crash or runner bugs.
[junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4.executeSlave(JUnit4.java:1503)
[junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4.access$000(JUnit4.java:130)
[junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4$2.call(JUnit4.java:963)
[junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4$2.call(JUnit4.java:960)
[junit4] at java.util.concurrent.FutureTask.run(FutureTask.java:262)
[junit4] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] at java.lang.Thread.run(Thread.java:745)
BUILD FAILED
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/build.xml:799: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/build.xml:736: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/build.xml:59: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build.xml:233: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/common-build.xml:526: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/common-build.xml:1452: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/common-build.xml:1006: At least one slave process threw an exception, first: Quit event not received from the forked process? This may indicate JVM crash or runner bugs.
Total time: 211 minutes 5 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
No prior successful build to compare, so performing full copy of artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any
[JENKINS] Lucene-Solr-NightlyTests-5.4 - Build # 12 - Still Failing
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-5.4/12/
1 tests failed.
FAILED: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.test
Error Message:
Captured an uncaught exception in thread: Thread[id=59605, name=collection1, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=59605, name=collection1, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest]
Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:56037/_pm: collection already exists: awholynewstresscollection_collection1_0
at __randomizedtesting.SeedInfo.seed([EB19EDDE5315287C]:0)
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:575)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:241)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:230)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:372)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:325)
at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1100)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:871)
at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:807)
at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1220)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1574)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1595)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:881)
Build Log:
[...truncated 10815 lines...]
[junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/init-core-data-001
[junit4] 2> 1696265 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[EB19EDDE5315287C]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false)
[junit4] 2> 1696265 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[EB19EDDE5315287C]-worker) [ ] o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /_pm/
[junit4] 2> 1696271 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 1696271 INFO (Thread-54234) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1696271 INFO (Thread-54234) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 1696371 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.ZkTestServer start zk server on port:43566
[junit4] 2> 1696371 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 1696372 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1696377 INFO (zkCallback-1072-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@78b9e56b name:ZooKeeperConnection Watcher:127.0.0.1:43566 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1696377 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1696378 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 1696378 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr
[junit4] 2> 1696382 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 1696384 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1696385 INFO (zkCallback-1073-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@637a799f name:ZooKeeperConnection Watcher:127.0.0.1:43566/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1696385 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1696385 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 1696386 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1
[junit4] 2> 1696389 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/shards
[junit4] 2> 1696392 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection
[junit4] 2> 1696393 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/shards
[junit4] 2> 1696396 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 1696397 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 1696400 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 1696401 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/schema.xml
[junit4] 2> 1696404 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1696404 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1696406 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 1696406 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/stopwords.txt
[junit4] 2> 1696408 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 1696409 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/protwords.txt
[junit4] 2> 1696411 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 1696411 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/currency.xml
[junit4] 2> 1696413 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 1696413 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 1696415 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 1696416 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 1696418 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1696418 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1696421 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 1696421 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 1696423 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 1696424 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/synonyms.txt
[junit4] 2> 1696783 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/control-001/cores/collection1
[junit4] 2> 1696785 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.e.j.s.Server jetty-9.2.13.v20150730
[junit4] 2> 1696787 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@18f0b0aa{/_pm,null,AVAILABLE}
[junit4] 2> 1696789 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.e.j.s.ServerConnector Started ServerConnector@5400a802{HTTP/1.1}{127.0.0.1:58841}
[junit4] 2> 1696789 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.e.j.s.Server Started @1699568ms
[junit4] 2> 1696789 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/tempDir-001/control/data, hostContext=/_pm, hostPort=58841, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/control-001/cores}
[junit4] 2> 1696789 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init(): sun.misc.Launcher$AppClassLoader@7b3cb2c6
[junit4] 2> 1696789 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/control-001'
[junit4] 2> 1696790 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1696790 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find system property or JNDI)
[junit4] 2> 1696790 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 1696790 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1696792 INFO (zkCallback-1074-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@62e822b3 name:ZooKeeperConnection Watcher:127.0.0.1:43566/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1696792 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1696792 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 1696793 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 1696794 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/control-001/solr.xml
[junit4] 2> 1696810 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.CorePropertiesLocator Config-defined core root directory: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/control-001/cores
[junit4] 2> 1696810 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.CoreContainer New CoreContainer 1732848339
[junit4] 2> 1696810 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.CoreContainer Loading cores into CoreContainer [instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/control-001]
[junit4] 2> 1696810 WARN (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.CoreContainer Couldn't add files from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/control-001/lib to classpath: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/control-001/lib
[junit4] 2> 1696810 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] 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> 1696812 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 1696812 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1696812 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.l.LogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1696812 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:43566/solr
[junit4] 2> 1696813 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.ZkController zkHost includes chroot
[junit4] 2> 1696813 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 1696814 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1696815 INFO (zkCallback-1076-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@182b19b9 name:ZooKeeperConnection Watcher:127.0.0.1:43566 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1696815 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1696815 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 1696817 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:58841__pm ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1696818 INFO (zkCallback-1077-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@45ab574a name:ZooKeeperConnection Watcher:127.0.0.1:43566/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1696818 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:58841__pm ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1696820 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:58841__pm ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue
[junit4] 2> 1696822 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:58841__pm ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-queue-work
[junit4] 2> 1696825 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:58841__pm ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-running
[junit4] 2> 1696828 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:58841__pm ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-completed
[junit4] 2> 1696830 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:58841__pm ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-failure
[junit4] 2> 1696832 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:58841__pm ] o.a.s.c.c.SolrZkClient makePath: /live_nodes
[junit4] 2> 1696834 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:58841__pm ] o.a.s.c.c.SolrZkClient makePath: /aliases.json
[junit4] 2> 1696835 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:58841__pm ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json
[junit4] 2> 1696837 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:58841__pm ] o.a.s.c.c.SolrZkClient makePath: /security.json
[junit4] 2> 1696838 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:58841__pm ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58841__pm
[junit4] 2> 1696838 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:58841__pm ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/127.0.0.1:58841__pm
[junit4] 2> 1696840 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:58841__pm ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect
[junit4] 2> 1696842 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:58841__pm ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/election
[junit4] 2> 1696843 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:58841__pm ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1696844 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:58841__pm ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/94999150421606404-127.0.0.1:58841__pm-n_0000000000
[junit4] 2> 1696844 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:58841__pm ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:58841__pm
[junit4] 2> 1696844 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:58841__pm ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader
[junit4] 2> 1696846 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:58841__pm ] o.a.s.c.Overseer Overseer (id=94999150421606404-127.0.0.1:58841__pm-n_0000000000) starting
[junit4] 2> 1696848 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:58841__pm ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue-work
[junit4] 2> 1696854 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:58841__pm ] o.a.s.c.OverseerAutoReplicaFailoverThread Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=10000 autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 1696854 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:58841__pm ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 1696854 INFO (OverseerCollectionConfigSetProcessor-94999150421606404-127.0.0.1:58841__pm-n_0000000000) [n:127.0.0.1:58841__pm ] o.a.s.c.OverseerTaskProcessor Process current queue of overseer operations
[junit4] 2> 1696855 INFO (OverseerStateUpdate-94999150421606404-127.0.0.1:58841__pm-n_0000000000) [n:127.0.0.1:58841__pm ] o.a.s.c.Overseer Starting to work on the main queue
[junit4] 2> 1696869 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:58841__pm ] o.a.s.c.CoreContainer Security conf doesn't exist. Skipping setup for authorization module.
[junit4] 2> 1696869 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:58841__pm ] o.a.s.c.CoreContainer No authentication plugin used.
[junit4] 2> 1696870 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:58841__pm ] o.a.s.c.CorePropertiesLocator Looking for core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/control-001/cores
[junit4] 2> 1696871 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:58841__pm ] o.a.s.c.CoreDescriptor Created CoreDescriptor: {dataDir=data/, loadOnStartup=true, schema=schema.xml, shard=, configSetProperties=configsetprops.json, coreNodeName=, name=collection1, transient=false, config=solrconfig.xml, collection=control_collection, instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/control-001/cores/collection1, absoluteInstDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/control-001/cores/collection1/}
[junit4] 2> 1696871 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:58841__pm ] o.a.s.c.CorePropertiesLocator Found core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/control-001/cores/collection1/
[junit4] 2> 1696871 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:58841__pm ] o.a.s.c.CorePropertiesLocator Found 1 core definitions
[junit4] 2> 1696872 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:58841__pm ] o.a.s.s.SolrDispatchFilter user.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0
[junit4] 2> 1696872 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection x:collection1] o.a.s.c.ZkController publishing state=down
[junit4] 2> 1696872 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:58841__pm ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init() done
[junit4] 2> 1696872 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection x:collection1] o.a.s.c.ZkController numShards not found on descriptor - reading it from system property
[junit4] 2> 1696875 INFO (OverseerStateUpdate-94999150421606404-127.0.0.1:58841__pm-n_0000000000) [n:127.0.0.1:58841__pm ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "shard":null,
[junit4] 2> "node_name":"127.0.0.1:58841__pm",
[junit4] 2> "base_url":"http://127.0.0.1:58841/_pm",
[junit4] 2> "roles":null,
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down"} current state version: 0
[junit4] 2> 1696875 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection x:collection1] o.a.s.c.ZkController look for our core node name
[junit4] 2> 1696875 INFO (OverseerStateUpdate-94999150421606404-127.0.0.1:58841__pm-n_0000000000) [n:127.0.0.1:58841__pm ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
[junit4] 2> "shard":null,
[junit4] 2> "node_name":"127.0.0.1:58841__pm",
[junit4] 2> "base_url":"http://127.0.0.1:58841/_pm",
[junit4] 2> "roles":null,
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down"}
[junit4] 2> 1696875 INFO (OverseerStateUpdate-94999150421606404-127.0.0.1:58841__pm-n_0000000000) [n:127.0.0.1:58841__pm ] o.a.s.c.o.ClusterStateMutator building a new cName: control_collection
[junit4] 2> 1696876 INFO (OverseerStateUpdate-94999150421606404-127.0.0.1:58841__pm-n_0000000000) [n:127.0.0.1:58841__pm ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 1696878 INFO (zkCallback-1077-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm ] 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> 1697875 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection x:collection1] o.a.s.c.ZkController waiting to find shard id in clusterstate for collection1
[junit4] 2> 1697875 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection x:collection1] o.a.s.c.ZkController Check for collection zkNode:control_collection
[junit4] 2> 1697876 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection x:collection1] o.a.s.c.ZkController Collection zkNode exists
[junit4] 2> 1697876 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection x:collection1] o.a.s.c.c.ZkStateReader Load collection config from:/collections/control_collection
[junit4] 2> 1697877 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection x:collection1] o.a.s.c.c.ZkStateReader path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1697877 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection x:collection1] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/control-001/cores/collection1'
[junit4] 2> 1697877 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection x:collection1] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1697877 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection x:collection1] o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find system property or JNDI)
[junit4] 2> 1697880 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection x:collection1] o.a.s.c.Config loaded config solrconfig.xml with version 0
[junit4] 2> 1697887 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection x:collection1] o.a.s.c.SolrConfig current version of requestparams : -1
[junit4] 2> 1697902 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 5.4.0
[junit4] 2> 1697933 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection x:collection1] o.a.s.c.SolrConfig Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1697942 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1698217 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1698226 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection x:collection1] o.a.s.s.IndexSchema default search field in schema is text
[junit4] 2> 1698228 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection x:collection1] o.a.s.s.IndexSchema unique key field: id
[junit4] 2> 1698239 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
[junit4] 2> 1698242 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
[junit4] 2> 1698245 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1698246 WARN (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Unknown key IMPORTANT NOTE
[junit4] 2> 1698246 WARN (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Expected key, got STRING
[junit4] 2> 1698246 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1698247 WARN (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Unknown key IMPORTANT NOTE
[junit4] 2> 1698247 WARN (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Expected key, got STRING
[junit4] 2> 1698248 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection x:collection1] o.a.s.c.ConfigSetProperties Did not find ConfigSet properties, assuming default properties: Can't find resource 'configsetprops.json' in classpath or '/configs/conf1', cwd=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0
[junit4] 2> 1698248 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection control_collection
[junit4] 2> 1698248 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1698249 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/control-001/cores/collection1], dataDir=[null]
[junit4] 2> 1698249 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm 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@189b7091
[junit4] 2> 1698249 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/control-001/cores/collection1/data
[junit4] 2> 1698249 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore New index directory detected: old=null new=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/control-001/cores/collection1/data/index/
[junit4] 2> 1698249 WARN (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [collection1] Solr index directory '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/control-001/cores/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 1698250 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/control-001/cores/collection1/data/index
[junit4] 2> 1698250 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=9, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 1698250 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@9e52655 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@23379b86),segFN=segments_1,generation=1}
[junit4] 2> 1698251 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 1
[junit4] 2> 1698251 INFO (OldIndexDirectoryCleanupThreadForCore-collection1) [n:127.0.0.1:58841__pm 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 /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/control-001/cores/collection1/data/
[junit4] 2> 1698251 WARN (OldIndexDirectoryCleanupThreadForCore-collection1) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.DirectoryFactory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/control-001/cores/collection1/data/ does not point to a valid data directory; skipping clean-up of old index directories.
[junit4] 2> 1698255 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1698256 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1698256 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1698256 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1698256 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1698256 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm 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> 1698256 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm 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> 1698257 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm 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> 1698257 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm 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> 1698257 WARN (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,args = {defaults={a=A,b=B}}}
[junit4] 2> 1698260 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 1698261 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 1698263 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 1698264 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 1698268 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.RequestHandlers Registered paths: /admin/logging,/admin/mbeans,/admin/file,/update/json,/admin/threads,/config,/schema,/admin/segments,/admin/plugins,/dump,standard,/admin/properties,/admin/ping,/update,/update/json/docs,/get,/replication,/admin/luke,/admin/system,/update/csv
[junit4] 2> 1698270 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm 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> 1698271 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm 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> 1698271 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm 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> 1698271 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1698271 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1698272 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=34, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=0.9345703125, noCFSRatio=0.0]
[junit4] 2> 1698272 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@9e52655 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@23379b86),segFN=segments_1,generation=1}
[junit4] 2> 1698272 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 1
[junit4] 2> 1698273 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@6046dd8d[collection1] main
[junit4] 2> 1698273 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm 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> 1698274 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm 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> 1698274 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm 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> 1698274 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1698274 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.RestManager Initializing RestManager with initArgs: {}
[junit4] 2> 1698274 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm 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> 1698275 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm 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> 1698275 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm 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> 1698275 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.RestManager Initializing 0 registered ManagedResources
[junit4] 2> 1698275 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1698276 INFO (searcherExecutor-3661-thread-1-processing-n:127.0.0.1:58841__pm s:shard1 x:collection1 r:core_node1 c:control_collection) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@6046dd8d[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1698276 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm 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> 1698276 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm 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> 1698276 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm 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> 1698276 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm 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 1519986408843902976
[junit4] 2> 1698278 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Took 2.0ms to seed version buckets with highest version 1519986408843902976
[junit4] 2> 1698278 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController watch zkdir /configs/conf1
[junit4] 2> 1698279 INFO (coreLoadExecutor-3660-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CoreContainer registering core: collection1
[junit4] 2> 1698279 INFO (coreZkRegister-3654-thread-1-processing-n:127.0.0.1:58841__pm s:shard1 x:collection1 r:core_node1 c:control_collection) [n:127.0.0.1:58841__pm 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:58841/_pm collection:control_collection shard:shard1
[junit4] 2> 1698280 INFO (coreZkRegister-3654-thread-1-processing-n:127.0.0.1:58841__pm s:shard1 x:collection1 r:core_node1 c:control_collection) [n:127.0.0.1:58841__pm 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> 1698284 INFO (coreZkRegister-3654-thread-1-processing-n:127.0.0.1:58841__pm s:shard1 x:collection1 r:core_node1 c:control_collection) [n:127.0.0.1:58841__pm 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/94999150421606404-core_node1-n_0000000000
[junit4] 2> 1698284 INFO (coreZkRegister-3654-thread-1-processing-n:127.0.0.1:58841__pm s:shard1 x:collection1 r:core_node1 c:control_collection) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Running the leader process for shard shard1
[junit4] 2> 1698286 INFO (coreZkRegister-3654-thread-1-processing-n:127.0.0.1:58841__pm s:shard1 x:collection1 r:core_node1 c:control_collection) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 1698286 INFO (coreZkRegister-3654-thread-1-processing-n:127.0.0.1:58841__pm s:shard1 x:collection1 r:core_node1 c:control_collection) [n:127.0.0.1:58841__pm 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> 1698286 INFO (coreZkRegister-3654-thread-1-processing-n:127.0.0.1:58841__pm s:shard1 x:collection1 r:core_node1 c:control_collection) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:58841/_pm/collection1/
[junit4] 2> 1698286 INFO (coreZkRegister-3654-thread-1-processing-n:127.0.0.1:58841__pm s:shard1 x:collection1 r:core_node1 c:control_collection) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 1698287 INFO (coreZkRegister-3654-thread-1-processing-n:127.0.0.1:58841__pm s:shard1 x:collection1 r:core_node1 c:control_collection) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy http://127.0.0.1:58841/_pm/collection1/ has no replicas
[junit4] 2> 1698287 INFO (OverseerStateUpdate-94999150421606404-127.0.0.1:58841__pm-n_0000000000) [n:127.0.0.1:58841__pm ] 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> 1698288 INFO (coreZkRegister-3654-thread-1-processing-n:127.0.0.1:58841__pm s:shard1 x:collection1 r:core_node1 c:control_collection) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 1698291 INFO (coreZkRegister-3654-thread-1-processing-n:127.0.0.1:58841__pm s:shard1 x:collection1 r:core_node1 c:control_collection) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node
[junit4] 2> 1698293 INFO (coreZkRegister-3654-thread-1-processing-n:127.0.0.1:58841__pm s:shard1 x:collection1 r:core_node1 c:control_collection) [n:127.0.0.1:58841__pm 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:58841/_pm/collection1/ shard1
[junit4] 2> 1698293 INFO (OverseerStateUpdate-94999150421606404-127.0.0.1:58841__pm-n_0000000000) [n:127.0.0.1:58841__pm ] 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:58841/_pm",
[junit4] 2> "core":"collection1",
[junit4] 2> "state":"active"} current state version: 1
[junit4] 2> 1698374 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 1698375 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1698377 INFO (zkCallback-1079-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@2780fd5e name:ZooKeeperConnection Watcher:127.0.0.1:43566/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1698377 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1698377 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 1698377 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 1698380 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.ChaosMonkey monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 1698380 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.AbstractFullDistribZkTestBase Creating collection1 with stateFormat=2
[junit4] 2> 1698380 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 1698380 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1698382 INFO (zkCallback-1080-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@32b4051c name:ZooKeeperConnection Watcher:127.0.0.1:43566/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1698382 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1698382 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 1698385 INFO (OverseerStateUpdate-94999150421606404-127.0.0.1:58841__pm-n_0000000000) [n:127.0.0.1:58841__pm ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"create",
[junit4] 2> "name":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "stateFormat":"2"} current state version: 1
[junit4] 2> 1698385 INFO (OverseerStateUpdate-94999150421606404-127.0.0.1:58841__pm-n_0000000000) [n:127.0.0.1:58841__pm ] o.a.s.c.o.ClusterStateMutator building a new cName: collection1
[junit4] 2> 1698385 INFO (zkCallback-1077-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm ] 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> 1698385 INFO (zkCallback-1079-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: 1)
[junit4] 2> 1698394 INFO (coreZkRegister-3654-thread-1-processing-n:127.0.0.1:58841__pm s:shard1 x:collection1 r:core_node1 c:control_collection) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController We are http://127.0.0.1:58841/_pm/collection1/ and leader is http://127.0.0.1:58841/_pm/collection1/
[junit4] 2> 1698394 INFO (coreZkRegister-3654-thread-1-processing-n:127.0.0.1:58841__pm s:shard1 x:collection1 r:core_node1 c:control_collection) [n:127.0.0.1:58841__pm 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:58841/_pm
[junit4] 2> 1698394 INFO (coreZkRegister-3654-thread-1-processing-n:127.0.0.1:58841__pm s:shard1 x:collection1 r:core_node1 c:control_collection) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 1698394 INFO (coreZkRegister-3654-thread-1-processing-n:127.0.0.1:58841__pm s:shard1 x:collection1 r:core_node1 c:control_collection) [n:127.0.0.1:58841__pm c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController publishing state=active
[junit4] 2> 1698394 INFO (coreZkRegister-3654-thread-1-processing-n:127.0.0.1:58841__pm s:shard1 x:collection1 r:core_node1 c:control_collection) [n:127.0.0.1:58841__pm 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> 1698396 INFO (OverseerStateUpdate-94999150421606404-127.0.0.1:58841__pm-n_0000000000) [n:127.0.0.1:58841__pm ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "shard":"shard1",
[junit4] 2> "node_name":"127.0.0.1:58841__pm",
[junit4] 2> "base_url":"http://127.0.0.1:58841/_pm",
[junit4] 2> "roles":null,
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "numShards":"2",
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active"} current state version: 2
[junit4] 2> 1698397 INFO (OverseerStateUpdate-94999150421606404-127.0.0.1:58841__pm-n_0000000000) [n:127.0.0.1:58841__pm ] o.a.s.c.o.ReplicaMutator Update state numShards=2 message={
[junit4] 2> "shard":"shard1",
[junit4] 2> "node_name":"127.0.0.1:58841__pm",
[junit4] 2> "base_url":"http://127.0.0.1:58841/_pm",
[junit4] 2> "roles":null,
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "numShards":"2",
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active"}
[junit4] 2> 1698398 INFO (OverseerStateUpdate-94999150421606404-127.0.0.1:58841__pm-n_0000000000) [n:127.0.0.1:58841__pm ] o.a.s.c.o.ZkStateWriter going to create_collection /collections/collection1/state.json
[junit4] 2> 1698502 INFO (zkCallback-1079-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: 1)
[junit4] 2> 1698503 INFO (zkCallback-1077-thread-1-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm ] 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> 1698722 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/shard-1-001/cores/collection1
[junit4] 2> 1698723 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 1 in directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/shard-1-001
[junit4] 2> 1698724 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.e.j.s.Server jetty-9.2.13.v20150730
[junit4] 2> 1698726 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@e1146f7{/_pm,null,AVAILABLE}
[junit4] 2> 1698727 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.e.j.s.ServerConnector Started ServerConnector@6cab78c2{HTTP/1.1}{127.0.0.1:39299}
[junit4] 2> 1698727 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.e.j.s.Server Started @1701506ms
[junit4] 2> 1698727 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/shard-1-001/cores, hostContext=/_pm, hostPort=39299, solrconfig=solrconfig.xml, solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/tempDir-001/jetty1}
[junit4] 2> 1698727 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init(): sun.misc.Launcher$AppClassLoader@7b3cb2c6
[junit4] 2> 1698727 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/shard-1-001'
[junit4] 2> 1698727 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1698727 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find system property or JNDI)
[junit4] 2> 1698728 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 1698728 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1698730 INFO (zkCallback-1081-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@1d485865 name:ZooKeeperConnection Watcher:127.0.0.1:43566/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1698730 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1698731 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 1698732 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 1698732 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/shard-1-001/solr.xml
[junit4] 2> 1698748 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.CorePropertiesLocator Config-defined core root directory: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/shard-1-001/cores
[junit4] 2> 1698748 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.CoreContainer New CoreContainer 400473856
[junit4] 2> 1698748 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.CoreContainer Loading cores into CoreContainer [instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/shard-1-001]
[junit4] 2> 1698748 WARN (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.CoreContainer Couldn't add files from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/shard-1-001/lib to classpath: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/shard-1-001/lib
[junit4] 2> 1698748 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] 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> 1698750 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 1698750 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1698750 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.l.LogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1698750 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:43566/solr
[junit4] 2> 1698751 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.ZkController zkHost includes chroot
[junit4] 2> 1698751 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 1698751 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1698753 INFO (zkCallback-1083-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@7974d606 name:ZooKeeperConnection Watcher:127.0.0.1:43566 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1698753 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1698753 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 1698755 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:39299__pm ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1698756 INFO (zkCallback-1084-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@440c8902 name:ZooKeeperConnection Watcher:127.0.0.1:43566/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1698756 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:39299__pm ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1698763 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:39299__pm ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 1699772 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:39299__pm ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39299__pm
[junit4] 2> 1699773 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:39299__pm ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/127.0.0.1:39299__pm
[junit4] 2> 1699774 INFO (zkCallback-1079-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1699775 INFO (zkCallback-1077-thread-2-processing-n:127.0.0.1:58841__pm) [n:127.0.0.1:58841__pm ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1699775 INFO (zkCallback-1084-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1699776 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:39299__pm ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1699778 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:39299__pm ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/94999150421606409-127.0.0.1:39299__pm-n_0000000001
[junit4] 2> 1699778 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:39299__pm ] o.a.s.c.LeaderElector Watching path /overseer_elect/election/94999150421606404-127.0.0.1:58841__pm-n_0000000000 to know if I could be the leader
[junit4] 2> 1699790 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:39299__pm ] o.a.s.c.CoreContainer Security conf doesn't exist. Skipping setup for authorization module.
[junit4] 2> 1699790 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:39299__pm ] o.a.s.c.CoreContainer No authentication plugin used.
[junit4] 2> 1699791 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:39299__pm ] o.a.s.c.CorePropertiesLocator Looking for core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/shard-1-001/cores
[junit4] 2> 1699792 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:39299__pm ] o.a.s.c.CoreDescriptor Created CoreDescriptor: {absoluteInstDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/shard-1-001/cores/collection1/, dataDir=data/, collection=collection1, name=collection1, loadOnStartup=true, instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/shard-1-001/cores/collection1, config=solrconfig.xml, transient=false, configSetProperties=configsetprops.json, coreNodeName=, schema=schema.xml, shard=}
[junit4] 2> 1699792 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:39299__pm ] o.a.s.c.CorePropertiesLocator Found core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/shard-1-001/cores/collection1/
[junit4] 2> 1699792 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:39299__pm ] o.a.s.c.CorePropertiesLocator Found 1 core definitions
[junit4] 2> 1699793 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:39299__pm ] o.a.s.s.SolrDispatchFilter user.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0
[junit4] 2> 1699793 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[EB19EDDE5315287C]) [n:127.0.0.1:39299__pm ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init() done
[junit4] 2> 1699794 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 x:collection1] o.a.s.c.ZkController publishing state=down
[junit4] 2> 1699794 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 x:collection1] o.a.s.c.ZkController numShards not found on descriptor - reading it from system property
[junit4] 2> 1699795 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 x:collection1] o.a.s.c.ZkController Registering watch for collection collection1
[junit4] 2> 1699796 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 x:collection1] o.a.s.c.c.ZkStateReader addZkWatch collection1
[junit4] 2> 1699796 INFO (OverseerStateUpdate-94999150421606404-127.0.0.1:58841__pm-n_0000000000) [n:127.0.0.1:58841__pm ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "shard":null,
[junit4] 2> "node_name":"127.0.0.1:39299__pm",
[junit4] 2> "base_url":"http://127.0.0.1:39299/_pm",
[junit4] 2> "roles":null,
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down"} current state version: 3
[junit4] 2> 1699796 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 x:collection1] o.a.s.c.c.ZkStateReader Add data for collection1 ver 0
[junit4] 2> 1699796 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 x:collection1] o.a.s.c.ZkController look for our core node name
[junit4] 2> 1699797 INFO (OverseerStateUpdate-94999150421606404-127.0.0.1:58841__pm-n_0000000000) [n:127.0.0.1:58841__pm ] o.a.s.c.o.ReplicaMutator Update state numShards=2 message={
[junit4] 2> "shard":null,
[junit4] 2> "node_name":"127.0.0.1:39299__pm",
[junit4] 2> "base_url":"http://127.0.0.1:39299/_pm",
[junit4] 2> "roles":null,
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down"}
[junit4] 2> 1699797 INFO (OverseerStateUpdate-94999150421606404-127.0.0.1:58841__pm-n_0000000000) [n:127.0.0.1:58841__pm ] o.a.s.c.o.ReplicaMutator Collection already exists with numShards=2
[junit4] 2> 1699797 INFO (OverseerStateUpdate-94999150421606404-127.0.0.1:58841__pm-n_0000000000) [n:127.0.0.1:58841__pm ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2
[junit4] 2> 1699900 INFO (OverseerStateUpdate-94999150421606404-127.0.0.1:58841__pm-n_0000000000) [n:127.0.0.1:58841__pm ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/collection1/state.json version: 0
[junit4] 2> 1699901 INFO (zkCallback-1084-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json for collection collection1 has occurred - updating... (live nodes size: 2)
[junit4] 2> 1699901 INFO (zkCallback-1084-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm ] o.a.s.c.c.ZkStateReader Updating data for collection1 from 0 to 1
[junit4] 2> 1700796 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 x:collection1] o.a.s.c.ZkController waiting to find shard id in clusterstate for collection1
[junit4] 2> 1700797 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 x:collection1] o.a.s.c.ZkController Check for collection zkNode:collection1
[junit4] 2> 1700797 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 x:collection1] o.a.s.c.ZkController Collection zkNode exists
[junit4] 2> 1700797 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 x:collection1] o.a.s.c.c.ZkStateReader Load collection config from:/collections/collection1
[junit4] 2> 1700798 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 x:collection1] o.a.s.c.c.ZkStateReader path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1700798 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 x:collection1] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/shard-1-001/cores/collection1'
[junit4] 2> 1700798 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 x:collection1] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1700798 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 x:collection1] o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find system property or JNDI)
[junit4] 2> 1700800 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 x:collection1] o.a.s.c.Config loaded config solrconfig.xml with version 0
[junit4] 2> 1700807 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 x:collection1] o.a.s.c.SolrConfig current version of requestparams : -1
[junit4] 2> 1700837 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 5.4.0
[junit4] 2> 1700870 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 x:collection1] o.a.s.c.SolrConfig Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1700879 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1701161 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1701170 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 x:collection1] o.a.s.s.IndexSchema default search field in schema is text
[junit4] 2> 1701172 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 x:collection1] o.a.s.s.IndexSchema unique key field: id
[junit4] 2> 1701185 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
[junit4] 2> 1701189 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
[junit4] 2> 1701192 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1701193 WARN (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Unknown key IMPORTANT NOTE
[junit4] 2> 1701193 WARN (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Expected key, got STRING
[junit4] 2> 1701193 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1701194 WARN (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Unknown key IMPORTANT NOTE
[junit4] 2> 1701194 WARN (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Expected key, got STRING
[junit4] 2> 1701196 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 x:collection1] o.a.s.c.ConfigSetProperties Did not find ConfigSet properties, assuming default properties: Can't find resource 'configsetprops.json' in classpath or '/configs/conf1', cwd=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0
[junit4] 2> 1701196 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 1701196 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.SolrCore org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1701196 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/shard-1-001/cores/collection1], dataDir=[null]
[junit4] 2> 1701196 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm 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@189b7091
[junit4] 2> 1701197 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/shard-1-001/cores/collection1/data
[junit4] 2> 1701197 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.SolrCore New index directory detected: old=null new=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/shard-1-001/cores/collection1/data/index/
[junit4] 2> 1701197 WARN (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.SolrCore [collection1] Solr index directory '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_EB19EDDE5315287C-001/shard-1-001/cores/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 1701197 INFO (coreLoadExecutor-3671-thread-1-processing-n:127.0.0.1:39299__pm) [n:127.0.0.1:39299__pm c:collection
[...truncated too long message...]
TGRP-CollectionsAPIDistributedZkTest]
[junit4] > Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:45927/_pm: collection already exists: awholynewstresscollection_collection5_0
[junit4] > at __randomizedtesting.SeedInfo.seed([EB19EDDE5315287C]:0)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:575)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:241)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:230)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:372)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:325)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1100)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:871)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:807)
[junit4] > at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1220)
[junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1574)
[junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1595)
[junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:881)Throwable #5: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=59604, name=collection0, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest]
[junit4] > Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:56037/_pm: collection already exists: awholynewstresscollection_collection0_0
[junit4] > at __randomizedtesting.SeedInfo.seed([EB19EDDE5315287C]:0)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:575)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:241)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:230)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:372)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:325)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1100)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:871)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:807)
[junit4] > at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1220)
[junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1574)
[junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1595)
[junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:881)Throwable #6: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=59606, name=collection2, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest]
[junit4] > Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:56037/_pm: Could not find collection : awholynewstresscollection_collection2_0
[junit4] > at __randomizedtesting.SeedInfo.seed([EB19EDDE5315287C]:0)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:575)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:241)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:230)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:372)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:325)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1100)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:871)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:807)
[junit4] > at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1220)
[junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:888)
[junit4] 2> 2133018 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[EB19EDDE5315287C]-worker) [n:127.0.0.1:45927__pm c:awholynewstresscollection_collection0_0 s:shard5 r:core_node8 x:awholynewstresscollection_collection0_0_shard5_replica2] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> Dec 08, 2015 11:00:34 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene54): {range_facet_i_dv=FSTOrd50, intDefault=FSTOrd50, range_facet_l=FSTOrd50, a_i1=FSTOrd50, timestamp=FSTOrd50, _version_=FSTOrd50, text=PostingsFormat(name=Direct), other_tl1=FSTOrd50, multiDefault=PostingsFormat(name=Asserting), a_t=FSTOrd50, range_facet_l_dv=FST50, id=FST50}, docValues:{range_facet_i_dv=DocValuesFormat(name=Memory), timestamp=DocValuesFormat(name=Memory), range_facet_l_dv=DocValuesFormat(name=Lucene54)}, sim=DefaultSimilarity, locale=lv, timezone=Asia/Harbin
[junit4] 2> NOTE: Linux 3.13.0-52-generic amd64/Oracle Corporation 1.7.0_80 (64-bit)/cpus=4,threads=1,free=72306112,total=469762048
[junit4] 2> NOTE: All tests run in this JVM: [TestAtomicUpdateErrorCases, TestJsonFacets, TestPKIAuthenticationPlugin, URLClassifyProcessorTest, LeaderElectionIntegrationTest, ConnectionManagerTest, TestOmitPositions, TestFieldSortValues, AnalyticsMergeStrategyTest, DistributedQueryElevationComponentTest, DeleteLastCustomShardedReplicaTest, SolrCloudExampleTest, TestInitParams, TestRTGBase, EchoParamsTest, TestBadConfig, HttpPartitionTest, TestMacros, TestManagedSchema, JSONWriterTest, TestComponentsName, SOLR749Test, TestSimpleTrackingShardHandler, TestLMDirichletSimilarityFactory, TestCSVLoader, SystemInfoHandlerTest, SolrRequestParserTest, AsyncMigrateRouteKeyTest, TestShortCircuitedRequests, TestLRUCache, ReturnFieldsTest, TestRandomMergePolicy, TestMinMaxOnMultiValuedField, TestCursorMarkWithoutUniqueKey, ZkStateWriterTest, TestPseudoReturnFields, IndexSchemaRuntimeFieldTest, DeleteShardTest, TestConfigReload, QueryEqualityTest, QueryElevationComponentTest, TestCustomDocTransformer, TestReqParamsAPI, TestExceedMaxTermLength, DistributedDebugComponentTest, SignatureUpdateProcessorFactoryTest, XsltUpdateRequestHandlerTest, CollectionReloadTest, TestLazyCores, BasicAuthIntegrationTest, TestSchemaManager, HdfsLockFactoryTest, PeerSyncTest, TestFunctionQuery, CacheHeaderTest, TestIBSimilarityFactory, EnumFieldTest, ExternalFileFieldSortTest, TestDistributedSearch, DistributedSuggestComponentTest, TestSmileRequest, CachingDirectoryFactoryTest, VMParamsZkACLAndCredentialsProvidersTest, ConfigSetsAPITest, SegmentsInfoRequestHandlerTest, TestSchemaSimilarityResource, TestCollectionAPI, DeleteInactiveReplicaTest, CurrencyFieldOpenExchangeTest, AnalysisAfterCoreReloadTest, ReplicationFactorTest, DistributedQueueTest, TestConfigSets, HLLUtilTest, TestShardHandlerFactory, TestCustomSort, JavabinLoaderTest, TestRemoteStreaming, TestNamedUpdateProcessors, TestRecoveryHdfs, TestRawResponseWriter, TestConfigSetsAPIExclusivity, UUIDFieldTest, HdfsWriteToMultipleCollectionsTest, TestDynamicLoading, AnalysisErrorHandlingTest, PreAnalyzedFieldTest, TestRTimerTree, TestBinaryField, ResourceLoaderTest, BasicDistributedZkTest, UnloadDistributedZkTest, CollectionsAPIDistributedZkTest]
[junit4] Completed [225/551] on J0 in 437.69s, 1 test, 1 error <<< FAILURES!
[...truncated 1043 lines...]
BUILD FAILED
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/build.xml:799: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/build.xml:736: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/build.xml:59: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build.xml:233: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/common-build.xml:526: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/common-build.xml:1452: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/common-build.xml:1006: There were test failures: 551 suites (7 ignored), 2177 tests, 1 error, 32 ignored (18 assumptions) [seed: EB19EDDE5315287C]
Total time: 209 minutes 5 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
No prior successful build to compare, so performing full copy of artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any