Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-6.x/106/
2 tests failed. FAILED: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.test Error Message: Captured an uncaught exception in thread: Thread[id=50182, name=collection2, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest] Stack Trace: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=50182, name=collection2, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest] Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:37887/t/u: collection already exists: awholynewstresscollection_collection2_0 at __randomizedtesting.SeedInfo.seed([502018AF5E6CE827]:0) at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:590) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:259) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:248) at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:403) at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:356) at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1228) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:998) at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:934) at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1219) at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1599) at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1620) at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:987) FAILED: junit.framework.TestSuite.org.apache.solr.handler.TestReplicationHandler Error Message: ObjectTracker found 11 object(s) that were not released!!! [NRTCachingDirectory, NRTCachingDirectory, NRTCachingDirectory, NRTCachingDirectory, NRTCachingDirectory, NRTCachingDirectory, NRTCachingDirectory, NRTCachingDirectory, NRTCachingDirectory, NRTCachingDirectory, NRTCachingDirectory] Stack Trace: java.lang.AssertionError: ObjectTracker found 11 object(s) that were not released!!! [NRTCachingDirectory, NRTCachingDirectory, NRTCachingDirectory, NRTCachingDirectory, NRTCachingDirectory, NRTCachingDirectory, NRTCachingDirectory, NRTCachingDirectory, NRTCachingDirectory, NRTCachingDirectory, NRTCachingDirectory] at __randomizedtesting.SeedInfo.seed([502018AF5E6CE827]:0) at org.junit.Assert.fail(Assert.java:93) at org.junit.Assert.assertTrue(Assert.java:43) at org.junit.Assert.assertNull(Assert.java:551) at org.apache.solr.SolrTestCaseJ4.teardownTestCases(SolrTestCaseJ4.java:257) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1764) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:834) 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:45) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) 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:53) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) 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 11214 lines...] [junit4] JVM J2: stdout was not empty, see: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/temp/junit4-J2-20160630_125455_754.sysout [junit4] >>> JVM J2 emitted unexpected output (verbatim) ---- [junit4] java.lang.OutOfMemoryError: GC overhead limit exceeded [junit4] Dumping heap to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/heapdumps/java_pid22102.hprof ... [junit4] Heap dump file created [615747174 bytes in 35.088 secs] [junit4] <<< JVM J2: EOF ---- [junit4] JVM J2: stderr was not empty, see: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/temp/junit4-J2-20160630_125455_754.syserr [junit4] >>> JVM J2 emitted unexpected output (verbatim) ---- [junit4] WARN: Unhandled exception in event serialization. -> java.lang.OutOfMemoryError: GC overhead limit exceeded [junit4] <<< JVM J2: EOF ---- [...truncated 588 lines...] [junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest [junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_502018AF5E6CE827-001/init-core-data-001 [junit4] 2> 2194310 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[502018AF5E6CE827]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN) [junit4] 2> 2194310 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[502018AF5E6CE827]-worker) [ ] o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /t/u [junit4] 2> 2194313 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 2194313 INFO (Thread-40720) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 2194313 INFO (Thread-40720) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 2194413 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.ZkTestServer start zk server on port:56634 [junit4] 2> 2194413 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 2194414 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 2194416 INFO (zkCallback-2085-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@66fb1071 name:ZooKeeperConnection Watcher:127.0.0.1:56634 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2194416 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 2194416 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 2194416 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr [junit4] 2> 2194418 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 2194419 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 2194419 INFO (zkCallback-2086-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@54e7764 name:ZooKeeperConnection Watcher:127.0.0.1:56634/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2194419 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 2194419 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 2194419 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1 [junit4] 2> 2194420 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/shards [junit4] 2> 2194421 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection [junit4] 2> 2194422 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/shards [junit4] 2> 2194422 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml [junit4] 2> 2194422 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/solrconfig.xml [junit4] 2> 2194424 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml [junit4] 2> 2194424 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/schema.xml [junit4] 2> 2194425 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml [junit4] 2> 2194425 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml [junit4] 2> 2194426 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt [junit4] 2> 2194426 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/stopwords.txt [junit4] 2> 2194426 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt [junit4] 2> 2194427 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/protwords.txt [junit4] 2> 2194427 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml [junit4] 2> 2194427 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/currency.xml [junit4] 2> 2194428 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml [junit4] 2> 2194428 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/enumsConfig.xml [junit4] 2> 2194429 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json [junit4] 2> 2194429 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/open-exchange-rates.json [junit4] 2> 2194430 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt [junit4] 2> 2194430 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/mapping-ISOLatin1Accent.txt [junit4] 2> 2194431 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt [junit4] 2> 2194431 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/old_synonyms.txt [junit4] 2> 2194432 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt [junit4] 2> 2194432 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/synonyms.txt [junit4] 2> 2194494 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_502018AF5E6CE827-001/control-001/cores/collection1 [junit4] 2> 2194496 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.e.j.s.Server jetty-9.3.8.v20160314 [junit4] 2> 2194497 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@18c80131{/t/u,null,AVAILABLE} [junit4] 2> 2194497 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.e.j.s.ServerConnector Started ServerConnector@17fa3651{HTTP/1.1,[http/1.1]}{127.0.0.1:37887} [junit4] 2> 2194497 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.e.j.s.Server Started @2198654ms [junit4] 2> 2194498 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_502018AF5E6CE827-001/tempDir-001/control/data, hostContext=/t/u, hostPort=37887, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_502018AF5E6CE827-001/control-001/cores} [junit4] 2> 2194498 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init(): sun.misc.Launcher$AppClassLoader@73d16e93 [junit4] 2> 2194498 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_502018AF5E6CE827-001/control-001' [junit4] 2> 2194498 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 2194498 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find system property or JNDI) [junit4] 2> 2194499 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 2194499 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 2194505 INFO (zkCallback-2087-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@4cba1669 name:ZooKeeperConnection Watcher:127.0.0.1:56634/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2194505 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 2194506 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 2194507 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper) [junit4] 2> 2194507 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_502018AF5E6CE827-001/control-001/solr.xml [junit4] 2> 2194513 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.CorePropertiesLocator Config-defined core root directory: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_502018AF5E6CE827-001/control-001/cores [junit4] 2> 2194513 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.CoreContainer New CoreContainer 1247706713 [junit4] 2> 2194513 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.CoreContainer Loading cores into CoreContainer [instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_502018AF5E6CE827-001/control-001] [junit4] 2> 2194513 WARN (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.CoreContainer Couldn't add files from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_502018AF5E6CE827-001/control-001/lib to classpath: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_502018AF5E6CE827-001/control-001/lib [junit4] 2> 2194513 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] 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> 2194514 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 2194514 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory [junit4] 2> 2194514 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.l.LogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)] [junit4] 2> 2194514 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:56634/solr [junit4] 2> 2194514 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.ZkController zkHost includes chroot [junit4] 2> 2194514 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 2194515 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 2194517 INFO (zkCallback-2090-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@20e41 name:ZooKeeperConnection Watcher:127.0.0.1:56634 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2194518 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 2194518 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 2194519 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.ZkController Added new OnReconnect listener org.apache.solr.cloud.ZkController$$Lambda$57/1449134916@65e73abe [junit4] 2> 2194519 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 2194520 INFO (zkCallback-2091-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@6f8b8c38 name:ZooKeeperConnection Watcher:127.0.0.1:56634/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2194520 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 2194520 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue [junit4] 2> 2194521 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-queue-work [junit4] 2> 2194522 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-running [junit4] 2> 2194523 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-completed [junit4] 2> 2194523 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-failure [junit4] 2> 2194524 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.c.SolrZkClient makePath: /live_nodes [junit4] 2> 2194525 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.c.SolrZkClient makePath: /aliases.json [junit4] 2> 2194525 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json [junit4] 2> 2194526 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.c.SolrZkClient makePath: /security.json [junit4] 2> 2194526 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 2194526 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.c.ZkStateReader Loaded empty cluster properties [junit4] 2> 2194526 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (0) [junit4] 2> 2194527 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect [junit4] 2> 2194528 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/election [junit4] 2> 2194528 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 2194529 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/96160546440544260-127.0.0.1:37887_t%2Fu-n_0000000000 [junit4] 2> 2194529 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:37887_t%2Fu [junit4] 2> 2194529 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader [junit4] 2> 2194529 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.Overseer Overseer (id=96160546440544260-127.0.0.1:37887_t%2Fu-n_0000000000) starting [junit4] 2> 2194530 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue-work [junit4] 2> 2194532 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.OverseerAutoReplicaFailoverThread Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=10000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 2194540 INFO (OverseerStateUpdate-96160546440544260-127.0.0.1:37887_t%2Fu-n_0000000000) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.Overseer Starting to work on the main queue [junit4] 2> 2194540 INFO (OverseerCollectionConfigSetProcessor-96160546440544260-127.0.0.1:37887_t%2Fu-n_0000000000) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.OverseerTaskProcessor Process current queue of overseer operations [junit4] 2> 2194543 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37887_t%2Fu [junit4] 2> 2194543 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/127.0.0.1:37887_t%2Fu [junit4] 2> 2194544 INFO (zkCallback-2091-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live nodes size: [0]) [junit4] 2> 2194544 INFO (OverseerStateUpdate-96160546440544260-127.0.0.1:37887_t%2Fu-n_0000000000) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 2194545 INFO (zkCallback-2091-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (1) [junit4] 2> 2194558 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.CoreContainer Security conf doesn't exist. Skipping setup for authorization module. [junit4] 2> 2194558 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.CoreContainer No authentication plugin used. [junit4] 2> 2194559 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.CorePropertiesLocator Looking for core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_502018AF5E6CE827-001/control-001/cores [junit4] 2> 2194559 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.CoreDescriptor Created CoreDescriptor: {name=collection1, config=solrconfig.xml, transient=false, schema=schema.xml, loadOnStartup=true, configSetProperties=configsetprops.json, collection=control_collection, coreNodeName=, dataDir=data/, shard=} [junit4] 2> 2194559 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.CorePropertiesLocator Found core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_502018AF5E6CE827-001/control-001/cores/collection1 [junit4] 2> 2194559 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.CorePropertiesLocator Found 1 core definitions [junit4] 2> 2194560 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection x:collection1] o.a.s.c.ZkController publishing state=down [junit4] 2> 2194560 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection x:collection1] o.a.s.c.ZkController numShards not found on descriptor - reading it from system property [junit4] 2> 2194561 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection x:collection1] o.a.s.c.ZkController Collection control_collection not visible yet, but flagging it so a watch is registered when it becomes visible [junit4] 2> 2194562 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection x:collection1] o.a.s.c.c.ZkStateReader Deleting data for [control_collection] [junit4] 2> 2194563 INFO (OverseerStateUpdate-96160546440544260-127.0.0.1:37887_t%2Fu-n_0000000000) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "core":"collection1", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:37887/t/u";, [junit4] 2> "node_name":"127.0.0.1:37887_t%2Fu", [junit4] 2> "numShards":"1", [junit4] 2> "state":"down", [junit4] 2> "shard":null, [junit4] 2> "collection":"control_collection", [junit4] 2> "operation":"state"} current state version: 0 [junit4] 2> 2194563 INFO (OverseerStateUpdate-96160546440544260-127.0.0.1:37887_t%2Fu-n_0000000000) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={ [junit4] 2> "core":"collection1", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:37887/t/u";, [junit4] 2> "node_name":"127.0.0.1:37887_t%2Fu", [junit4] 2> "numShards":"1", [junit4] 2> "state":"down", [junit4] 2> "shard":null, [junit4] 2> "collection":"control_collection", [junit4] 2> "operation":"state"} [junit4] 2> 2194563 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection x:collection1] o.a.s.c.ZkController look for our core node name [junit4] 2> 2194563 INFO (OverseerStateUpdate-96160546440544260-127.0.0.1:37887_t%2Fu-n_0000000000) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.o.ClusterStateMutator building a new cName: control_collection [junit4] 2> 2194564 INFO (OverseerStateUpdate-96160546440544260-127.0.0.1:37887_t%2Fu-n_0000000000) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1 [junit4] 2> 2194564 INFO (zkCallback-2091-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu ] 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> 2194568 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.s.SolrDispatchFilter user.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0 [junit4] 2> 2194568 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:37887_t%2Fu ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init() done [junit4] 2> 2195564 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection x:collection1] o.a.s.c.ZkController waiting to find shard id in clusterstate for collection1 [junit4] 2> 2195564 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection x:collection1] o.a.s.c.ZkController Check for collection zkNode:control_collection [junit4] 2> 2195564 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection x:collection1] o.a.s.c.ZkController Collection zkNode exists [junit4] 2> 2195564 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection x:collection1] o.a.s.c.c.ZkStateReader Load collection config from: [/collections/control_collection] [junit4] 2> 2195564 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection x:collection1] o.a.s.c.c.ZkStateReader path=[/collections/control_collection] [configName]=[conf1] specified config exists in ZooKeeper [junit4] 2> 2195564 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection x:collection1] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_502018AF5E6CE827-001/control-001/cores/collection1' [junit4] 2> 2195564 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection x:collection1] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 2195564 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection x:collection1] o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find system property or JNDI) [junit4] 2> 2195565 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection x:collection1] o.a.s.c.Config loaded config solrconfig.xml with version 0 [junit4] 2> 2195568 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection x:collection1] o.a.s.c.SolrConfig current version of requestparams : -1 [junit4] 2> 2195571 WARN (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection x:collection1] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead. [junit4] 2> 2195572 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.2.0 [junit4] 2> 2195591 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection x:collection1] o.a.s.c.SolrConfig Loaded SolrConfig: solrconfig.xml [junit4] 2> 2195595 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 2195712 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Initialized with rates=open-exchange-rates.json, refreshInterval=1440. [junit4] 2> 2195716 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection x:collection1] o.a.s.s.IndexSchema default search field in schema is text [junit4] 2> 2195717 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection x:collection1] o.a.s.s.IndexSchema unique key field: id [junit4] 2> 2195723 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml [junit4] 2> 2195724 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml [junit4] 2> 2195725 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json [junit4] 2> 2195726 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json [junit4] 2> 2195727 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu 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-6.x/solr/build/solr-core/test/J0 [junit4] 2> 2195727 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection control_collection [junit4] 2> 2195727 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore org.apache.solr.core.MockDirectoryFactory [junit4] 2> 2195727 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu 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-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_502018AF5E6CE827-001/control-001/cores/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_502018AF5E6CE827-001/control-001/cores/collection1/data/] [junit4] 2> 2195727 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu 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@2cb23ca0 [junit4] 2> 2195727 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu 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-6.x/solr/build/solr-core/test/J0/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_502018AF5E6CE827-001/control-001/cores/collection1/data [junit4] 2> 2195727 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu 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-6.x/solr/build/solr-core/test/J0/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_502018AF5E6CE827-001/control-001/cores/collection1/data/index/ [junit4] 2> 2195727 WARN (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu 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-6.x/solr/build/solr-core/test/J0/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_502018AF5E6CE827-001/control-001/cores/collection1/data/index' doesn't exist. Creating new index... [junit4] 2> 2195728 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu 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-6.x/solr/build/solr-core/test/J0/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_502018AF5E6CE827-001/control-001/cores/collection1/data/index [junit4] 2> 2195728 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=611606607, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1] [junit4] 2> 2195728 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu 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@378553c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1bab947b),segFN=segments_1,generation=1} [junit4] 2> 2195728 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 1 [junit4] 2> 2195728 INFO (OldIndexDirectoryCleanupThreadForCore-collection1) [n:127.0.0.1:37887_t%2Fu 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-6.x/solr/build/solr-core/test/J0/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_502018AF5E6CE827-001/control-001/cores/collection1/data/ [junit4] 2> 2195729 WARN (OldIndexDirectoryCleanupThreadForCore-collection1) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.DirectoryFactory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_502018AF5E6CE827-001/control-001/cores/collection1/data/ does not point to a valid data directory; skipping clean-up of old index directories. [junit4] 2> 2195730 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "nodistrib" [junit4] 2> 2195730 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "dedupe" [junit4] 2> 2195731 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe" [junit4] 2> 2195731 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "stored_sig" [junit4] 2> 2195731 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig" [junit4] 2> 2195731 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu 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> 2195731 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu 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> 2195731 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu 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> 2195731 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu 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> 2195731 WARN (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu 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> 2195732 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60 [junit4] 2> 2195732 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60 [junit4] 2> 2195733 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60 [junit4] 2> 2195733 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60 [junit4] 2> 2195735 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.RequestHandlers Registered paths: /admin/mbeans,standard,/update/json/docs,/admin/luke,/export,/get,/admin/properties,/update/json,/admin/threads,/dump,/update/csv,/sql,/graph,/admin/segments,/admin/system,/replication,/config,/stream,/schema,/admin/plugins,/admin/logging,/admin/ping,/update,/admin/file [junit4] 2> 2195735 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu 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> 2195735 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu 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> 2195735 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu 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> 2195736 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 2195736 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 2195736 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu 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=35, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.35466542856860384] [junit4] 2> 2195736 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu 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@378553c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1bab947b),segFN=segments_1,generation=1} [junit4] 2> 2195736 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 1 [junit4] 2> 2195736 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@3c9fa2b4[collection1] main] [junit4] 2> 2195737 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu 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> 2195737 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu 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> 2195737 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu 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> 2195737 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 2195737 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.RestManager Initializing RestManager with initArgs: {} [junit4] 2> 2195737 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu 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> 2195737 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu 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> 2195738 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu 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> 2195738 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.RestManager Initializing 0 registered ManagedResources [junit4] 2> 2195738 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 2195738 INFO (searcherExecutor-5170-thread-1-processing-n:127.0.0.1:37887_t%2Fu x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@3c9fa2b4[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 2195738 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu 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> 2195739 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu 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> 2195739 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu 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> 2195739 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu 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 1538568744542928896 [junit4] 2> 2195740 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Took 1.0ms to seed version buckets with highest version 1538568744542928896 [junit4] 2> 2195740 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController watch zkdir /configs/conf1 [junit4] 2> 2195741 INFO (coreLoadExecutor-5169-thread-1-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CoreContainer registering core: collection1 [junit4] 2> 2195741 INFO (coreZkRegister-5163-thread-1-processing-n:127.0.0.1:37887_t%2Fu x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:37887_t%2Fu 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:37887/t/u collection:control_collection shard:shard1 [junit4] 2> 2195742 INFO (coreZkRegister-5163-thread-1-processing-n:127.0.0.1:37887_t%2Fu x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:37887_t%2Fu 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> 2195746 INFO (coreZkRegister-5163-thread-1-processing-n:127.0.0.1:37887_t%2Fu x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:37887_t%2Fu 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/96160546440544260-core_node1-n_0000000000 [junit4] 2> 2195748 INFO (coreZkRegister-5163-thread-1-processing-n:127.0.0.1:37887_t%2Fu x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Running the leader process for shard=shard1 and weAreReplacement=false and leaderVoteWait=180000 [junit4] 2> 2195748 INFO (coreZkRegister-5163-thread-1-processing-n:127.0.0.1:37887_t%2Fu x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 2195749 INFO (OverseerStateUpdate-96160546440544260-127.0.0.1:37887_t%2Fu-n_0000000000) [n:127.0.0.1:37887_t%2Fu ] 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> 2195749 INFO (coreZkRegister-5163-thread-1-processing-n:127.0.0.1:37887_t%2Fu x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:37887_t%2Fu 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> 2195749 INFO (coreZkRegister-5163-thread-1-processing-n:127.0.0.1:37887_t%2Fu x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:37887/t/u/collection1/ [junit4] 2> 2195749 INFO (coreZkRegister-5163-thread-1-processing-n:127.0.0.1:37887_t%2Fu x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 2195749 INFO (coreZkRegister-5163-thread-1-processing-n:127.0.0.1:37887_t%2Fu x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy http://127.0.0.1:37887/t/u/collection1/ has no replicas [junit4] 2> 2195749 INFO (coreZkRegister-5163-thread-1-processing-n:127.0.0.1:37887_t%2Fu x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/leaders/shard1 [junit4] 2> 2195750 INFO (coreZkRegister-5163-thread-1-processing-n:127.0.0.1:37887_t%2Fu x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/control_collection/leaders/shard1/leader after winning as /collections/control_collection/leader_elect/shard1/election/96160546440544260-core_node1-n_0000000000 [junit4] 2> 2195751 INFO (coreZkRegister-5163-thread-1-processing-n:127.0.0.1:37887_t%2Fu x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:37887_t%2Fu 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:37887/t/u/collection1/ shard1 [junit4] 2> 2195752 INFO (OverseerStateUpdate-96160546440544260-127.0.0.1:37887_t%2Fu-n_0000000000) [n:127.0.0.1:37887_t%2Fu ] 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:37887/t/u";, [junit4] 2> "core":"collection1", [junit4] 2> "state":"active"} current state version: 1 [junit4] 2> 2195853 INFO (zkCallback-2091-thread-4-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu ] 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> 2195901 INFO (coreZkRegister-5163-thread-1-processing-n:127.0.0.1:37887_t%2Fu x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController We are http://127.0.0.1:37887/t/u/collection1/ and leader is http://127.0.0.1:37887/t/u/collection1/ [junit4] 2> 2195902 INFO (coreZkRegister-5163-thread-1-processing-n:127.0.0.1:37887_t%2Fu x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:37887_t%2Fu 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:37887/t/u [junit4] 2> 2195902 INFO (coreZkRegister-5163-thread-1-processing-n:127.0.0.1:37887_t%2Fu x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 2195902 INFO (coreZkRegister-5163-thread-1-processing-n:127.0.0.1:37887_t%2Fu x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:37887_t%2Fu c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController publishing state=active [junit4] 2> 2195902 INFO (coreZkRegister-5163-thread-1-processing-n:127.0.0.1:37887_t%2Fu x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:37887_t%2Fu 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> 2195903 INFO (OverseerStateUpdate-96160546440544260-127.0.0.1:37887_t%2Fu-n_0000000000) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "core":"collection1", [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:37887/t/u";, [junit4] 2> "node_name":"127.0.0.1:37887_t%2Fu", [junit4] 2> "numShards":"1", [junit4] 2> "state":"active", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"control_collection", [junit4] 2> "operation":"state"} current state version: 2 [junit4] 2> 2195903 INFO (OverseerStateUpdate-96160546440544260-127.0.0.1:37887_t%2Fu-n_0000000000) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={ [junit4] 2> "core":"collection1", [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:37887/t/u";, [junit4] 2> "node_name":"127.0.0.1:37887_t%2Fu", [junit4] 2> "numShards":"1", [junit4] 2> "state":"active", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"control_collection", [junit4] 2> "operation":"state"} [junit4] 2> 2196004 INFO (zkCallback-2091-thread-5-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu ] 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> 2196070 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 2196071 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 2196071 INFO (zkCallback-2095-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@3d98086f name:ZooKeeperConnection Watcher:127.0.0.1:56634/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2196072 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 2196072 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 2196072 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 2196072 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.ZkStateReader Loaded empty cluster properties [junit4] 2> 2196072 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 2196073 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.ChaosMonkey monkey: init - expire sessions:false cause connection loss:false [junit4] 2> 2196131 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_502018AF5E6CE827-001/shard-1-001/cores/collection1 [junit4] 2> 2196132 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 1 in directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_502018AF5E6CE827-001/shard-1-001 [junit4] 2> 2196132 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.e.j.s.Server jetty-9.3.8.v20160314 [junit4] 2> 2196133 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@55ce7d66{/t/u,null,AVAILABLE} [junit4] 2> 2196133 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.e.j.s.ServerConnector Started ServerConnector@3e7f0e88{HTTP/1.1,[http/1.1]}{127.0.0.1:59542} [junit4] 2> 2196133 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.e.j.s.Server Started @2200290ms [junit4] 2> 2196133 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_502018AF5E6CE827-001/tempDir-001/jetty1, solrconfig=solrconfig.xml, hostContext=/t/u, hostPort=59542, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_502018AF5E6CE827-001/shard-1-001/cores} [junit4] 2> 2196134 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init(): sun.misc.Launcher$AppClassLoader@73d16e93 [junit4] 2> 2196134 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_502018AF5E6CE827-001/shard-1-001' [junit4] 2> 2196134 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 2196134 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find system property or JNDI) [junit4] 2> 2196134 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 2196134 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 2196141 INFO (zkCallback-2096-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@6564f4a6 name:ZooKeeperConnection Watcher:127.0.0.1:56634/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2196142 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 2196142 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 2196142 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper) [junit4] 2> 2196142 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_502018AF5E6CE827-001/shard-1-001/solr.xml [junit4] 2> 2196145 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.CorePropertiesLocator Config-defined core root directory: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_502018AF5E6CE827-001/shard-1-001/cores [junit4] 2> 2196146 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.CoreContainer New CoreContainer 1503624596 [junit4] 2> 2196146 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.CoreContainer Loading cores into CoreContainer [instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_502018AF5E6CE827-001/shard-1-001] [junit4] 2> 2196146 WARN (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.CoreContainer Couldn't add files from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_502018AF5E6CE827-001/shard-1-001/lib to classpath: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_502018AF5E6CE827-001/shard-1-001/lib [junit4] 2> 2196146 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] 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> 2196147 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 2196147 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory [junit4] 2> 2196147 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.l.LogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)] [junit4] 2> 2196147 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:56634/solr [junit4] 2> 2196147 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.ZkController zkHost includes chroot [junit4] 2> 2196147 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 2196148 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 2196148 INFO (zkCallback-2099-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@6090941 name:ZooKeeperConnection Watcher:127.0.0.1:56634 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2196148 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 2196148 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 2196149 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:59542_t%2Fu ] o.a.s.c.ZkController Added new OnReconnect listener org.apache.solr.cloud.ZkController$$Lambda$57/1449134916@6e39e8a8 [junit4] 2> 2196149 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:59542_t%2Fu ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 2196150 INFO (zkCallback-2100-thread-1-processing-n:127.0.0.1:59542_t%2Fu) [n:127.0.0.1:59542_t%2Fu ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@5dbe67cf name:ZooKeeperConnection Watcher:127.0.0.1:56634/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2196150 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:59542_t%2Fu ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 2196152 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:59542_t%2Fu ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 2196152 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:59542_t%2Fu ] o.a.s.c.c.ZkStateReader Loaded empty cluster properties [junit4] 2> 2196152 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:59542_t%2Fu ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 2196153 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:59542_t%2Fu ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 2196153 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:59542_t%2Fu ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/96160546440544264-127.0.0.1:59542_t%2Fu-n_0000000001 [junit4] 2> 2196153 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:59542_t%2Fu ] o.a.s.c.LeaderElector Watching path /overseer_elect/election/96160546440544260-127.0.0.1:37887_t%2Fu-n_0000000000 to know if I could be the leader [junit4] 2> 2196153 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:59542_t%2Fu ] o.a.s.c.ZkController Publish node=127.0.0.1:59542_t%2Fu as DOWN [junit4] 2> 2196154 INFO (OverseerStateUpdate-96160546440544260-127.0.0.1:37887_t%2Fu-n_0000000000) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"downnode", [junit4] 2> "node_name":"127.0.0.1:59542_t%2Fu"} current state version: 3 [junit4] 2> 2196154 INFO (OverseerStateUpdate-96160546440544260-127.0.0.1:37887_t%2Fu-n_0000000000) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.o.NodeMutator DownNode state invoked for node: 127.0.0.1:59542_t%2Fu [junit4] 2> 2196255 INFO (zkCallback-2095-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> 2196256 INFO (zkCallback-2100-thread-1-processing-n:127.0.0.1:59542_t%2Fu) [n:127.0.0.1:59542_t%2Fu ] 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> 2196256 INFO (zkCallback-2091-thread-5-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu ] 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> 2197154 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:59542_t%2Fu ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:59542_t%2Fu [junit4] 2> 2197154 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:59542_t%2Fu ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/127.0.0.1:59542_t%2Fu [junit4] 2> 2197156 INFO (zkCallback-2091-thread-5-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu ] 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> 2197156 INFO (zkCallback-2095-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> 2197156 INFO (zkCallback-2100-thread-1-processing-n:127.0.0.1:59542_t%2Fu) [n:127.0.0.1:59542_t%2Fu ] 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> 2197156 INFO (zkCallback-2095-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 2197156 INFO (zkCallback-2091-thread-5-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 2197160 INFO (zkCallback-2100-thread-1-processing-n:127.0.0.1:59542_t%2Fu) [n:127.0.0.1:59542_t%2Fu ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 2197171 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:59542_t%2Fu ] o.a.s.c.CoreContainer Security conf doesn't exist. Skipping setup for authorization module. [junit4] 2> 2197171 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:59542_t%2Fu ] o.a.s.c.CoreContainer No authentication plugin used. [junit4] 2> 2197172 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:59542_t%2Fu ] o.a.s.c.CorePropertiesLocator Looking for core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_502018AF5E6CE827-001/shard-1-001/cores [junit4] 2> 2197172 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:59542_t%2Fu ] o.a.s.c.CoreDescriptor Created CoreDescriptor: {name=collection1, config=solrconfig.xml, transient=false, schema=schema.xml, loadOnStartup=true, configSetProperties=configsetprops.json, collection=collection1, coreNodeName=, dataDir=data/, shard=} [junit4] 2> 2197172 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:59542_t%2Fu ] o.a.s.c.CorePropertiesLocator Found core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_502018AF5E6CE827-001/shard-1-001/cores/collection1 [junit4] 2> 2197172 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:59542_t%2Fu ] o.a.s.c.CorePropertiesLocator Found 1 core definitions [junit4] 2> 2197173 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:59542_t%2Fu ] o.a.s.s.SolrDispatchFilter user.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/J0 [junit4] 2> 2197173 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[502018AF5E6CE827]) [n:127.0.0.1:59542_t%2Fu ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init() done [junit4] 2> 2197173 INFO (coreLoadExecutor-5180-thread-1-processing-n:127.0.0.1:59542_t%2Fu) [n:127.0.0.1:59542_t%2Fu c:collection1 x:collection1] o.a.s.c.ZkController publishing state=down [junit4] 2> 2197173 INFO (coreLoadExecutor-5180-thread-1-processing-n:127.0.0.1:59542_t%2Fu) [n:127.0.0.1:59542_t%2Fu c:collection1 x:collection1] o.a.s.c.ZkController numShards not found on descriptor - reading it from system property [junit4] 2> 2197174 INFO (coreLoadExecutor-5180-thread-1-processing-n:127.0.0.1:59542_t%2Fu) [n:127.0.0.1:59542_t%2Fu c:collection1 x:collection1] o.a.s.c.ZkController Collection collection1 not visible yet, but flagging it so a watch is registered when it becomes visible [junit4] 2> 2197174 INFO (OverseerStateUpdate-96160546440544260-127.0.0.1:37887_t%2Fu-n_0000000000) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "core":"collection1", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:59542/t/u";, [junit4] 2> "node_name":"127.0.0.1:59542_t%2Fu", [junit4] 2> "numShards":"2", [junit4] 2> "state":"down", [junit4] 2> "shard":null, [junit4] 2> "collection":"collection1", [junit4] 2> "operation":"state"} current state version: 4 [junit4] 2> 2197174 INFO (OverseerStateUpdate-96160546440544260-127.0.0.1:37887_t%2Fu-n_0000000000) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.o.ReplicaMutator Update state numShards=2 message={ [junit4] 2> "core":"collection1", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:59542/t/u";, [junit4] 2> "node_name":"127.0.0.1:59542_t%2Fu", [junit4] 2> "numShards":"2", [junit4] 2> "state":"down", [junit4] 2> "shard":null, [junit4] 2> "collection":"collection1", [junit4] 2> "operation":"state"} [junit4] 2> 2197174 INFO (OverseerStateUpdate-96160546440544260-127.0.0.1:37887_t%2Fu-n_0000000000) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.o.ClusterStateMutator building a new cName: collection1 [junit4] 2> 2197174 INFO (OverseerStateUpdate-96160546440544260-127.0.0.1:37887_t%2Fu-n_0000000000) [n:127.0.0.1:37887_t%2Fu ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2 [junit4] 2> 2197175 INFO (coreLoadExecutor-5180-thread-1-processing-n:127.0.0.1:59542_t%2Fu) [n:127.0.0.1:59542_t%2Fu c:collection1 x:collection1] o.a.s.c.c.ZkStateReader Deleting data for [collection1] [junit4] 2> 2197176 INFO (coreLoadExecutor-5180-thread-1-processing-n:127.0.0.1:59542_t%2Fu) [n:127.0.0.1:59542_t%2Fu c:collection1 x:collection1] o.a.s.c.ZkController look for our core node name [junit4] 2> 2197276 INFO (zkCallback-2095-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> 2197276 INFO (zkCallback-2091-thread-5-processing-n:127.0.0.1:37887_t%2Fu) [n:127.0.0.1:37887_t%2Fu ] 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> 2197276 INFO (zkCallback-2100-thread-1-processing-n:127.0.0.1:59542_t%2Fu) [n:127.0.0.1:59542_t%2Fu ] 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> 2198176 INFO (coreLoadExecutor-5180-thread-1-processing-n:127.0.0.1:59542_t%2Fu) [n:127.0.0.1:59542_t%2Fu c:collection1 x:collection1] o.a.s.c.ZkController waiting to find shard id in clusterstate for collection1 [junit4] 2> 2198176 INFO (coreLoadExecutor-5180-thread-1-processing-n:127.0.0.1:59542_t%2Fu) [n:127.0.0.1:59542_t%2Fu c:collection1 x:collection1] o.a.s.c [...truncated too long message...] htlyTests-6.x/solr/core/test-lib/apacheds-interceptors-journal-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/apacheds-interceptors-normalization-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/apacheds-interceptors-operational-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/apacheds-interceptors-referral-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/apacheds-interceptors-schema-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/apacheds-interceptors-subtree-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/apacheds-interceptors-trigger-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/apacheds-jdbm-partition-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/apacheds-jdbm1-2.0.0-M2.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/apacheds-kerberos-codec-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/apacheds-ldif-partition-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/apacheds-mavibot-partition-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/apacheds-protocol-kerberos-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/apacheds-protocol-ldap-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/apacheds-protocol-shared-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/apacheds-xdbm-partition-2.0.0-M15.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/api-all-1.0.0-M20.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/bcprov-jdk15-1.45.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/cglib-nodep-2.2.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/commons-collections-3.2.2.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/commons-math3-3.4.1.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/easymock-3.0.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/ehcache-core-2.4.4.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/hadoop-common-2.7.2-tests.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/hadoop-hdfs-2.7.2-tests.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/hadoop-minikdc-2.7.2.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/htrace-core-3.2.0-incubating.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/jackson-annotations-2.5.4.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/jackson-core-asl-1.9.13.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/jackson-databind-2.5.4.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/jackson-mapper-asl-1.9.13.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/jersey-core-1.9.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/jersey-server-1.9.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/jetty-6.1.26.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/jetty-util-6.1.26.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/mina-core-2.0.0-M5.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/mockito-core-1.9.5.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/netty-all-4.0.36.Final.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/objenesis-1.2.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/presto-parser-0.122.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/core/test-lib/slice-0.10.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/lucene/build/analysis/icu/lucene-analyzers-icu-6.2.0-SNAPSHOT.jar:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/contrib/solr-analysis-extras/classes/java:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/lucene/build/queryparser/classes/test:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/contrib/analysis-extras/lib/icu4j-56.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.8/lib/tools.jar:/x1/jenkins/.ivy2/cache/com.carrotsearch.randomizedtesting/junit4-ant/jars/junit4-ant-2.3.4.jar com.carrotsearch.ant.tasks.junit4.slave.SlaveMainSafe -eventsfile /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/temp/junit4-J2-20160630_125455_754.events @/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build/solr-core/test/temp/junit4-J2-20160630_125455_754.suites -stdin [junit4] ERROR: JVM J2 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:1501) [junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4.access$000(JUnit4.java:121) [junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4$2.call(JUnit4.java:955) [junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4$2.call(JUnit4.java:952) [junit4] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [junit4] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [junit4] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [junit4] at java.lang.Thread.run(Thread.java:745) BUILD FAILED /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/build.xml:747: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/build.xml:684: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/build.xml:59: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/build.xml:233: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/solr/common-build.xml:530: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/lucene/common-build.xml:1427: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/lucene/common-build.xml:984: 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: 295 minutes 28 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
--------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
