Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-6.5/7/
2 tests failed. FAILED: org.apache.solr.cloud.FullSolrCloudDistribCmdsTest.test Error Message: Captured an uncaught exception in thread: Thread[id=20725, name=Thread-8692, state=RUNNABLE, group=TGRP-FullSolrCloudDistribCmdsTest] Stack Trace: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=20725, name=Thread-8692, state=RUNNABLE, group=TGRP-FullSolrCloudDistribCmdsTest] Caused by: java.lang.RuntimeException: org.apache.solr.client.solrj.SolrServerException: Timeout occured while waiting response from server at: http://127.0.0.1:52658/_dy/bb/collection1 at __randomizedtesting.SeedInfo.seed([4BBDDB607670A81A]:0) at org.apache.solr.cloud.FullSolrCloudDistribCmdsTest$1IndexThread.run(FullSolrCloudDistribCmdsTest.java:644) Caused by: org.apache.solr.client.solrj.SolrServerException: Timeout occured while waiting response from server at: http://127.0.0.1:52658/_dy/bb/collection1 at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:621) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:279) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:268) at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:160) at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:177) at org.apache.solr.cloud.FullSolrCloudDistribCmdsTest$1IndexThread.run(FullSolrCloudDistribCmdsTest.java:642) Caused by: java.net.SocketTimeoutException: Read timed out at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.socketRead(SocketInputStream.java:116) at java.net.SocketInputStream.read(SocketInputStream.java:171) at java.net.SocketInputStream.read(SocketInputStream.java:141) at org.apache.http.impl.io.AbstractSessionInputBuffer.fillBuffer(AbstractSessionInputBuffer.java:160) at org.apache.http.impl.io.SocketInputBuffer.fillBuffer(SocketInputBuffer.java:84) at org.apache.http.impl.io.AbstractSessionInputBuffer.readLine(AbstractSessionInputBuffer.java:273) at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:140) at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57) at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:261) at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:283) at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:251) at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:197) at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:272) at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:124) at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:685) at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:487) at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:882) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55) at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:515) ... 5 more FAILED: org.apache.solr.store.blockcache.BlockDirectoryTest.ensureCacheConfigurable Error Message: Direct buffer memory Stack Trace: java.lang.OutOfMemoryError: Direct buffer memory at java.nio.Bits.reserveMemory(Bits.java:693) at java.nio.DirectByteBuffer.<init>(DirectByteBuffer.java:123) at java.nio.ByteBuffer.allocateDirect(ByteBuffer.java:311) at org.apache.solr.store.blockcache.BlockCache.<init>(BlockCache.java:75) at org.apache.solr.store.blockcache.BlockDirectoryTest.setUp(BlockDirectoryTest.java:119) 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:1713) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:941) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863) 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:368) at java.lang.Thread.run(Thread.java:745) Build Log: [...truncated 13223 lines...] [junit4] Suite: org.apache.solr.cloud.FullSolrCloudDistribCmdsTest [junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/init-core-data-001 [junit4] 2> 2699442 WARN (SUITE-FullSolrCloudDistribCmdsTest-seed#[4BBDDB607670A81A]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=88 numCloses=88 [junit4] 2> 2699443 INFO (SUITE-FullSolrCloudDistribCmdsTest-seed#[4BBDDB607670A81A]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields [junit4] 2> 2699445 INFO (SUITE-FullSolrCloudDistribCmdsTest-seed#[4BBDDB607670A81A]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl=https://issues.apache.org/jira/browse/SOLR-5776) [junit4] 2> 2699445 INFO (SUITE-FullSolrCloudDistribCmdsTest-seed#[4BBDDB607670A81A]-worker) [ ] o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /_dy/bb [junit4] 2> 2699453 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 2699459 INFO (Thread-8604) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 2699459 INFO (Thread-8604) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 2699553 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.ZkTestServer start zk server on port:53068 [junit4] 2> 2699629 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml [junit4] 2> 2699632 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/core/src/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml [junit4] 2> 2699634 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml [junit4] 2> 2699645 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt [junit4] 2> 2699650 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt [junit4] 2> 2699654 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml [junit4] 2> 2699659 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml [junit4] 2> 2699660 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json [junit4] 2> 2699661 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt [junit4] 2> 2699663 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt [junit4] 2> 2699665 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt [junit4] 2> 2700173 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/control-001/cores/collection1 [junit4] 2> 2700175 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 2700251 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1d89d475{/_dy/bb,null,AVAILABLE} [junit4] 2> 2700253 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@40ac368e{HTTP/1.1,[http/1.1]}{127.0.0.1:52658} [junit4] 2> 2700253 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.e.j.s.Server Started @2706213ms [junit4] 2> 2700253 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/tempDir-001/control/data, hostContext=/_dy/bb, hostPort=52658, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/control-001/cores} [junit4] 2> 2700253 ERROR (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 2700253 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.5.0 [junit4] 2> 2700253 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2700253 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 2700253 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-04-05T17:11:54.125Z [junit4] 2> 2700272 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper) [junit4] 2> 2700272 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/control-001/solr.xml [junit4] 2> 2700318 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 2700320 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:53068/solr [junit4] 2> 2700529 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [n:127.0.0.1:52658__dy%2Fbb ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 2700530 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [n:127.0.0.1:52658__dy%2Fbb ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:52658__dy%2Fbb [junit4] 2> 2700531 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [n:127.0.0.1:52658__dy%2Fbb ] o.a.s.c.Overseer Overseer (id=97741197366591492-127.0.0.1:52658__dy%2Fbb-n_0000000000) starting [junit4] 2> 2700595 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [n:127.0.0.1:52658__dy%2Fbb ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52658__dy%2Fbb [junit4] 2> 2700597 INFO (zkCallback-2433-thread-1-processing-n:127.0.0.1:52658__dy%2Fbb) [n:127.0.0.1:52658__dy%2Fbb ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 2700770 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [n:127.0.0.1:52658__dy%2Fbb ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/control-001/cores [junit4] 2> 2700772 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [n:127.0.0.1:52658__dy%2Fbb ] o.a.s.c.CorePropertiesLocator Cores are: [collection1] [junit4] 2> 2700842 INFO (OverseerStateUpdate-97741197366591492-127.0.0.1:52658__dy%2Fbb-n_0000000000) [n:127.0.0.1:52658__dy%2Fbb ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1 [junit4] 2> 2701891 INFO (coreLoadExecutor-6195-thread-1-processing-n:127.0.0.1:52658__dy%2Fbb) [n:127.0.0.1:52658__dy%2Fbb c:control_collection x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0 [junit4] 2> 2702008 INFO (coreLoadExecutor-6195-thread-1-processing-n:127.0.0.1:52658__dy%2Fbb) [n:127.0.0.1:52658__dy%2Fbb c:control_collection x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 2702252 WARN (coreLoadExecutor-6195-thread-1-processing-n:127.0.0.1:52658__dy%2Fbb) [n:127.0.0.1:52658__dy%2Fbb c:control_collection x:collection1] o.a.s.s.IndexSchema [collection1] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead. [junit4] 2> 2702253 INFO (coreLoadExecutor-6195-thread-1-processing-n:127.0.0.1:52658__dy%2Fbb) [n:127.0.0.1:52658__dy%2Fbb c:control_collection x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id [junit4] 2> 2702280 INFO (coreLoadExecutor-6195-thread-1-processing-n:127.0.0.1:52658__dy%2Fbb) [n:127.0.0.1:52658__dy%2Fbb c:control_collection x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection control_collection [junit4] 2> 2702280 INFO (coreLoadExecutor-6195-thread-1-processing-n:127.0.0.1:52658__dy%2Fbb) [n:127.0.0.1:52658__dy%2Fbb c:control_collection x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 2702281 INFO (coreLoadExecutor-6195-thread-1-processing-n:127.0.0.1:52658__dy%2Fbb) [n:127.0.0.1:52658__dy%2Fbb c:control_collection x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/control-001/cores/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/control-001/cores/collection1/data/] [junit4] 2> 2702281 INFO (coreLoadExecutor-6195-thread-1-processing-n:127.0.0.1:52658__dy%2Fbb) [n:127.0.0.1:52658__dy%2Fbb c:control_collection x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4b2d3805 [junit4] 2> 2702283 INFO (coreLoadExecutor-6195-thread-1-processing-n:127.0.0.1:52658__dy%2Fbb) [n:127.0.0.1:52658__dy%2Fbb c:control_collection x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=43, maxMergeAtOnceExplicit=26, maxMergedSegmentMB=66.96875, floorSegmentMB=0.244140625, forceMergeDeletesPctAllowed=5.064414177834005, segmentsPerTier=41.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0 [junit4] 2> 2702309 WARN (coreLoadExecutor-6195-thread-1-processing-n:127.0.0.1:52658__dy%2Fbb) [n:127.0.0.1:52658__dy%2Fbb c:control_collection x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,attributes = {initParams=a, name=/dump, class=DumpRequestHandler},args = {defaults={a=A,b=B}}} [junit4] 2> 2702669 INFO (coreLoadExecutor-6195-thread-1-processing-n:127.0.0.1:52658__dy%2Fbb) [n:127.0.0.1:52658__dy%2Fbb c:control_collection x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 2702669 INFO (coreLoadExecutor-6195-thread-1-processing-n:127.0.0.1:52658__dy%2Fbb) [n:127.0.0.1:52658__dy%2Fbb c:control_collection x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 2702670 INFO (coreLoadExecutor-6195-thread-1-processing-n:127.0.0.1:52658__dy%2Fbb) [n:127.0.0.1:52658__dy%2Fbb c:control_collection x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 2702670 INFO (coreLoadExecutor-6195-thread-1-processing-n:127.0.0.1:52658__dy%2Fbb) [n:127.0.0.1:52658__dy%2Fbb c:control_collection x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 2702673 INFO (coreLoadExecutor-6195-thread-1-processing-n:127.0.0.1:52658__dy%2Fbb) [n:127.0.0.1:52658__dy%2Fbb c:control_collection x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=31, maxMergeAtOnceExplicit=18, maxMergedSegmentMB=1.6103515625, floorSegmentMB=1.2958984375, forceMergeDeletesPctAllowed=11.477088415895137, segmentsPerTier=25.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0 [junit4] 2> 2702675 INFO (coreLoadExecutor-6195-thread-1-processing-n:127.0.0.1:52658__dy%2Fbb) [n:127.0.0.1:52658__dy%2Fbb c:control_collection x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1d3680c3[collection1] main] [junit4] 2> 2702676 INFO (coreLoadExecutor-6195-thread-1-processing-n:127.0.0.1:52658__dy%2Fbb) [n:127.0.0.1:52658__dy%2Fbb c:control_collection x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 2702677 INFO (coreLoadExecutor-6195-thread-1-processing-n:127.0.0.1:52658__dy%2Fbb) [n:127.0.0.1:52658__dy%2Fbb c:control_collection x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 2702677 INFO (coreLoadExecutor-6195-thread-1-processing-n:127.0.0.1:52658__dy%2Fbb) [n:127.0.0.1:52658__dy%2Fbb c:control_collection x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 2702678 INFO (coreLoadExecutor-6195-thread-1-processing-n:127.0.0.1:52658__dy%2Fbb) [n:127.0.0.1:52658__dy%2Fbb c:control_collection x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1563859161238732800 [junit4] 2> 2702682 INFO (searcherExecutor-6196-thread-1-processing-n:127.0.0.1:52658__dy%2Fbb x:collection1 c:control_collection) [n:127.0.0.1:52658__dy%2Fbb c:control_collection x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@1d3680c3[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 2702690 INFO (coreZkRegister-6188-thread-1-processing-n:127.0.0.1:52658__dy%2Fbb x:collection1 c:control_collection) [n:127.0.0.1:52658__dy%2Fbb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 2702690 INFO (coreZkRegister-6188-thread-1-processing-n:127.0.0.1:52658__dy%2Fbb x:collection1 c:control_collection) [n:127.0.0.1:52658__dy%2Fbb 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> 2702690 INFO (coreZkRegister-6188-thread-1-processing-n:127.0.0.1:52658__dy%2Fbb x:collection1 c:control_collection) [n:127.0.0.1:52658__dy%2Fbb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:52658/_dy/bb/collection1/ [junit4] 2> 2702690 INFO (coreZkRegister-6188-thread-1-processing-n:127.0.0.1:52658__dy%2Fbb x:collection1 c:control_collection) [n:127.0.0.1:52658__dy%2Fbb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 2702690 INFO (coreZkRegister-6188-thread-1-processing-n:127.0.0.1:52658__dy%2Fbb x:collection1 c:control_collection) [n:127.0.0.1:52658__dy%2Fbb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy http://127.0.0.1:52658/_dy/bb/collection1/ has no replicas [junit4] 2> 2702690 INFO (coreZkRegister-6188-thread-1-processing-n:127.0.0.1:52658__dy%2Fbb x:collection1 c:control_collection) [n:127.0.0.1:52658__dy%2Fbb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 2702693 INFO (coreZkRegister-6188-thread-1-processing-n:127.0.0.1:52658__dy%2Fbb x:collection1 c:control_collection) [n:127.0.0.1:52658__dy%2Fbb 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:52658/_dy/bb/collection1/ shard1 [junit4] 2> 2702844 INFO (coreZkRegister-6188-thread-1-processing-n:127.0.0.1:52658__dy%2Fbb x:collection1 c:control_collection) [n:127.0.0.1:52658__dy%2Fbb c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 2703230 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 2703232 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:53068/solr ready [junit4] 2> 2703232 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.ChaosMonkey monkey: init - expire sessions:false cause connection loss:false [junit4] 2> 2703738 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/shard-1-001/cores/collection1 [junit4] 2> 2703738 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 1 in directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/shard-1-001 [junit4] 2> 2703739 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 2703771 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@54aec22{/_dy/bb,null,AVAILABLE} [junit4] 2> 2703771 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@59ef02cc{HTTP/1.1,[http/1.1]}{127.0.0.1:45351} [junit4] 2> 2703771 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.e.j.s.Server Started @2709732ms [junit4] 2> 2703771 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/tempDir-001/jetty1, solrconfig=solrconfig.xml, hostContext=/_dy/bb, hostPort=45351, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/../../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/shard-1-001/cores} [junit4] 2> 2703772 ERROR (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 2703778 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.5.0 [junit4] 2> 2703778 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2703778 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 2703778 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-04-05T17:11:57.650Z [junit4] 2> 2703973 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper) [junit4] 2> 2703973 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/shard-1-001/solr.xml [junit4] 2> 2703989 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 2704004 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:53068/solr [junit4] 2> 2704126 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [n:127.0.0.1:45351__dy%2Fbb ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 2704129 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [n:127.0.0.1:45351__dy%2Fbb ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 2704131 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [n:127.0.0.1:45351__dy%2Fbb ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45351__dy%2Fbb [junit4] 2> 2704136 INFO (zkCallback-2433-thread-1-processing-n:127.0.0.1:52658__dy%2Fbb) [n:127.0.0.1:52658__dy%2Fbb ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 2704172 INFO (zkCallback-2437-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 2704173 INFO (zkCallback-2442-thread-2-processing-n:127.0.0.1:45351__dy%2Fbb) [n:127.0.0.1:45351__dy%2Fbb ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 2704294 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [n:127.0.0.1:45351__dy%2Fbb ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/../../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/shard-1-001/cores [junit4] 2> 2704295 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [n:127.0.0.1:45351__dy%2Fbb ] o.a.s.c.CorePropertiesLocator Cores are: [collection1] [junit4] 2> 2704305 INFO (OverseerStateUpdate-97741197366591492-127.0.0.1:52658__dy%2Fbb-n_0000000000) [n:127.0.0.1:52658__dy%2Fbb ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2 [junit4] 2> 2705395 INFO (coreLoadExecutor-6206-thread-1-processing-n:127.0.0.1:45351__dy%2Fbb) [n:127.0.0.1:45351__dy%2Fbb c:collection1 x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0 [junit4] 2> 2705456 INFO (coreLoadExecutor-6206-thread-1-processing-n:127.0.0.1:45351__dy%2Fbb) [n:127.0.0.1:45351__dy%2Fbb c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 2705820 WARN (coreLoadExecutor-6206-thread-1-processing-n:127.0.0.1:45351__dy%2Fbb) [n:127.0.0.1:45351__dy%2Fbb c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead. [junit4] 2> 2705822 INFO (coreLoadExecutor-6206-thread-1-processing-n:127.0.0.1:45351__dy%2Fbb) [n:127.0.0.1:45351__dy%2Fbb c:collection1 x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id [junit4] 2> 2705868 INFO (coreLoadExecutor-6206-thread-1-processing-n:127.0.0.1:45351__dy%2Fbb) [n:127.0.0.1:45351__dy%2Fbb c:collection1 x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1 [junit4] 2> 2705868 INFO (coreLoadExecutor-6206-thread-1-processing-n:127.0.0.1:45351__dy%2Fbb) [n:127.0.0.1:45351__dy%2Fbb c:collection1 x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 2705869 INFO (coreLoadExecutor-6206-thread-1-processing-n:127.0.0.1:45351__dy%2Fbb) [n:127.0.0.1:45351__dy%2Fbb c:collection1 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/shard-1-001/cores/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/../../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/shard-1-001/cores/collection1/data/] [junit4] 2> 2705869 INFO (coreLoadExecutor-6206-thread-1-processing-n:127.0.0.1:45351__dy%2Fbb) [n:127.0.0.1:45351__dy%2Fbb c:collection1 x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4b2d3805 [junit4] 2> 2705873 INFO (coreLoadExecutor-6206-thread-1-processing-n:127.0.0.1:45351__dy%2Fbb) [n:127.0.0.1:45351__dy%2Fbb c:collection1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=43, maxMergeAtOnceExplicit=26, maxMergedSegmentMB=66.96875, floorSegmentMB=0.244140625, forceMergeDeletesPctAllowed=5.064414177834005, segmentsPerTier=41.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0 [junit4] 2> 2705896 WARN (coreLoadExecutor-6206-thread-1-processing-n:127.0.0.1:45351__dy%2Fbb) [n:127.0.0.1:45351__dy%2Fbb c:collection1 x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,attributes = {initParams=a, name=/dump, class=DumpRequestHandler},args = {defaults={a=A,b=B}}} [junit4] 2> 2706214 INFO (coreLoadExecutor-6206-thread-1-processing-n:127.0.0.1:45351__dy%2Fbb) [n:127.0.0.1:45351__dy%2Fbb c:collection1 x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 2706215 INFO (coreLoadExecutor-6206-thread-1-processing-n:127.0.0.1:45351__dy%2Fbb) [n:127.0.0.1:45351__dy%2Fbb c:collection1 x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 2706215 INFO (coreLoadExecutor-6206-thread-1-processing-n:127.0.0.1:45351__dy%2Fbb) [n:127.0.0.1:45351__dy%2Fbb c:collection1 x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 2706216 INFO (coreLoadExecutor-6206-thread-1-processing-n:127.0.0.1:45351__dy%2Fbb) [n:127.0.0.1:45351__dy%2Fbb c:collection1 x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 2706219 INFO (coreLoadExecutor-6206-thread-1-processing-n:127.0.0.1:45351__dy%2Fbb) [n:127.0.0.1:45351__dy%2Fbb c:collection1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=31, maxMergeAtOnceExplicit=18, maxMergedSegmentMB=1.6103515625, floorSegmentMB=1.2958984375, forceMergeDeletesPctAllowed=11.477088415895137, segmentsPerTier=25.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0 [junit4] 2> 2706220 INFO (coreLoadExecutor-6206-thread-1-processing-n:127.0.0.1:45351__dy%2Fbb) [n:127.0.0.1:45351__dy%2Fbb c:collection1 x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5b76e99b[collection1] main] [junit4] 2> 2706222 INFO (coreLoadExecutor-6206-thread-1-processing-n:127.0.0.1:45351__dy%2Fbb) [n:127.0.0.1:45351__dy%2Fbb c:collection1 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 2706223 INFO (coreLoadExecutor-6206-thread-1-processing-n:127.0.0.1:45351__dy%2Fbb) [n:127.0.0.1:45351__dy%2Fbb c:collection1 x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 2706223 INFO (coreLoadExecutor-6206-thread-1-processing-n:127.0.0.1:45351__dy%2Fbb) [n:127.0.0.1:45351__dy%2Fbb c:collection1 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 2706233 INFO (searcherExecutor-6207-thread-1-processing-n:127.0.0.1:45351__dy%2Fbb x:collection1 c:collection1) [n:127.0.0.1:45351__dy%2Fbb c:collection1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5b76e99b[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 2706233 INFO (coreLoadExecutor-6206-thread-1-processing-n:127.0.0.1:45351__dy%2Fbb) [n:127.0.0.1:45351__dy%2Fbb c:collection1 x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1563859164966420480 [junit4] 2> 2706240 INFO (coreZkRegister-6201-thread-1-processing-n:127.0.0.1:45351__dy%2Fbb x:collection1 c:collection1) [n:127.0.0.1:45351__dy%2Fbb c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 2706241 INFO (coreZkRegister-6201-thread-1-processing-n:127.0.0.1:45351__dy%2Fbb x:collection1 c:collection1) [n:127.0.0.1:45351__dy%2Fbb c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 2706241 INFO (coreZkRegister-6201-thread-1-processing-n:127.0.0.1:45351__dy%2Fbb x:collection1 c:collection1) [n:127.0.0.1:45351__dy%2Fbb c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:45351/_dy/bb/collection1/ [junit4] 2> 2706241 INFO (coreZkRegister-6201-thread-1-processing-n:127.0.0.1:45351__dy%2Fbb x:collection1 c:collection1) [n:127.0.0.1:45351__dy%2Fbb c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 2706241 INFO (coreZkRegister-6201-thread-1-processing-n:127.0.0.1:45351__dy%2Fbb x:collection1 c:collection1) [n:127.0.0.1:45351__dy%2Fbb c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.SyncStrategy http://127.0.0.1:45351/_dy/bb/collection1/ has no replicas [junit4] 2> 2706241 INFO (coreZkRegister-6201-thread-1-processing-n:127.0.0.1:45351__dy%2Fbb x:collection1 c:collection1) [n:127.0.0.1:45351__dy%2Fbb c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 2706253 INFO (coreZkRegister-6201-thread-1-processing-n:127.0.0.1:45351__dy%2Fbb x:collection1 c:collection1) [n:127.0.0.1:45351__dy%2Fbb c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:45351/_dy/bb/collection1/ shard2 [junit4] 2> 2706405 INFO (coreZkRegister-6201-thread-1-processing-n:127.0.0.1:45351__dy%2Fbb x:collection1 c:collection1) [n:127.0.0.1:45351__dy%2Fbb c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 2707225 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/shard-2-001/cores/collection1 [junit4] 2> 2707226 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 2 in directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/shard-2-001 [junit4] 2> 2707227 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 2707340 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@a83d108{/_dy/bb,null,AVAILABLE} [junit4] 2> 2707340 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@45206e70{HTTP/1.1,[http/1.1]}{127.0.0.1:48162} [junit4] 2> 2707340 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.e.j.s.Server Started @2713301ms [junit4] 2> 2707340 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/tempDir-001/jetty2, solrconfig=solrconfig.xml, hostContext=/_dy/bb, hostPort=48162, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/../../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/shard-2-001/cores} [junit4] 2> 2707340 ERROR (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 2707343 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.5.0 [junit4] 2> 2707343 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2707343 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 2707343 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-04-05T17:12:01.215Z [junit4] 2> 2707406 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper) [junit4] 2> 2707406 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/shard-2-001/solr.xml [junit4] 2> 2707435 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 2707452 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:53068/solr [junit4] 2> 2707660 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [n:127.0.0.1:48162__dy%2Fbb ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 2707663 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [n:127.0.0.1:48162__dy%2Fbb ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 2707669 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [n:127.0.0.1:48162__dy%2Fbb ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48162__dy%2Fbb [junit4] 2> 2707675 INFO (zkCallback-2437-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 2707675 INFO (zkCallback-2442-thread-2-processing-n:127.0.0.1:45351__dy%2Fbb) [n:127.0.0.1:45351__dy%2Fbb ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 2707677 INFO (zkCallback-2433-thread-2-processing-n:127.0.0.1:52658__dy%2Fbb) [n:127.0.0.1:52658__dy%2Fbb ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 2707699 INFO (zkCallback-2448-thread-1-processing-n:127.0.0.1:48162__dy%2Fbb) [n:127.0.0.1:48162__dy%2Fbb ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 2708080 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [n:127.0.0.1:48162__dy%2Fbb ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/../../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/shard-2-001/cores [junit4] 2> 2708080 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [n:127.0.0.1:48162__dy%2Fbb ] o.a.s.c.CorePropertiesLocator Cores are: [collection1] [junit4] 2> 2708109 INFO (OverseerStateUpdate-97741197366591492-127.0.0.1:52658__dy%2Fbb-n_0000000000) [n:127.0.0.1:52658__dy%2Fbb ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard3 [junit4] 2> 2708177 INFO (coreLoadExecutor-6217-thread-1-processing-n:127.0.0.1:48162__dy%2Fbb) [n:127.0.0.1:48162__dy%2Fbb c:collection1 x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0 [junit4] 2> 2708272 INFO (coreLoadExecutor-6217-thread-1-processing-n:127.0.0.1:48162__dy%2Fbb) [n:127.0.0.1:48162__dy%2Fbb c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 2708646 WARN (coreLoadExecutor-6217-thread-1-processing-n:127.0.0.1:48162__dy%2Fbb) [n:127.0.0.1:48162__dy%2Fbb c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead. [junit4] 2> 2708647 INFO (coreLoadExecutor-6217-thread-1-processing-n:127.0.0.1:48162__dy%2Fbb) [n:127.0.0.1:48162__dy%2Fbb c:collection1 x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id [junit4] 2> 2708769 INFO (coreLoadExecutor-6217-thread-1-processing-n:127.0.0.1:48162__dy%2Fbb) [n:127.0.0.1:48162__dy%2Fbb c:collection1 x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1 [junit4] 2> 2708770 INFO (coreLoadExecutor-6217-thread-1-processing-n:127.0.0.1:48162__dy%2Fbb) [n:127.0.0.1:48162__dy%2Fbb c:collection1 x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 2708770 INFO (coreLoadExecutor-6217-thread-1-processing-n:127.0.0.1:48162__dy%2Fbb) [n:127.0.0.1:48162__dy%2Fbb c:collection1 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/shard-2-001/cores/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/../../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/shard-2-001/cores/collection1/data/] [junit4] 2> 2708770 INFO (coreLoadExecutor-6217-thread-1-processing-n:127.0.0.1:48162__dy%2Fbb) [n:127.0.0.1:48162__dy%2Fbb c:collection1 x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4b2d3805 [junit4] 2> 2708774 INFO (coreLoadExecutor-6217-thread-1-processing-n:127.0.0.1:48162__dy%2Fbb) [n:127.0.0.1:48162__dy%2Fbb c:collection1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=43, maxMergeAtOnceExplicit=26, maxMergedSegmentMB=66.96875, floorSegmentMB=0.244140625, forceMergeDeletesPctAllowed=5.064414177834005, segmentsPerTier=41.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0 [junit4] 2> 2708808 WARN (coreLoadExecutor-6217-thread-1-processing-n:127.0.0.1:48162__dy%2Fbb) [n:127.0.0.1:48162__dy%2Fbb c:collection1 x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,attributes = {initParams=a, name=/dump, class=DumpRequestHandler},args = {defaults={a=A,b=B}}} [junit4] 2> 2708971 INFO (coreLoadExecutor-6217-thread-1-processing-n:127.0.0.1:48162__dy%2Fbb) [n:127.0.0.1:48162__dy%2Fbb c:collection1 x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 2708971 INFO (coreLoadExecutor-6217-thread-1-processing-n:127.0.0.1:48162__dy%2Fbb) [n:127.0.0.1:48162__dy%2Fbb c:collection1 x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 2708972 INFO (coreLoadExecutor-6217-thread-1-processing-n:127.0.0.1:48162__dy%2Fbb) [n:127.0.0.1:48162__dy%2Fbb c:collection1 x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 2708972 INFO (coreLoadExecutor-6217-thread-1-processing-n:127.0.0.1:48162__dy%2Fbb) [n:127.0.0.1:48162__dy%2Fbb c:collection1 x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 2708973 INFO (coreLoadExecutor-6217-thread-1-processing-n:127.0.0.1:48162__dy%2Fbb) [n:127.0.0.1:48162__dy%2Fbb c:collection1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=31, maxMergeAtOnceExplicit=18, maxMergedSegmentMB=1.6103515625, floorSegmentMB=1.2958984375, forceMergeDeletesPctAllowed=11.477088415895137, segmentsPerTier=25.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0 [junit4] 2> 2708974 INFO (coreLoadExecutor-6217-thread-1-processing-n:127.0.0.1:48162__dy%2Fbb) [n:127.0.0.1:48162__dy%2Fbb c:collection1 x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@387bcaab[collection1] main] [junit4] 2> 2708975 INFO (coreLoadExecutor-6217-thread-1-processing-n:127.0.0.1:48162__dy%2Fbb) [n:127.0.0.1:48162__dy%2Fbb c:collection1 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 2708976 INFO (coreLoadExecutor-6217-thread-1-processing-n:127.0.0.1:48162__dy%2Fbb) [n:127.0.0.1:48162__dy%2Fbb c:collection1 x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 2708976 INFO (coreLoadExecutor-6217-thread-1-processing-n:127.0.0.1:48162__dy%2Fbb) [n:127.0.0.1:48162__dy%2Fbb c:collection1 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 2708977 INFO (searcherExecutor-6218-thread-1-processing-n:127.0.0.1:48162__dy%2Fbb x:collection1 c:collection1) [n:127.0.0.1:48162__dy%2Fbb c:collection1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@387bcaab[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 2708987 INFO (coreLoadExecutor-6217-thread-1-processing-n:127.0.0.1:48162__dy%2Fbb) [n:127.0.0.1:48162__dy%2Fbb c:collection1 x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1563859167854198784 [junit4] 2> 2709194 INFO (coreZkRegister-6212-thread-1-processing-n:127.0.0.1:48162__dy%2Fbb x:collection1 c:collection1) [n:127.0.0.1:48162__dy%2Fbb c:collection1 s:shard3 r:core_node2 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 2709194 INFO (coreZkRegister-6212-thread-1-processing-n:127.0.0.1:48162__dy%2Fbb x:collection1 c:collection1) [n:127.0.0.1:48162__dy%2Fbb c:collection1 s:shard3 r:core_node2 x:collection1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 2709194 INFO (coreZkRegister-6212-thread-1-processing-n:127.0.0.1:48162__dy%2Fbb x:collection1 c:collection1) [n:127.0.0.1:48162__dy%2Fbb c:collection1 s:shard3 r:core_node2 x:collection1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:48162/_dy/bb/collection1/ [junit4] 2> 2709194 INFO (coreZkRegister-6212-thread-1-processing-n:127.0.0.1:48162__dy%2Fbb x:collection1 c:collection1) [n:127.0.0.1:48162__dy%2Fbb c:collection1 s:shard3 r:core_node2 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 2709194 INFO (coreZkRegister-6212-thread-1-processing-n:127.0.0.1:48162__dy%2Fbb x:collection1 c:collection1) [n:127.0.0.1:48162__dy%2Fbb c:collection1 s:shard3 r:core_node2 x:collection1] o.a.s.c.SyncStrategy http://127.0.0.1:48162/_dy/bb/collection1/ has no replicas [junit4] 2> 2709194 INFO (coreZkRegister-6212-thread-1-processing-n:127.0.0.1:48162__dy%2Fbb x:collection1 c:collection1) [n:127.0.0.1:48162__dy%2Fbb c:collection1 s:shard3 r:core_node2 x:collection1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 2709200 INFO (coreZkRegister-6212-thread-1-processing-n:127.0.0.1:48162__dy%2Fbb x:collection1 c:collection1) [n:127.0.0.1:48162__dy%2Fbb c:collection1 s:shard3 r:core_node2 x:collection1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:48162/_dy/bb/collection1/ shard3 [junit4] 2> 2709351 INFO (coreZkRegister-6212-thread-1-processing-n:127.0.0.1:48162__dy%2Fbb x:collection1 c:collection1) [n:127.0.0.1:48162__dy%2Fbb c:collection1 s:shard3 r:core_node2 x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 2709695 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/shard-3-001/cores/collection1 [junit4] 2> 2709696 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 3 in directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/shard-3-001 [junit4] 2> 2709697 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 2709698 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@4a5369b5{/_dy/bb,null,AVAILABLE} [junit4] 2> 2709698 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@2f7072ae{HTTP/1.1,[http/1.1]}{127.0.0.1:39588} [junit4] 2> 2709698 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.e.j.s.Server Started @2715659ms [junit4] 2> 2709698 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/tempDir-001/jetty3, solrconfig=solrconfig.xml, hostContext=/_dy/bb, hostPort=39588, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/shard-3-001/cores} [junit4] 2> 2709699 ERROR (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 2709709 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.5.0 [junit4] 2> 2709709 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2709709 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 2709709 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-04-05T17:12:03.581Z [junit4] 2> 2709766 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper) [junit4] 2> 2709766 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/shard-3-001/solr.xml [junit4] 2> 2709789 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 2709797 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:53068/solr [junit4] 2> 2709851 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [n:127.0.0.1:39588__dy%2Fbb ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3) [junit4] 2> 2709853 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [n:127.0.0.1:39588__dy%2Fbb ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 2709855 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [n:127.0.0.1:39588__dy%2Fbb ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39588__dy%2Fbb [junit4] 2> 2709858 INFO (zkCallback-2448-thread-1-processing-n:127.0.0.1:48162__dy%2Fbb) [n:127.0.0.1:48162__dy%2Fbb ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 2709864 INFO (zkCallback-2433-thread-2-processing-n:127.0.0.1:52658__dy%2Fbb) [n:127.0.0.1:52658__dy%2Fbb ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 2709865 INFO (zkCallback-2442-thread-2-processing-n:127.0.0.1:45351__dy%2Fbb) [n:127.0.0.1:45351__dy%2Fbb ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 2709865 INFO (zkCallback-2437-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 2709874 INFO (zkCallback-2454-thread-1-processing-n:127.0.0.1:39588__dy%2Fbb) [n:127.0.0.1:39588__dy%2Fbb ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 2710254 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [n:127.0.0.1:39588__dy%2Fbb ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/shard-3-001/cores [junit4] 2> 2710254 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [n:127.0.0.1:39588__dy%2Fbb ] o.a.s.c.CorePropertiesLocator Cores are: [collection1] [junit4] 2> 2710265 INFO (OverseerStateUpdate-97741197366591492-127.0.0.1:52658__dy%2Fbb-n_0000000000) [n:127.0.0.1:52658__dy%2Fbb ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1 [junit4] 2> 2711307 INFO (coreLoadExecutor-6228-thread-1-processing-n:127.0.0.1:39588__dy%2Fbb) [n:127.0.0.1:39588__dy%2Fbb c:collection1 x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0 [junit4] 2> 2711413 INFO (coreLoadExecutor-6228-thread-1-processing-n:127.0.0.1:39588__dy%2Fbb) [n:127.0.0.1:39588__dy%2Fbb c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 2711582 WARN (coreLoadExecutor-6228-thread-1-processing-n:127.0.0.1:39588__dy%2Fbb) [n:127.0.0.1:39588__dy%2Fbb c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead. [junit4] 2> 2711584 INFO (coreLoadExecutor-6228-thread-1-processing-n:127.0.0.1:39588__dy%2Fbb) [n:127.0.0.1:39588__dy%2Fbb c:collection1 x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id [junit4] 2> 2711653 INFO (coreLoadExecutor-6228-thread-1-processing-n:127.0.0.1:39588__dy%2Fbb) [n:127.0.0.1:39588__dy%2Fbb c:collection1 x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1 [junit4] 2> 2711656 INFO (coreLoadExecutor-6228-thread-1-processing-n:127.0.0.1:39588__dy%2Fbb) [n:127.0.0.1:39588__dy%2Fbb c:collection1 x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 2711656 INFO (coreLoadExecutor-6228-thread-1-processing-n:127.0.0.1:39588__dy%2Fbb) [n:127.0.0.1:39588__dy%2Fbb c:collection1 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/shard-3-001/cores/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/shard-3-001/cores/collection1/data/] [junit4] 2> 2711656 INFO (coreLoadExecutor-6228-thread-1-processing-n:127.0.0.1:39588__dy%2Fbb) [n:127.0.0.1:39588__dy%2Fbb c:collection1 x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4b2d3805 [junit4] 2> 2711669 INFO (coreLoadExecutor-6228-thread-1-processing-n:127.0.0.1:39588__dy%2Fbb) [n:127.0.0.1:39588__dy%2Fbb c:collection1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=43, maxMergeAtOnceExplicit=26, maxMergedSegmentMB=66.96875, floorSegmentMB=0.244140625, forceMergeDeletesPctAllowed=5.064414177834005, segmentsPerTier=41.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0 [junit4] 2> 2711700 WARN (coreLoadExecutor-6228-thread-1-processing-n:127.0.0.1:39588__dy%2Fbb) [n:127.0.0.1:39588__dy%2Fbb c:collection1 x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,attributes = {initParams=a, name=/dump, class=DumpRequestHandler},args = {defaults={a=A,b=B}}} [junit4] 2> 2711868 INFO (coreLoadExecutor-6228-thread-1-processing-n:127.0.0.1:39588__dy%2Fbb) [n:127.0.0.1:39588__dy%2Fbb c:collection1 x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 2711868 INFO (coreLoadExecutor-6228-thread-1-processing-n:127.0.0.1:39588__dy%2Fbb) [n:127.0.0.1:39588__dy%2Fbb c:collection1 x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 2711868 INFO (coreLoadExecutor-6228-thread-1-processing-n:127.0.0.1:39588__dy%2Fbb) [n:127.0.0.1:39588__dy%2Fbb c:collection1 x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 2711869 INFO (coreLoadExecutor-6228-thread-1-processing-n:127.0.0.1:39588__dy%2Fbb) [n:127.0.0.1:39588__dy%2Fbb c:collection1 x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 2711869 INFO (coreLoadExecutor-6228-thread-1-processing-n:127.0.0.1:39588__dy%2Fbb) [n:127.0.0.1:39588__dy%2Fbb c:collection1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=31, maxMergeAtOnceExplicit=18, maxMergedSegmentMB=1.6103515625, floorSegmentMB=1.2958984375, forceMergeDeletesPctAllowed=11.477088415895137, segmentsPerTier=25.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0 [junit4] 2> 2711870 INFO (coreLoadExecutor-6228-thread-1-processing-n:127.0.0.1:39588__dy%2Fbb) [n:127.0.0.1:39588__dy%2Fbb c:collection1 x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@2237574b[collection1] main] [junit4] 2> 2711871 INFO (coreLoadExecutor-6228-thread-1-processing-n:127.0.0.1:39588__dy%2Fbb) [n:127.0.0.1:39588__dy%2Fbb c:collection1 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 2711872 INFO (coreLoadExecutor-6228-thread-1-processing-n:127.0.0.1:39588__dy%2Fbb) [n:127.0.0.1:39588__dy%2Fbb c:collection1 x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 2711872 INFO (coreLoadExecutor-6228-thread-1-processing-n:127.0.0.1:39588__dy%2Fbb) [n:127.0.0.1:39588__dy%2Fbb c:collection1 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 2711873 INFO (coreLoadExecutor-6228-thread-1-processing-n:127.0.0.1:39588__dy%2Fbb) [n:127.0.0.1:39588__dy%2Fbb c:collection1 x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1563859170880389120 [junit4] 2> 2711887 INFO (searcherExecutor-6229-thread-1-processing-n:127.0.0.1:39588__dy%2Fbb x:collection1 c:collection1) [n:127.0.0.1:39588__dy%2Fbb c:collection1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@2237574b[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 2711936 INFO (coreZkRegister-6223-thread-1-processing-n:127.0.0.1:39588__dy%2Fbb x:collection1 c:collection1) [n:127.0.0.1:39588__dy%2Fbb c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 2711936 INFO (coreZkRegister-6223-thread-1-processing-n:127.0.0.1:39588__dy%2Fbb x:collection1 c:collection1) [n:127.0.0.1:39588__dy%2Fbb c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 2711936 INFO (coreZkRegister-6223-thread-1-processing-n:127.0.0.1:39588__dy%2Fbb x:collection1 c:collection1) [n:127.0.0.1:39588__dy%2Fbb c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:39588/_dy/bb/collection1/ [junit4] 2> 2711936 INFO (coreZkRegister-6223-thread-1-processing-n:127.0.0.1:39588__dy%2Fbb x:collection1 c:collection1) [n:127.0.0.1:39588__dy%2Fbb c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 2711936 INFO (coreZkRegister-6223-thread-1-processing-n:127.0.0.1:39588__dy%2Fbb x:collection1 c:collection1) [n:127.0.0.1:39588__dy%2Fbb c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.SyncStrategy http://127.0.0.1:39588/_dy/bb/collection1/ has no replicas [junit4] 2> 2711936 INFO (coreZkRegister-6223-thread-1-processing-n:127.0.0.1:39588__dy%2Fbb x:collection1 c:collection1) [n:127.0.0.1:39588__dy%2Fbb c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 2711961 INFO (coreZkRegister-6223-thread-1-processing-n:127.0.0.1:39588__dy%2Fbb x:collection1 c:collection1) [n:127.0.0.1:39588__dy%2Fbb c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:39588/_dy/bb/collection1/ shard1 [junit4] 2> 2712132 INFO (coreZkRegister-6223-thread-1-processing-n:127.0.0.1:39588__dy%2Fbb x:collection1 c:collection1) [n:127.0.0.1:39588__dy%2Fbb c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 2712615 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/shard-4-001/cores/collection1 [junit4] 2> 2712617 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 4 in directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/shard-4-001 [junit4] 2> 2712621 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 2712655 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6ad0c576{/_dy/bb,null,AVAILABLE} [junit4] 2> 2712656 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@100a384d{HTTP/1.1,[http/1.1]}{127.0.0.1:47187} [junit4] 2> 2712659 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.e.j.s.Server Started @2718619ms [junit4] 2> 2712659 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/tempDir-001/jetty4, solrconfig=solrconfig.xml, hostContext=/_dy/bb, hostPort=47187, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/../../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/shard-4-001/cores} [junit4] 2> 2712659 ERROR (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 2712665 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.5.0 [junit4] 2> 2712665 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2712665 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 2712665 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-04-05T17:12:06.537Z [junit4] 2> 2712696 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper) [junit4] 2> 2712696 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/shard-4-001/solr.xml [junit4] 2> 2712725 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 2712726 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:53068/solr [junit4] 2> 2712742 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [n:127.0.0.1:47187__dy%2Fbb ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 2712744 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [n:127.0.0.1:47187__dy%2Fbb ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 2712746 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [n:127.0.0.1:47187__dy%2Fbb ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:47187__dy%2Fbb [junit4] 2> 2712752 INFO (zkCallback-2448-thread-1-processing-n:127.0.0.1:48162__dy%2Fbb) [n:127.0.0.1:48162__dy%2Fbb ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 2712752 INFO (zkCallback-2437-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 2712752 INFO (zkCallback-2433-thread-2-processing-n:127.0.0.1:52658__dy%2Fbb) [n:127.0.0.1:52658__dy%2Fbb ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 2712754 INFO (zkCallback-2442-thread-2-processing-n:127.0.0.1:45351__dy%2Fbb) [n:127.0.0.1:45351__dy%2Fbb ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 2712754 INFO (zkCallback-2454-thread-1-processing-n:127.0.0.1:39588__dy%2Fbb) [n:127.0.0.1:39588__dy%2Fbb ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 2712788 INFO (zkCallback-2460-thread-1-processing-n:127.0.0.1:47187__dy%2Fbb) [n:127.0.0.1:47187__dy%2Fbb ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 2712864 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [n:127.0.0.1:47187__dy%2Fbb ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/../../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/shard-4-001/cores [junit4] 2> 2712864 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [n:127.0.0.1:47187__dy%2Fbb ] o.a.s.c.CorePropertiesLocator Cores are: [collection1] [junit4] 2> 2712866 INFO (OverseerStateUpdate-97741197366591492-127.0.0.1:52658__dy%2Fbb-n_0000000000) [n:127.0.0.1:52658__dy%2Fbb ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2 [junit4] 2> 2713917 INFO (coreLoadExecutor-6239-thread-1-processing-n:127.0.0.1:47187__dy%2Fbb) [n:127.0.0.1:47187__dy%2Fbb c:collection1 x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0 [junit4] 2> 2713938 INFO (coreLoadExecutor-6239-thread-1-processing-n:127.0.0.1:47187__dy%2Fbb) [n:127.0.0.1:47187__dy%2Fbb c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 2714118 WARN (coreLoadExecutor-6239-thread-1-processing-n:127.0.0.1:47187__dy%2Fbb) [n:127.0.0.1:47187__dy%2Fbb c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead. [junit4] 2> 2714139 INFO (coreLoadExecutor-6239-thread-1-processing-n:127.0.0.1:47187__dy%2Fbb) [n:127.0.0.1:47187__dy%2Fbb c:collection1 x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id [junit4] 2> 2714209 INFO (coreLoadExecutor-6239-thread-1-processing-n:127.0.0.1:47187__dy%2Fbb) [n:127.0.0.1:47187__dy%2Fbb c:collection1 x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1 [junit4] 2> 2714210 INFO (coreLoadExecutor-6239-thread-1-processing-n:127.0.0.1:47187__dy%2Fbb) [n:127.0.0.1:47187__dy%2Fbb c:collection1 x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 2714210 INFO (coreLoadExecutor-6239-thread-1-processing-n:127.0.0.1:47187__dy%2Fbb) [n:127.0.0.1:47187__dy%2Fbb c:collection1 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/shard-4-001/cores/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/../../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/shard-4-001/cores/collection1/data/] [junit4] 2> 2714210 INFO (coreLoadExecutor-6239-thread-1-processing-n:127.0.0.1:47187__dy%2Fbb) [n:127.0.0.1:47187__dy%2Fbb c:collection1 x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4b2d3805 [junit4] 2> 2714213 INFO (coreLoadExecutor-6239-thread-1-processing-n:127.0.0.1:47187__dy%2Fbb) [n:127.0.0.1:47187__dy%2Fbb c:collection1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=43, maxMergeAtOnceExplicit=26, maxMergedSegmentMB=66.96875, floorSegmentMB=0.244140625, forceMergeDeletesPctAllowed=5.064414177834005, segmentsPerTier=41.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0 [junit4] 2> 2714257 WARN (coreLoadExecutor-6239-thread-1-processing-n:127.0.0.1:47187__dy%2Fbb) [n:127.0.0.1:47187__dy%2Fbb c:collection1 x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,attributes = {initParams=a, name=/dump, class=DumpRequestHandler},args = {defaults={a=A,b=B}}} [junit4] 2> 2714383 INFO (coreLoadExecutor-6239-thread-1-processing-n:127.0.0.1:47187__dy%2Fbb) [n:127.0.0.1:47187__dy%2Fbb c:collection1 x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 2714383 INFO (coreLoadExecutor-6239-thread-1-processing-n:127.0.0.1:47187__dy%2Fbb) [n:127.0.0.1:47187__dy%2Fbb c:collection1 x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 2714384 INFO (coreLoadExecutor-6239-thread-1-processing-n:127.0.0.1:47187__dy%2Fbb) [n:127.0.0.1:47187__dy%2Fbb c:collection1 x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 2714384 INFO (coreLoadExecutor-6239-thread-1-processing-n:127.0.0.1:47187__dy%2Fbb) [n:127.0.0.1:47187__dy%2Fbb c:collection1 x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 2714385 INFO (coreLoadExecutor-6239-thread-1-processing-n:127.0.0.1:47187__dy%2Fbb) [n:127.0.0.1:47187__dy%2Fbb c:collection1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=31, maxMergeAtOnceExplicit=18, maxMergedSegmentMB=1.6103515625, floorSegmentMB=1.2958984375, forceMergeDeletesPctAllowed=11.477088415895137, segmentsPerTier=25.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0 [junit4] 2> 2714386 INFO (coreLoadExecutor-6239-thread-1-processing-n:127.0.0.1:47187__dy%2Fbb) [n:127.0.0.1:47187__dy%2Fbb c:collection1 x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@2a7aff6d[collection1] main] [junit4] 2> 2714390 INFO (coreLoadExecutor-6239-thread-1-processing-n:127.0.0.1:47187__dy%2Fbb) [n:127.0.0.1:47187__dy%2Fbb c:collection1 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 2714392 INFO (coreLoadExecutor-6239-thread-1-processing-n:127.0.0.1:47187__dy%2Fbb) [n:127.0.0.1:47187__dy%2Fbb c:collection1 x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 2714392 INFO (coreLoadExecutor-6239-thread-1-processing-n:127.0.0.1:47187__dy%2Fbb) [n:127.0.0.1:47187__dy%2Fbb c:collection1 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 2714393 INFO (coreLoadExecutor-6239-thread-1-processing-n:127.0.0.1:47187__dy%2Fbb) [n:127.0.0.1:47187__dy%2Fbb c:collection1 x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1563859173522800640 [junit4] 2> 2714396 INFO (searcherExecutor-6240-thread-1-processing-n:127.0.0.1:47187__dy%2Fbb x:collection1 c:collection1) [n:127.0.0.1:47187__dy%2Fbb c:collection1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@2a7aff6d[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 2714403 INFO (coreZkRegister-6234-thread-1-processing-n:127.0.0.1:47187__dy%2Fbb x:collection1 c:collection1) [n:127.0.0.1:47187__dy%2Fbb c:collection1 s:shard2 r:core_node4 x:collection1] o.a.s.c.ZkController Core needs to recover:collection1 [junit4] 2> 2714419 INFO (updateExecutor-2457-thread-1-processing-n:127.0.0.1:47187__dy%2Fbb x:collection1 s:shard2 c:collection1 r:core_node4) [n:127.0.0.1:47187__dy%2Fbb c:collection1 s:shard2 r:core_node4 x:collection1] o.a.s.u.DefaultSolrCoreState Running recovery [junit4] 2> 2714455 INFO (recoveryExecutor-2458-thread-1-processing-n:127.0.0.1:47187__dy%2Fbb x:collection1 s:shard2 c:collection1 r:core_node4) [n:127.0.0.1:47187__dy%2Fbb c:collection1 s:shard2 r:core_node4 x:collection1] o.a.s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=true [junit4] 2> 2714474 INFO (recoveryExecutor-2458-thread-1-processing-n:127.0.0.1:47187__dy%2Fbb x:collection1 s:shard2 c:collection1 r:core_node4) [n:127.0.0.1:47187__dy%2Fbb c:collection1 s:shard2 r:core_node4 x:collection1] o.a.s.c.RecoveryStrategy ###### startupVersions=[[]] [junit4] 2> 2714474 INFO (recoveryExecutor-2458-thread-1-processing-n:127.0.0.1:47187__dy%2Fbb x:collection1 s:shard2 c:collection1 r:core_node4) [n:127.0.0.1:47187__dy%2Fbb c:collection1 s:shard2 r:core_node4 x:collection1] o.a.s.c.RecoveryStrategy Begin buffering updates. core=[collection1] [junit4] 2> 2714474 INFO (recoveryExecutor-2458-thread-1-processing-n:127.0.0.1:47187__dy%2Fbb x:collection1 s:shard2 c:collection1 r:core_node4) [n:127.0.0.1:47187__dy%2Fbb c:collection1 s:shard2 r:core_node4 x:collection1] o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null} [junit4] 2> 2714474 INFO (recoveryExecutor-2458-thread-1-processing-n:127.0.0.1:47187__dy%2Fbb x:collection1 s:shard2 c:collection1 r:core_node4) [n:127.0.0.1:47187__dy%2Fbb c:collection1 s:shard2 r:core_node4 x:collection1] o.a.s.c.RecoveryStrategy Publishing state of core [collection1] as recovering, leader is [http://127.0.0.1:45351/_dy/bb/collection1/] and I am [http://127.0.0.1:47187/_dy/bb/collection1/] [junit4] 2> 2714487 INFO (recoveryExecutor-2458-thread-1-processing-n:127.0.0.1:47187__dy%2Fbb x:collection1 s:shard2 c:collection1 r:core_node4) [n:127.0.0.1:47187__dy%2Fbb c:collection1 s:shard2 r:core_node4 x:collection1] o.a.s.c.RecoveryStrategy Sending prep recovery command to [http://127.0.0.1:45351/_dy/bb]; [WaitForState: action=PREPRECOVERY&core=collection1&nodeName=127.0.0.1:47187__dy%252Fbb&coreNodeName=core_node4&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true] [junit4] 2> 2714814 INFO (qtp161281286-20314) [n:127.0.0.1:45351__dy%2Fbb ] o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node4, state: recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true [junit4] 2> 2714814 INFO (qtp161281286-20314) [n:127.0.0.1:45351__dy%2Fbb ] o.a.s.h.a.PrepRecoveryOp Will wait a max of 183 seconds to see collection1 (shard2 of collection1) have state: recovering [junit4] 2> 2714814 INFO (qtp161281286-20314) [n:127.0.0.1:45351__dy%2Fbb ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=collection1, shard=shard2, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=recovering, localState=active, nodeName=127.0.0.1:47187__dy%2Fbb, coreNodeName=core_node4, onlyIfActiveCheckResult=false, nodeProps: core_node4:{"core":"collection1","base_url":"http://127.0.0.1:47187/_dy/bb","node_name":"127.0.0.1:47187__dy%2Fbb","state":"recovering"} [junit4] 2> 2714815 INFO (qtp161281286-20314) [n:127.0.0.1:45351__dy%2Fbb ] o.a.s.h.a.PrepRecoveryOp Waited coreNodeName: core_node4, state: recovering, checkLive: true, onlyIfLeader: true for: 0 seconds. [junit4] 2> 2714815 INFO (qtp161281286-20314) [n:127.0.0.1:45351__dy%2Fbb ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={nodeName=127.0.0.1:47187__dy%252Fbb&onlyIfLeaderActive=true&core=collection1&coreNodeName=core_node4&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2} status=0 QTime=1 [junit4] 2> 2715237 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A-001/shard-5-001/cores/collection1 [junit4] 2> 2715248 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[4BBDDB607670A81A]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 5 in directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.FullSolrCloudDistribCmdsTest_4BBDDB607670A81A- [...truncated too long message...] ateRequestProcessorFactoryTest, TestNumericTerms32, PeerSyncReplicationTest, DateMathParserTest, TestLocalFSCloudBackupRestore, TestManagedSynonymFilterFactory, TestSolrIndexConfig, TestSolrQueryResponse, TestFastOutputStream, TestCursorMarkWithoutUniqueKey, TlogReplayBufferedWhileIndexingTest, SimplePostToolTest, TestConfigSetProperties, TestClusterStateMutator, TestSystemCollAutoCreate, ConnectionManagerTest, TestInfoStreamLogging, TestStandardQParsers, SliceStateTest, TestFieldCacheVsDocValues, SearchHandlerTest, TestBinaryResponseWriter, TestFieldCacheSanityChecker, DistributedFacetPivotWhiteBoxTest, DistribCursorPagingTest, TestRuleBasedAuthorizationPlugin, RollingRestartTest, DistributedIntervalFacetingTest, BasicDistributedZkTest, CollectionsAPIDistributedZkTest, SyncSliceTest, LeaderElectionIntegrationTest, ShardRoutingTest, FullSolrCloudDistribCmdsTest] [junit4] Completed [498/701 (1!)] on J1 in 1428.54s, 1 test, 1 error <<< FAILURES! [...truncated 620 lines...] [junit4] Suite: org.apache.solr.store.blockcache.BlockDirectoryTest [junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J2/temp/solr.store.blockcache.BlockDirectoryTest_4BBDDB607670A81A-001/init-core-data-001 [junit4] 2> 5964743 WARN (SUITE-BlockDirectoryTest-seed#[4BBDDB607670A81A]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=1 numCloses=1 [junit4] 2> 5964743 INFO (SUITE-BlockDirectoryTest-seed#[4BBDDB607670A81A]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields [junit4] 2> 5964745 INFO (SUITE-BlockDirectoryTest-seed#[4BBDDB607670A81A]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN) [junit4] 2> 5964750 INFO (TEST-BlockDirectoryTest.testRandomAccessWrites-seed#[4BBDDB607670A81A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testRandomAccessWrites [junit4] 1> Total time is 9214ms [junit4] 2> 5973965 INFO (TEST-BlockDirectoryTest.testRandomAccessWrites-seed#[4BBDDB607670A81A]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testRandomAccessWrites [junit4] 2> 5973970 INFO (TEST-BlockDirectoryTest.ensureCacheConfigurable-seed#[4BBDDB607670A81A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting ensureCacheConfigurable [junit4] 2> 5975756 INFO (TEST-BlockDirectoryTest.ensureCacheConfigurable-seed#[4BBDDB607670A81A]) [ ] o.a.s.SolrTestCaseJ4 ###Ending ensureCacheConfigurable [junit4] 2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory. [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=BlockDirectoryTest -Dtests.method=ensureCacheConfigurable -Dtests.seed=4BBDDB607670A81A -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/test-data/enwiki.random.lines.txt -Dtests.locale=ar-BH -Dtests.timezone=Europe/Zagreb -Dtests.asserts=true -Dtests.file.encoding=UTF-8 [junit4] ERROR 1.79s J2 | BlockDirectoryTest.ensureCacheConfigurable <<< [junit4] > Throwable #1: java.lang.OutOfMemoryError: Direct buffer memory [junit4] > at java.nio.Bits.reserveMemory(Bits.java:693) [junit4] > at java.nio.DirectByteBuffer.<init>(DirectByteBuffer.java:123) [junit4] > at java.nio.ByteBuffer.allocateDirect(ByteBuffer.java:311) [junit4] > at org.apache.solr.store.blockcache.BlockCache.<init>(BlockCache.java:75) [junit4] > at org.apache.solr.store.blockcache.BlockDirectoryTest.setUp(BlockDirectoryTest.java:119) [junit4] > at java.lang.Thread.run(Thread.java:745)Throwable #2: java.lang.NullPointerException [junit4] > at org.apache.solr.store.blockcache.BlockDirectoryTest.tearDown(BlockDirectoryTest.java:131) [junit4] > at java.lang.Thread.run(Thread.java:745) [junit4] 2> 5975762 INFO (TEST-BlockDirectoryTest.testRandomAccessWritesLargeCache-seed#[4BBDDB607670A81A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testRandomAccessWritesLargeCache [junit4] 2> 5976641 INFO (TEST-BlockDirectoryTest.testRandomAccessWritesLargeCache-seed#[4BBDDB607670A81A]) [ ] o.a.s.s.b.BlockDirectory Block cache on write is disabled [junit4] 1> Total time is 2016ms [junit4] 2> 5978658 INFO (TEST-BlockDirectoryTest.testRandomAccessWritesLargeCache-seed#[4BBDDB607670A81A]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testRandomAccessWritesLargeCache [junit4] 2> 5978669 INFO (TEST-BlockDirectoryTest.testEOF-seed#[4BBDDB607670A81A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testEOF [junit4] 2> 5978701 INFO (TEST-BlockDirectoryTest.testEOF-seed#[4BBDDB607670A81A]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testEOF [junit4] 2> 5978702 INFO (SUITE-BlockDirectoryTest-seed#[4BBDDB607670A81A]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore [junit4] 2> NOTE: leaving temporary files on disk at: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.5/checkout/solr/build/solr-core/test/J2/temp/solr.store.blockcache.BlockDirectoryTest_4BBDDB607670A81A-001 [junit4] 2> NOTE: test params are: codec=CheapBastard, sim=RandomSimilarity(queryNorm=false,coord=crazy): {}, locale=ar-BH, timezone=Europe/Zagreb [junit4] 2> NOTE: Linux 3.13.0-85-generic amd64/Oracle Corporation 1.8.0_121 (64-bit)/cpus=4,threads=1,free=326343704,total=534773760 [junit4] 2> NOTE: All tests run in this JVM: [RecoveryZkTest, CoreSorterTest, HdfsWriteToMultipleCollectionsTest, SuggesterTest, BasicAuthIntegrationTest, HighlighterMaxOffsetTest, HdfsRecoveryZkTest, WrapperMergePolicyFactoryTest, TestTolerantSearch, PrimUtilsTest, DocExpirationUpdateProcessorFactoryTest, TestConfigSetsAPIExclusivity, TestRTimerTree, TestFileDictionaryLookup, TestDFRSimilarityFactory, TestIndexSearcher, TestApiFramework, UtilsToolTest, TestReversedWildcardFilterFactory, ConcurrentDeleteAndCreateCollectionTest, HdfsDirectoryTest, TestRequestForwarding, TestCoreAdminApis, DistanceUnitsTest, TestRecoveryHdfs, DirectUpdateHandlerTest, TestCopyFieldCollectionResource, TestNamedUpdateProcessors, LeaderElectionTest, HdfsCollectionsAPIDistributedZkTest, BlockCacheTest, JSONWriterTest, QueryParsingTest, TestStressUserVersions, TestJmxMonitoredMap, TestIntervalFaceting, TestCollationField, SecurityConfHandlerTest, TestInPlaceUpdatesStandalone, AddSchemaFieldsUpdateProcessorFactoryTest, TestDistributedMissingSort, TestSort, TestReload, JSONWriterTest, TestSolrConfigHandlerCloud, BasicDistributedZk2Test, OpenExchangeRatesOrgProviderTest, CoreAdminHandlerTest, CloudExitableDirectoryReaderTest, TestDeleteCollectionOnDownNodes, OverseerTest, TestUniqueKeyFieldResource, DOMUtilTest, BJQParserTest, TestExactSharedStatsCache, TestStressCloudBlindAtomicUpdates, TestManagedSchemaAPI, TestXmlQParserPlugin, TestXIncludeConfig, TestExceedMaxTermLength, UpdateParamsTest, TestFieldTypeCollectionResource, TestCloudSchemaless, CircularListTest, FacetPivotSmallTest, DistribDocExpirationUpdateProcessorTest, ShufflingReplicaListTransformerTest, MigrateRouteKeyTest, TestDynamicLoading, TestSolrXml, ResponseLogComponentTest, TestExclusionRuleCollectionAccess, TestEmbeddedSolrServerSchemaAPI, SolrMetricReporterTest, SpellPossibilityIteratorTest, OverseerCollectionConfigSetProcessorTest, HdfsDirectoryFactoryTest, TestWriterPerf, TestCustomSort, TestGraphTermsQParserPlugin, TestSubQueryTransformerDistrib, TestTolerantUpdateProcessorCloud, DistributedQueryComponentCustomSortTest, TestLFUCache, TestGroupingSearch, BlockJoinFacetSimpleTest, HLLSerializationTest, PreAnalyzedUpdateProcessorTest, TestLeaderElectionZkExpiry, LeaderFailureAfterFreshStartTest, SuggestComponentTest, TestRecovery, TimeZoneUtilsTest, DistributedFacetExistsSmallTest, ClassificationUpdateProcessorIntegrationTest, TestFieldCacheSort, StatelessScriptUpdateProcessorFactoryTest, RecoveryAfterSoftCommitTest, SuggesterTSTTest, ActionThrottleTest, TestIndexingPerformance, TestZkChroot, TestSha256AuthenticationProvider, TestFieldCacheWithThreads, UnloadDistributedZkTest, FieldMutatingUpdateProcessorTest, PluginInfoTest, BadCopyFieldTest, TestAnalyzedSuggestions, RuleEngineTest, ManagedSchemaRoundRobinCloudTest, SolrTestCaseJ4Test, RankQueryTest, OpenCloseCoreStressTest, TestReplicationHandler, CurrencyFieldXmlFileTest, SolrIndexSplitterTest, AnalysisAfterCoreReloadTest, TestExtendedDismaxParser, SuggesterFSTTest, SpatialFilterTest, TestCSVLoader, NoCacheHeaderTest, TestPseudoReturnFields, DirectUpdateHandlerOptimizeTest, SortByFunctionTest, DocValuesMultiTest, DebugComponentTest, StandardRequestHandlerTest, DirectSolrSpellCheckerTest, DocumentAnalysisRequestHandlerTest, TestOmitPositions, RequestHandlersTest, MoreLikeThisHandlerTest, FieldAnalysisRequestHandlerTest, IndexSchemaRuntimeFieldTest, SolrPluginUtilsTest, TestJmxIntegration, TestCSVResponseWriter, BinaryUpdateRequestHandlerTest, PingRequestHandlerTest, TestMergePolicyConfig, TestSolrDeletionPolicy2, SampleTest, TestBinaryField, TestSearchPerf, MinimalSchemaTest, TestConfig, TestFuzzyAnalyzedSuggestions, TestPostingsSolrHighlighter, NotRequiredUniqueKeyTest, TestPhraseSuggestions, SynonymTokenizerTest, EchoParamsTest, TestSweetSpotSimilarityFactory, TestLMJelinekMercerSimilarityFactory, ResourceLoaderTest, ChaosMonkeyNothingIsSafeTest, CdcrReplicationDistributedZkTest, CdcrReplicationHandlerTest, CleanupOldIndexTest, CollectionsAPISolrJTest, DeleteNodeTest, DeleteShardTest, DistributedVersionInfoTest, LeaderElectionContextKeyTest, LeaderFailoverAfterPartitionTest, LeaderInitiatedRecoveryOnCommitTest, LeaderInitiatedRecoveryOnShardRestartTest, MissingSegmentRecoveryTest, OverseerRolesTest, ReplicationFactorTest, ShardSplitTest, TriLevelCompositeIdRoutingTest, HdfsBasicDistributedZkTest, TestFreeTextSuggestions, BlockDirectoryTest] [junit4] Completed [683/701 (2!)] on J2 in 13.98s, 4 tests, 1 error <<< FAILURES! [...truncated 62742 lines...]
--------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
