You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2017/11/10 02:59:08 UTC
[JENKINS] Lucene-Solr-7.x-Solaris (64bit/jdk1.8.0) - Build # 293 -
Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Solaris/293/
Java: 64bit/jdk1.8.0 -XX:+UseCompressedOops -XX:+UseG1GC
2 tests failed.
FAILED: junit.framework.TestSuite.org.apache.solr.handler.TestReplicationHandler
Error Message:
ObjectTracker found 4 object(s) that were not released!!! [MockDirectoryWrapper, MockDirectoryWrapper, InternalHttpClient, SolrCore] org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.lucene.store.MockDirectoryWrapper at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:348) at org.apache.solr.update.SolrIndexWriter.create(SolrIndexWriter.java:92) at org.apache.solr.core.SolrCore.initIndex(SolrCore.java:742) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:935) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:844) at org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1037) at org.apache.solr.core.CoreContainer.lambda$load$13(CoreContainer.java:642) at com.codahale.metrics.InstrumentedExecutorService$InstrumentedCallable.call(InstrumentedExecutorService.java:197) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.lucene.store.MockDirectoryWrapper at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:348) at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:501) at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:345) at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:421) at org.apache.solr.handler.ReplicationHandler.lambda$setupPolling$12(ReplicationHandler.java:1183) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.http.impl.client.InternalHttpClient at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.client.solrj.impl.HttpClientUtil.createClient(HttpClientUtil.java:289) at org.apache.solr.client.solrj.impl.HttpClientUtil.createClient(HttpClientUtil.java:298) at org.apache.solr.handler.IndexFetcher.createHttpClient(IndexFetcher.java:224) at org.apache.solr.handler.IndexFetcher.<init>(IndexFetcher.java:266) at org.apache.solr.handler.ReplicationHandler.inform(ReplicationHandler.java:1214) at org.apache.solr.core.SolrResourceLoader.inform(SolrResourceLoader.java:696) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:968) at org.apache.solr.core.SolrCore.reload(SolrCore.java:637) at org.apache.solr.core.CoreContainer.reload(CoreContainer.java:1285) at org.apache.solr.handler.IndexFetcher.lambda$reloadCore$0(IndexFetcher.java:917) at java.lang.Thread.run(Thread.java:748) org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.solr.core.SolrCore at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:1020) at org.apache.solr.core.SolrCore.reload(SolrCore.java:637) at org.apache.solr.core.CoreContainer.reload(CoreContainer.java:1285) at org.apache.solr.handler.IndexFetcher.lambda$reloadCore$0(IndexFetcher.java:917) at java.lang.Thread.run(Thread.java:748)
Stack Trace:
java.lang.AssertionError: ObjectTracker found 4 object(s) that were not released!!! [MockDirectoryWrapper, MockDirectoryWrapper, InternalHttpClient, SolrCore]
org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.lucene.store.MockDirectoryWrapper
at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42)
at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:348)
at org.apache.solr.update.SolrIndexWriter.create(SolrIndexWriter.java:92)
at org.apache.solr.core.SolrCore.initIndex(SolrCore.java:742)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:935)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:844)
at org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1037)
at org.apache.solr.core.CoreContainer.lambda$load$13(CoreContainer.java:642)
at com.codahale.metrics.InstrumentedExecutorService$InstrumentedCallable.call(InstrumentedExecutorService.java:197)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.lucene.store.MockDirectoryWrapper
at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42)
at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:348)
at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:501)
at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:345)
at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:421)
at org.apache.solr.handler.ReplicationHandler.lambda$setupPolling$12(ReplicationHandler.java:1183)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.http.impl.client.InternalHttpClient
at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42)
at org.apache.solr.client.solrj.impl.HttpClientUtil.createClient(HttpClientUtil.java:289)
at org.apache.solr.client.solrj.impl.HttpClientUtil.createClient(HttpClientUtil.java:298)
at org.apache.solr.handler.IndexFetcher.createHttpClient(IndexFetcher.java:224)
at org.apache.solr.handler.IndexFetcher.<init>(IndexFetcher.java:266)
at org.apache.solr.handler.ReplicationHandler.inform(ReplicationHandler.java:1214)
at org.apache.solr.core.SolrResourceLoader.inform(SolrResourceLoader.java:696)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:968)
at org.apache.solr.core.SolrCore.reload(SolrCore.java:637)
at org.apache.solr.core.CoreContainer.reload(CoreContainer.java:1285)
at org.apache.solr.handler.IndexFetcher.lambda$reloadCore$0(IndexFetcher.java:917)
at java.lang.Thread.run(Thread.java:748)
org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.solr.core.SolrCore
at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:1020)
at org.apache.solr.core.SolrCore.reload(SolrCore.java:637)
at org.apache.solr.core.CoreContainer.reload(CoreContainer.java:1285)
at org.apache.solr.handler.IndexFetcher.lambda$reloadCore$0(IndexFetcher.java:917)
at java.lang.Thread.run(Thread.java:748)
at __randomizedtesting.SeedInfo.seed([5697B516B50D3C9B]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.junit.Assert.assertNull(Assert.java:551)
at org.apache.solr.SolrTestCaseJ4.teardownTestCases(SolrTestCaseJ4.java:298)
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:1737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:897)
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:748)
FAILED: org.apache.solr.client.solrj.impl.CloudSolrClientTest.testRetryUpdatesWhenClusterStateIsStale
Error Message:
Error from server at http://127.0.0.1:57440/solr/stale_state_test_col_shard1_replica_n1: Expected mime type application/octet-stream but got text/html. <html> <head> <meta http-equiv="Content-Type" content="text/html;charset=ISO-8859-1"/> <title>Error 404 </title> </head> <body> <h2>HTTP ERROR: 404</h2> <p>Problem accessing /solr/stale_state_test_col_shard1_replica_n1/update. Reason: <pre> Can not find: /solr/stale_state_test_col_shard1_replica_n1/update</pre></p> <hr /><a href="http://eclipse.org/jetty">Powered by Jetty:// 9.3.20.v20170531</a><hr/> </body> </html>
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:57440/solr/stale_state_test_col_shard1_replica_n1: Expected mime type application/octet-stream but got text/html. <html>
<head>
<meta http-equiv="Content-Type" content="text/html;charset=ISO-8859-1"/>
<title>Error 404 </title>
</head>
<body>
<h2>HTTP ERROR: 404</h2>
<p>Problem accessing /solr/stale_state_test_col_shard1_replica_n1/update. Reason:
<pre> Can not find: /solr/stale_state_test_col_shard1_replica_n1/update</pre></p>
<hr /><a href="http://eclipse.org/jetty">Powered by Jetty:// 9.3.20.v20170531</a><hr/>
</body>
</html>
at __randomizedtesting.SeedInfo.seed([C663787755F7412D:7252E09FB61E3701]:0)
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:607)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:255)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:244)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:483)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:413)
at org.apache.solr.client.solrj.impl.CloudSolrClient.directUpdate(CloudSolrClient.java:559)
at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1016)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:883)
at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:816)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:194)
at org.apache.solr.client.solrj.request.UpdateRequest.commit(UpdateRequest.java:233)
at org.apache.solr.client.solrj.impl.CloudSolrClientTest.testRetryUpdatesWhenClusterStateIsStale(CloudSolrClientTest.java:844)
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:1737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at org.junit.rules.ExpectedException$ExpectedExceptionStatement.evaluate(ExpectedException.java:110)
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:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
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:748)
Build Log:
[...truncated 11545 lines...]
[junit4] Suite: org.apache.solr.handler.TestReplicationHandler
[junit4] 2> 67237 INFO (SUITE-TestReplicationHandler-seed#[5697B516B50D3C9B]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir: /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_5697B516B50D3C9B-001/init-core-data-001
[junit4] 2> 67238 WARN (SUITE-TestReplicationHandler-seed#[5697B516B50D3C9B]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=11 numCloses=11
[junit4] 2> 67238 INFO (SUITE-TestReplicationHandler-seed#[5697B516B50D3C9B]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 67239 INFO (SUITE-TestReplicationHandler-seed#[5697B516B50D3C9B]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl=None)
[junit4] 2> 67241 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testEmptyCommits
[junit4] 2> 67241 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_5697B516B50D3C9B-001/solr-instance-001/collection1
[junit4] 2> 67245 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 67246 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@e66787a{/solr,null,AVAILABLE}
[junit4] 2> 67247 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@27225bf2{HTTP/1.1,[http/1.1]}{127.0.0.1:๖๑๓๒๖}
[junit4] 2> 67247 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.e.j.s.Server Started @๖๙๔๙๔ms
[junit4] 2> 67247 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_5697B516B50D3C9B-001/solr-instance-001/collection1/data, hostContext=/solr, hostPort=61326}
[junit4] 2> 67248 ERROR (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 67248 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.2.0
[junit4] 2> 67248 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 67248 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 67248 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-11-10T01:15:21.565Z
[junit4] 2> 67248 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_5697B516B50D3C9B-001/solr-instance-001/solr.xml
[junit4] 2> 67252 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored
[junit4] 2> 67252 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored
[junit4] 2> 67252 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@47dc7f16, but no JMX reporters were configured - adding default JMX reporter.
[junit4] 2> 67285 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@47dc7f16
[junit4] 2> 67293 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@47dc7f16
[junit4] 2> 67293 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@47dc7f16
[junit4] 2> 67295 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_5697B516B50D3C9B-001/solr-instance-001/.
[junit4] 2> 67295 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 67296 INFO (coreLoadExecutor-187-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores
[junit4] 2> 67310 INFO (coreLoadExecutor-187-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.2.0
[junit4] 2> 67318 INFO (coreLoadExecutor-187-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 67321 INFO (coreLoadExecutor-187-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 67321 INFO (coreLoadExecutor-187-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_5697B516B50D3C9B-001/solr-instance-001/./collection1, trusted=true
[junit4] 2> 67322 INFO (coreLoadExecutor-187-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.collection1' (registry 'solr.core.collection1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@47dc7f16
[junit4] 2> 67322 INFO (coreLoadExecutor-187-thread-1) [ x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 67322 INFO (coreLoadExecutor-187-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_5697B516B50D3C9B-001/solr-instance-001/collection1], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_5697B516B50D3C9B-001/solr-instance-001/./collection1/data/]
[junit4] 2> 67323 INFO (coreLoadExecutor-187-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=18, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 67377 INFO (coreLoadExecutor-187-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 67377 INFO (coreLoadExecutor-187-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 67378 INFO (coreLoadExecutor-187-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=21, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 67378 INFO (coreLoadExecutor-187-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@7dab69a8[collection1] main]
[junit4] 2> 67379 INFO (coreLoadExecutor-187-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_5697B516B50D3C9B-001/solr-instance-001/collection1/conf
[junit4] 2> 67381 INFO (coreLoadExecutor-187-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4] 2> 67381 INFO (coreLoadExecutor-187-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 67383 INFO (searcherExecutor-188-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@7dab69a8[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 67885 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_5697B516B50D3C9B-001/solr-instance-002/collection1
[junit4] 2> 67887 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 67890 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@524ac01e{/solr,null,AVAILABLE}
[junit4] 2> 67890 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@4f86f6e8{HTTP/1.1,[http/1.1]}{127.0.0.1:๕๙๗๒๑}
[junit4] 2> 67890 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.e.j.s.Server Started @๗๐๑๓๗ms
[junit4] 2> 67890 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_5697B516B50D3C9B-001/solr-instance-002/collection1/data, hostContext=/solr, hostPort=59721}
[junit4] 2> 67890 ERROR (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 67890 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.2.0
[junit4] 2> 67890 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 67891 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 67891 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-11-10T01:15:22.208Z
[junit4] 2> 67891 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_5697B516B50D3C9B-001/solr-instance-002/solr.xml
[junit4] 2> 67894 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored
[junit4] 2> 67894 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored
[junit4] 2> 67894 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@47dc7f16, but no JMX reporters were configured - adding default JMX reporter.
[junit4] 2> 67931 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@47dc7f16
[junit4] 2> 67939 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@47dc7f16
[junit4] 2> 67939 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@47dc7f16
[junit4] 2> 67941 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_5697B516B50D3C9B-001/solr-instance-002/.
[junit4] 2> 67941 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 67959 INFO (coreLoadExecutor-197-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores
[junit4] 2> 67977 INFO (coreLoadExecutor-197-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.2.0
[junit4] 2> 67984 INFO (coreLoadExecutor-197-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 67986 INFO (coreLoadExecutor-197-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 67986 INFO (coreLoadExecutor-197-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_5697B516B50D3C9B-001/solr-instance-002/./collection1, trusted=true
[junit4] 2> 67986 INFO (coreLoadExecutor-197-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.collection1' (registry 'solr.core.collection1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@47dc7f16
[junit4] 2> 67986 INFO (coreLoadExecutor-197-thread-1) [ x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 67986 INFO (coreLoadExecutor-197-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_5697B516B50D3C9B-001/solr-instance-002/collection1], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_5697B516B50D3C9B-001/solr-instance-002/./collection1/data/]
[junit4] 2> 67989 INFO (coreLoadExecutor-197-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=18, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 68045 INFO (coreLoadExecutor-197-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 68045 INFO (coreLoadExecutor-197-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 68047 INFO (coreLoadExecutor-197-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=21, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 68047 INFO (coreLoadExecutor-197-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@67497461[collection1] main]
[junit4] 2> 68048 INFO (coreLoadExecutor-197-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_5697B516B50D3C9B-001/solr-instance-002/collection1/conf
[junit4] 2> 68049 INFO (coreLoadExecutor-197-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 1000ms
[junit4] 2> 68049 INFO (coreLoadExecutor-197-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 68052 INFO (searcherExecutor-198-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@67497461[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 68057 INFO (qtp1337807999-547) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=*:*&sort=id+desc&wt=javabin&version=2} hits=0 status=0 QTime=1
[junit4] 2> 68064 INFO (qtp1337807999-546) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1]} 0 5
[junit4] 2> 68065 INFO (qtp1337807999-549) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 68065 INFO (qtp1337807999-549) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@181e4588 commitCommandVersion:0
[junit4] 2> 68079 INFO (qtp1337807999-549) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@335cc9f5[collection1] main]
[junit4] 2> 68079 INFO (qtp1337807999-549) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 68084 INFO (searcherExecutor-188-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@335cc9f5[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.2.0):C1)))}
[junit4] 2> 68084 INFO (qtp1337807999-549) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={commit=true&wt=javabin&version=2}{commit=} 0 19
[junit4] 2> 68210 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 68212 INFO (qtp1337807999-550) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
[junit4] 2> 68213 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 2
[junit4] 2> 68213 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's version: 1510276522382
[junit4] 2> 68213 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 1
[junit4] 2> 68213 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave's version: 0
[junit4] 2> 68213 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting replication process
[junit4] 2> 68217 INFO (qtp1337807999-551) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&tlogFiles=false&wt=javabin&version=2&command=filelist} status=0 QTime=3
[junit4] 2> 68217 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Number of files in latest index in master: 10
[junit4] 2> 68219 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=20, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1326198795088722]
[junit4] 2> 68221 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 68222 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting download (fullCopy=false) to MockDirectoryWrapper(RAMDirectory@79e771c5 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4212e9ac)
[junit4] 2> 68229 INFO (qtp1337807999-544) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.si&checksum=true&wt=filestream&command=filecontent} status=0 QTime=3
[junit4] 2> 68231 INFO (qtp1337807999-547) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_LuceneVarGapFixedInterval_0.tib&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 68234 INFO (qtp1337807999-546) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_LuceneVarGapFixedInterval_0.tiv&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 68235 INFO (qtp1337807999-549) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.nvd&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 68287 INFO (qtp1337807999-548) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.fdx&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 68291 INFO (qtp1337807999-550) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_LuceneVarGapFixedInterval_0.doc&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 68301 INFO (qtp1337807999-551) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.fdt&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 68444 INFO (qtp1337807999-544) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.fnm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 68446 INFO (qtp1337807999-547) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.nvm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 68448 INFO (qtp1337807999-546) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=segments_2&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 68450 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Total time taken for download (fullCopy=false,bytesDownloaded=1814) : 0 secs (null bytes/sec) to MockDirectoryWrapper(RAMDirectory@79e771c5 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4212e9ac)
[junit4] 2> 68452 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=18, maxMergedSegmentMB=65.228515625, floorSegmentMB=1.6396484375, forceMergeDeletesPctAllowed=11.041589717081127, segmentsPerTier=47.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.17969593647135274
[junit4] 2> 68454 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 68455 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@32f69e9c[collection1] main]
[junit4] 2> 68456 INFO (searcherExecutor-198-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@32f69e9c[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.2.0):C1)))}
[junit4] 2> 68457 INFO (qtp260992077-563) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={wait=true&masterUrl=http://127.0.0.1:61326/solr/collection1/replication&command=fetchindex} status=0 QTime=247
[junit4] 2> 68466 INFO (qtp260992077-565) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=name:empty1&sort=id+desc&wt=javabin&version=2} hits=1 status=0 QTime=2
[junit4] 2> 68466 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 1 docs
[junit4] 2> 68468 INFO (qtp1337807999-546) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getDetails&qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=1
[junit4] 2> 68469 INFO (qtp1337807999-548) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getDetails&qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=0
[junit4] 2> 68471 INFO (qtp1337807999-550) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={slave=false&qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=0
[junit4] 2> 68472 INFO (qtp260992077-566) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getDetails&qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=2
[junit4] 2> 68473 INFO (qtp1337807999-551) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=assertVersions&qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
[junit4] 2> 68473 INFO (qtp260992077-567) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=assertVersions&qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
[junit4] 2> 68474 INFO (qtp1337807999-544) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 68474 INFO (qtp1337807999-544) [ x:collection1] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 68474 INFO (qtp1337807999-544) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 68475 INFO (qtp1337807999-544) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={commit=true&wt=javabin&version=2}{commit=} 0 0
[junit4] 2> 68476 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 68478 INFO (qtp1337807999-547) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
[junit4] 2> 68479 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 2
[junit4] 2> 68479 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's version: 1510276522382
[junit4] 2> 68479 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 2
[junit4] 2> 68479 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave's version: 1510276522382
[junit4] 2> 68479 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave in sync with master.
[junit4] 2> 68479 INFO (qtp260992077-568) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={wait=true&masterUrl=http://127.0.0.1:61326/solr/collection1/replication&command=fetchindex} status=0 QTime=3
[junit4] 2> 68481 INFO (qtp1337807999-549) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2]} 0 1
[junit4] 2> 68482 INFO (qtp1337807999-546) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 68482 INFO (qtp1337807999-546) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@181e4588 commitCommandVersion:0
[junit4] 2> 68486 INFO (qtp1337807999-546) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@38324002[collection1] main]
[junit4] 2> 68486 INFO (qtp1337807999-546) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 68487 INFO (searcherExecutor-188-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@38324002[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.2.0):C1) Uninverting(_1(7.2.0):C1)))}
[junit4] 2> 68487 INFO (qtp1337807999-546) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={commit=true&wt=javabin&version=2}{commit=} 0 5
[junit4] 2> 68488 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 68489 INFO (qtp1337807999-548) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
[junit4] 2> 68490 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 3
[junit4] 2> 68490 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's version: 1510276522799
[junit4] 2> 68490 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 2
[junit4] 2> 68490 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave's version: 1510276522382
[junit4] 2> 68490 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting replication process
[junit4] 2> 68491 INFO (qtp1337807999-550) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&tlogFiles=false&wt=javabin&version=2&command=filelist} status=0 QTime=0
[junit4] 2> 68491 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Number of files in latest index in master: 19
[junit4] 2> 68503 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=20, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1326198795088722]
[junit4] 2> 68503 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 68504 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting download (fullCopy=false) to MockDirectoryWrapper(RAMDirectory@2b48c507 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@35dfa624)
[junit4] 2> 68504 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.si because it already exists
[junit4] 2> 68504 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0_LuceneVarGapFixedInterval_0.tib because it already exists
[junit4] 2> 68504 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0_LuceneVarGapFixedInterval_0.tiv because it already exists
[junit4] 2> 68504 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.nvd because it already exists
[junit4] 2> 68504 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.fdx because it already exists
[junit4] 2> 68504 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0_LuceneVarGapFixedInterval_0.doc because it already exists
[junit4] 2> 68504 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.fdt because it already exists
[junit4] 2> 68504 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.fnm because it already exists
[junit4] 2> 68504 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.nvm because it already exists
[junit4] 2> 68505 INFO (qtp1337807999-551) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_1.si&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 68507 INFO (qtp1337807999-544) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_1.nvd&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 68508 INFO (qtp1337807999-544) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_1_LuceneVarGapFixedInterval_0.doc&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 68509 INFO (qtp1337807999-544) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_1.fdx&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 68510 INFO (qtp1337807999-544) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_1_LuceneVarGapFixedInterval_0.tib&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 68511 INFO (qtp1337807999-544) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_1.fnm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 68512 INFO (qtp1337807999-544) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_1.nvm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 68513 INFO (qtp1337807999-544) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_1.fdt&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 68514 INFO (qtp1337807999-544) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_1_LuceneVarGapFixedInterval_0.tiv&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 68516 INFO (qtp1337807999-544) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=segments_3&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 68516 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Total time taken for download (fullCopy=false,bytesDownloaded=1876) : 0 secs (null bytes/sec) to MockDirectoryWrapper(RAMDirectory@2b48c507 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@35dfa624)
[junit4] 2> 68517 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=18, maxMergedSegmentMB=65.228515625, floorSegmentMB=1.6396484375, forceMergeDeletesPctAllowed=11.041589717081127, segmentsPerTier=47.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.17969593647135274
[junit4] 2> 68518 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 68524 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@4442b9e[collection1] main]
[junit4] 2> 68525 INFO (searcherExecutor-198-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@4442b9e[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.2.0):C1) Uninverting(_1(7.2.0):C1)))}
[junit4] 2> 68526 INFO (qtp260992077-561) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={wait=true&masterUrl=http://127.0.0.1:61326/solr/collection1/replication&command=fetchindex} status=0 QTime=37
[junit4] 2> 68527 INFO (qtp260992077-563) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=name:empty2&sort=id+desc&wt=javabin&version=2} hits=1 status=0 QTime=0
[junit4] 2> 68527 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 1 docs
[junit4] 2> 68528 INFO (qtp1337807999-547) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getDetails&qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=0
[junit4] 2> 68530 INFO (qtp1337807999-549) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getDetails&qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=0
[junit4] 2> 68533 INFO (qtp1337807999-546) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={slave=false&qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=0
[junit4] 2> 68534 INFO (qtp260992077-564) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getDetails&qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=3
[junit4] 2> 68535 INFO (qtp1337807999-548) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=assertVersions&qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
[junit4] 2> 68535 INFO (qtp260992077-565) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=assertVersions&qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
[junit4] 2> 68536 INFO (qtp1337807999-550) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[3]} 0 0
[junit4] 2> 68537 INFO (qtp1337807999-551) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 68537 INFO (qtp1337807999-551) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@181e4588 commitCommandVersion:0
[junit4] 2> 68539 INFO (qtp1337807999-551) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@2b33db29[collection1] realtime]
[junit4] 2> 68539 INFO (qtp1337807999-551) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 68539 INFO (qtp1337807999-551) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={openSearcher=false&commit=true&wt=javabin&version=2}{commit=} 0 2
[junit4] 2> 68541 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 68543 INFO (qtp1337807999-544) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
[junit4] 2> 68543 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 4
[junit4] 2> 68543 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's version: 1510276522854
[junit4] 2> 68543 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 3
[junit4] 2> 68543 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave's version: 1510276522799
[junit4] 2> 68543 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting replication process
[junit4] 2> 68544 INFO (qtp1337807999-544) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&qt=/replication&tlogFiles=false&wt=javabin&version=2&command=filelist} status=0 QTime=0
[junit4] 2> 68544 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Number of files in latest index in master: 28
[junit4] 2> 68547 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=20, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1326198795088722]
[junit4] 2> 68547 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 68547 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2
[junit4] 2> 68547 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able
[junit4] 2> 69549 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2
[junit4] 2> 69549 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able
[junit4] 2> 70550 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2
[junit4] 2> 70550 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able
[junit4] 2> 71551 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2
[junit4] 2> 71551 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able
[junit4] 2> 72551 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2
[junit4] 2> 72552 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able
[junit4] 2> 73552 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2
[junit4] 2> 73552 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able
[junit4] 2> 74553 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2
[junit4] 2> 74553 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able
[junit4] 2> 75555 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2
[junit4] 2> 75555 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able
[junit4] 2> 76555 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2
[junit4] 2> 76555 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able
[junit4] 2> 77557 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2
[junit4] 2> 77557 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able
[junit4] 2> 78627 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2
[junit4] 2> 78627 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able
[junit4] 2> 79631 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher IndexFetcher slept for 11000ms for unused lucene index files to be delete-able
[junit4] 2> 79631 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting download (fullCopy=false) to MockDirectoryWrapper(RAMDirectory@1b4d7014 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7429158f)
[junit4] 2> 79631 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.si because it already exists
[junit4] 2> 79631 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0_LuceneVarGapFixedInterval_0.tib because it already exists
[junit4] 2> 79631 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0_LuceneVarGapFixedInterval_0.tiv because it already exists
[junit4] 2> 79631 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.nvd because it already exists
[junit4] 2> 79631 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.fdx because it already exists
[junit4] 2> 79631 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0_LuceneVarGapFixedInterval_0.doc because it already exists
[junit4] 2> 79632 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.fdt because it already exists
[junit4] 2> 79632 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.fnm because it already exists
[junit4] 2> 79632 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.nvm because it already exists
[junit4] 2> 79632 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.si because it already exists
[junit4] 2> 79632 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.nvd because it already exists
[junit4] 2> 79632 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1_LuceneVarGapFixedInterval_0.doc because it already exists
[junit4] 2> 79632 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.fdx because it already exists
[junit4] 2> 79632 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1_LuceneVarGapFixedInterval_0.tib because it already exists
[junit4] 2> 79632 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.fnm because it already exists
[junit4] 2> 79632 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.nvm because it already exists
[junit4] 2> 79632 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.fdt because it already exists
[junit4] 2> 79632 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1_LuceneVarGapFixedInterval_0.tiv because it already exists
[junit4] 2> 80057 INFO (qtp1337807999-547) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&qt=/replication&file=_2.nvd&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 80059 INFO (qtp1337807999-549) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&qt=/replication&file=_2.si&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 80062 INFO (qtp1337807999-546) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&qt=/replication&file=_2_LuceneVarGapFixedInterval_0.tib&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 80063 INFO (qtp1337807999-548) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&qt=/replication&file=_2.fdt&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 80065 INFO (qtp1337807999-550) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&qt=/replication&file=_2_LuceneVarGapFixedInterval_0.tiv&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 80066 INFO (qtp1337807999-550) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&qt=/replication&file=_2.fnm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 80067 INFO (qtp1337807999-550) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&qt=/replication&file=_2.nvm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 80068 INFO (qtp1337807999-550) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&qt=/replication&file=_2.fdx&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 80071 INFO (qtp1337807999-547) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&qt=/replication&file=_2_LuceneVarGapFixedInterval_0.doc&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 80089 INFO (qtp1337807999-549) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&qt=/replication&file=segments_4&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 80091 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Total time taken for download (fullCopy=false,bytesDownloaded=1938) : 11 secs (176 bytes/sec) to MockDirectoryWrapper(RAMDirectory@1b4d7014 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7429158f)
[junit4] 2> 80092 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=18, maxMergedSegmentMB=65.228515625, floorSegmentMB=1.6396484375, forceMergeDeletesPctAllowed=11.041589717081127, segmentsPerTier=47.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.17969593647135274
[junit4] 2> 80093 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 80095 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@7d445876[collection1] main]
[junit4] 2> 80096 INFO (searcherExecutor-198-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@7d445876[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.2.0):C1) Uninverting(_1(7.2.0):C1) Uninverting(_2(7.2.0):C1)))}
[junit4] 2> 80096 INFO (qtp260992077-566) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={wait=true&masterUrl=http://127.0.0.1:61326/solr/collection1/replication&command=fetchindex} status=0 QTime=11556
[junit4] 2> 80099 INFO (qtp1337807999-549) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=name:empty3&sort=id+desc&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 80100 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 0 docs
[junit4] 2> 80102 INFO (qtp260992077-567) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=name:empty3&sort=id+desc&wt=javabin&version=2} hits=1 status=0 QTime=0
[junit4] 2> 80103 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 1 docs
[junit4] 2> 80104 INFO (qtp1337807999-548) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[4]} 0 0
[junit4] 2> 80137 INFO (qtp1337807999-551) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 80137 INFO (qtp1337807999-551) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@181e4588 commitCommandVersion:0
[junit4] 2> 80147 INFO (qtp1337807999-551) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@905c407[collection1] main]
[junit4] 2> 80148 INFO (qtp1337807999-551) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 80149 INFO (searcherExecutor-188-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@905c407[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.2.0):C1) Uninverting(_1(7.2.0):C1) Uninverting(_2(7.2.0):C1) Uninverting(_3(7.2.0):C1)))}
[junit4] 2> 80149 INFO (qtp1337807999-551) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={commit=true&wt=javabin&version=2}{commit=} 0 11
[junit4] 2> 80158 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 80160 INFO (qtp1337807999-544) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
[junit4] 2> 80160 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 5
[junit4] 2> 80160 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's version: 1510276534454
[junit4] 2> 80160 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 4
[junit4] 2> 80160 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave's version: 1510276522854
[junit4] 2> 80160 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting replication process
[junit4] 2> 80162 INFO (qtp1337807999-550) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=5&qt=/replication&tlogFiles=false&wt=javabin&version=2&command=filelist} status=0 QTime=0
[junit4] 2> 80162 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Number of files in latest index in master: 37
[junit4] 2> 80164 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=20, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1326198795088722]
[junit4] 2> 80165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 80165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting download (fullCopy=false) to MockDirectoryWrapper(RAMDirectory@1e4a5926 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4c74a5b0)
[junit4] 2> 80165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.si because it already exists
[junit4] 2> 80165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0_LuceneVarGapFixedInterval_0.tib because it already exists
[junit4] 2> 80165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0_LuceneVarGapFixedInterval_0.tiv because it already exists
[junit4] 2> 80165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.nvd because it already exists
[junit4] 2> 80165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.fdx because it already exists
[junit4] 2> 80165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0_LuceneVarGapFixedInterval_0.doc because it already exists
[junit4] 2> 80165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.fdt because it already exists
[junit4] 2> 80165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.fnm because it already exists
[junit4] 2> 80165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.nvm because it already exists
[junit4] 2> 80165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.si because it already exists
[junit4] 2> 80165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.nvd because it already exists
[junit4] 2> 80165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1_LuceneVarGapFixedInterval_0.doc because it already exists
[junit4] 2> 80165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.fdx because it already exists
[junit4] 2> 80165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1_LuceneVarGapFixedInterval_0.tib because it already exists
[junit4] 2> 80165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.fnm because it already exists
[junit4] 2> 80165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.nvm because it already exists
[junit4] 2> 80165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.fdt because it already exists
[junit4] 2> 80165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1_LuceneVarGapFixedInterval_0.tiv because it already exists
[junit4] 2> 80165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _2.nvd because it already exists
[junit4] 2> 80165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _2.si because it already exists
[junit4] 2> 80165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _2_LuceneVarGapFixedInterval_0.tib because it already exists
[junit4] 2> 80165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _2.fdt because it already exists
[junit4] 2> 80165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _2_LuceneVarGapFixedInterval_0.tiv because it already exists
[junit4] 2> 80165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _2.fnm because it already exists
[junit4] 2> 80165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _2.nvm because it already exists
[junit4] 2> 80165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _2.fdx because it already exists
[junit4] 2> 80165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _2_LuceneVarGapFixedInterval_0.doc because it already exists
[junit4] 2> 80166 INFO (qtp1337807999-547) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=5&qt=/replication&file=_3.fdx&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 80168 INFO (qtp1337807999-547) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=5&qt=/replication&file=_3_LuceneVarGapFixedInterval_0.tiv&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 80169 INFO (qtp1337807999-547) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=5&qt=/replication&file=_3.si&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 80180 INFO (qtp1337807999-547) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=5&qt=/replication&file=_3.nvd&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 80204 INFO (qtp1337807999-548) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=5&qt=/replication&file=_3_LuceneVarGapFixedInterval_0.doc&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 80369 INFO (qtp1337807999-551) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=5&qt=/replication&file=_3.fnm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 80372 INFO (qtp1337807999-544) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=5&qt=/replication&file=_3.nvm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 80375 INFO (qtp1337807999-550) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=5&qt=/replication&file=_3.fdt&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 80377 INFO (qtp1337807999-546) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=5&qt=/replication&file=_3_LuceneVarGapFixedInterval_0.tib&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 80380 INFO (qtp1337807999-549) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=5&qt=/replication&file=segments_5&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 80381 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Total time taken for download (fullCopy=false,bytesDownloaded=2000) : 0 secs (null bytes/sec) to MockDirectoryWrapper(RAMDirectory@1e4a5926 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4c74a5b0)
[junit4] 2> 80385 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=18, maxMergedSegmentMB=65.228515625, floorSegmentMB=1.6396484375, forceMergeDeletesPctAllowed=11.041589717081127, segmentsPerTier=47.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.17969593647135274
[junit4] 2> 80389 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 80390 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@7d29718b[collection1] main]
[junit4] 2> 80393 INFO (searcherExecutor-198-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@7d29718b[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.2.0):C1) Uninverting(_1(7.2.0):C1) Uninverting(_2(7.2.0):C1) Uninverting(_3(7.2.0):C1)))}
[junit4] 2> 80393 INFO (qtp260992077-568) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={wait=true&masterUrl=http://127.0.0.1:61326/solr/collection1/replication&command=fetchindex} status=0 QTime=241
[junit4] 2> 80399 INFO (qtp1337807999-547) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=name:(empty1+empty2+empty3+empty4)&sort=id+desc&wt=javabin&version=2} hits=4 status=0 QTime=3
[junit4] 2> 80401 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 4 docs
[junit4] 2> 80406 INFO (qtp260992077-561) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=name:(empty1+empty2+empty3+empty4)&sort=id+desc&wt=javabin&version=2} hits=4 status=0 QTime=4
[junit4] 2> 80408 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 4 docs
[junit4] 2> 80410 INFO (qtp1337807999-548) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getDetails&qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=0
[junit4] 2> 80412 INFO (qtp1337807999-551) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getDetails&qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=0
[junit4] 2> 80414 INFO (qtp1337807999-544) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={slave=false&qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=0
[junit4] 2> 80415 INFO (qtp260992077-563) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getDetails&qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=1
[junit4] 2> 80416 INFO (qtp1337807999-550) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=assertVersions&qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
[junit4] 2> 80416 INFO (qtp260992077-564) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=assertVersions&qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
[junit4] 2> 80416 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testEmptyCommits
[junit4] 2> 80417 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@27225bf2{HTTP/1.1,[http/1.1]}{127.0.0.1:๐}
[junit4] 2> 80417 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=976914407
[junit4] 2> 80417 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 80417 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@3f89ed5a: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@484fcacb
[junit4] 2> 80420 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 80420 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4e043235: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@775f1060
[junit4] 2> 80470 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 80470 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[5697B516B50D3C9B]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@553c766b: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@79b882
[junit4] 2> 80471 INFO (coreCloseExecutor-207-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@8e6fb2b
[junit4] 2> 80471 INFO (coreCloseExecutor-207-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=149355307
[junit4] 2> 80471 INFO (coreCloseExecutor-207-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxR
[...truncated too long message...]
core_node3 x:multicollection2_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@5151b4b4: rootName = solr_57440, domain = solr.core.multicollection2.shard1.replica_n1, service url = null, agent id = null] for registry solr.core.multicollection2.shard1.replica_n1 / com.codahale.metrics.MetricRegistry@16912c41
[junit4] 2> 183452 INFO (jetty-closer-578-thread-3) [ ] o.a.s.c.Overseer Overseer (id=98977829430951944-127.0.0.1:47523_solr-n_0000000000) closing
[junit4] 2> 183453 INFO (OverseerStateUpdate-98977829430951944-127.0.0.1:47523_solr-n_0000000000) [n:127.0.0.1:47523_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:47523_solr
[junit4] 2> 183461 INFO (coreCloseExecutor-1431-thread-2) [n:127.0.0.1:57440_solr c:multicollection2 s:shard1 r:core_node3 x:multicollection2_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.multicollection2.shard1.leader, tag=826026017
[junit4] 2> 183461 INFO (coreCloseExecutor-1431-thread-3) [n:127.0.0.1:57440_solr c:multicollection1 s:shard1 r:core_node3 x:multicollection1_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.multicollection1.shard1.replica_n1, tag=1900350909
[junit4] 2> 183461 INFO (coreCloseExecutor-1431-thread-3) [n:127.0.0.1:57440_solr c:multicollection1 s:shard1 r:core_node3 x:multicollection1_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1b783fbd: rootName = solr_57440, domain = solr.core.multicollection1.shard1.replica_n1, service url = null, agent id = null] for registry solr.core.multicollection1.shard1.replica_n1 / com.codahale.metrics.MetricRegistry@5e42a01f
[junit4] 2> 183463 WARN (OverseerAutoScalingTriggerThread-98977829430951944-127.0.0.1:47523_solr-n_0000000000) [n:127.0.0.1:47523_solr ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 183472 INFO (zkCallback-592-thread-7-processing-n:127.0.0.1:57440_solr) [n:127.0.0.1:57440_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:57440_solr
[junit4] 2> 183475 INFO (jetty-closer-578-thread-3) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@2ba6f8c1{/solr,null,UNAVAILABLE}
[junit4] 2> 183479 INFO (coreCloseExecutor-1431-thread-3) [n:127.0.0.1:57440_solr c:multicollection1 s:shard1 r:core_node3 x:multicollection1_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.multicollection1.shard1.leader, tag=1900350909
[junit4] 2> 183479 INFO (coreCloseExecutor-1431-thread-1) [n:127.0.0.1:57440_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1.shard1.replica_n1, tag=1609336445
[junit4] 2> 183479 INFO (coreCloseExecutor-1431-thread-1) [n:127.0.0.1:57440_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@35a52940: rootName = solr_57440, domain = solr.core.collection1.shard1.replica_n1, service url = null, agent id = null] for registry solr.core.collection1.shard1.replica_n1 / com.codahale.metrics.MetricRegistry@4cc11500
[junit4] 2> 183488 INFO (coreCloseExecutor-1431-thread-1) [n:127.0.0.1:57440_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.collection1.shard1.leader, tag=1609336445
[junit4] 2> 183488 INFO (coreCloseExecutor-1431-thread-7) [n:127.0.0.1:57440_solr c:2nd_collection s:shard1 r:core_node3 x:2nd_collection_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.2nd_collection.shard1.replica_n1, tag=2135608617
[junit4] 2> 183488 INFO (coreCloseExecutor-1431-thread-1) [n:127.0.0.1:57440_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 Committing on IndexWriter close.
[junit4] 2> 183488 INFO (coreCloseExecutor-1431-thread-7) [n:127.0.0.1:57440_solr c:2nd_collection s:shard1 r:core_node3 x:2nd_collection_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@51005a94: rootName = solr_57440, domain = solr.core.2nd_collection.shard1.replica_n1, service url = null, agent id = null] for registry solr.core.2nd_collection.shard1.replica_n1 / com.codahale.metrics.MetricRegistry@4ac6af83
[junit4] 2> 183488 INFO (coreCloseExecutor-1431-thread-1) [n:127.0.0.1:57440_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@44518b1a commitCommandVersion:0
[junit4] 2> 183499 INFO (coreCloseExecutor-1431-thread-7) [n:127.0.0.1:57440_solr c:2nd_collection s:shard1 r:core_node3 x:2nd_collection_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.2nd_collection.shard1.leader, tag=2135608617
[junit4] 2> 183507 INFO (jetty-closer-578-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@722d2a48{/solr,null,UNAVAILABLE}
[junit4] 2> 183508 ERROR (SUITE-CloudSolrClientTest-seed#[C663787755F7412D]-worker) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
[junit4] 2> 183509 INFO (SUITE-CloudSolrClientTest-seed#[C663787755F7412D]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:60466 60466
[junit4] 2> 194324 INFO (Thread-721) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:60466 60466
[junit4] 2> 194324 WARN (Thread-721) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 8 /solr/clusterprops.json
[junit4] 2> 8 /solr/aliases.json
[junit4] 2> 3 /solr/security.json
[junit4] 2> 3 /solr/configs/conf
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 43 /solr/collections/localShardsTestColl/state.json
[junit4] 2> 24 /solr/collections/foo/state.json
[junit4] 2> 16 /solr/collections/stale_state_test_col/state.json
[junit4] 2> 12 /solr/collections/collection1/state.json
[junit4] 2> 12 /solr/collections/2nd_collection/state.json
[junit4] 2> 12 /solr/collections/multicollection2/state.json
[junit4] 2> 12 /solr/collections/multicollection1/state.json
[junit4] 2> 10 /solr/collections/nemesis/state.json
[junit4] 2> 8 /solr/clusterstate.json
[junit4] 2> 6 /solr/collections/overwrite/state.json
[junit4] 2> 2 /solr/collections/localShardsTestColl/leader_elect/shard2/election/98977829430951943-core_node12-n_0000000000
[junit4] 2> 2 /solr/collections/foo/leader_elect/shard1/election/98977829430951943-core_node6-n_0000000000
[junit4] 2> 2 /solr/collections/localShardsTestColl/leader_elect/shard1/election/98977829430951944-core_node3-n_0000000000
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 8 /solr/live_nodes
[junit4] 2> 8 /solr/collections
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at: /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.impl.CloudSolrClientTest_C663787755F7412D-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {multiDefault=PostingsFormat(name=Direct), a_t=PostingsFormat(name=Direct), title_s=PostingsFormat(name=Direct), id=PostingsFormat(name=LuceneVarGapFixedInterval), text=FST50}, docValues:{_version_=DocValuesFormat(name=Memory), multiDefault=DocValuesFormat(name=Direct), title_s=DocValuesFormat(name=Direct), intDefault=DocValuesFormat(name=Memory), id=DocValuesFormat(name=Asserting), timestamp=DocValuesFormat(name=Direct)}, maxPointsInLeafNode=524, maxMBSortInHeap=5.467834908657985, sim=RandomSimilarity(queryNorm=true): {}, locale=es-VE, timezone=Pacific/Marquesas
[junit4] 2> NOTE: SunOS 5.11 amd64/Oracle Corporation 1.8.0_152 (64-bit)/cpus=3,threads=1,free=183511176,total=382730240
[junit4] 2> NOTE: All tests run in this JVM: [SolrExampleStreamingTest, TestUpdateRequestCodec, SchemaTest, TestBatchUpdate, NotEvaluatorTest, NormalDistributionEvaluatorTest, TestSpellCheckResponse, TestHash, TestCoreAdmin, TestJsonRecordReader, TestCloudSolrClientConnections, ArcSineEvaluatorTest, CumulativeProbabilityEvaluatorTest, UsingSolrJRefGuideExamplesTest, GreaterThanEvaluatorTest, AppendEvaluatorTest, TestDelegationTokenRequest, StreamingTest, ModifiableSolrParamsTest, FieldAnalysisResponseTest, TestDelegationTokenResponse, ShardParamsTest, TestXMLEscaping, TestCollectionStateWatchers, TestCollectionAdminRequest, TestDocumentObjectBinder, EmpiricalDistributionEvaluatorTest, SolrExampleXMLTest, LengthEvaluatorTest, CloudSolrClientBuilderTest, PowerEvaluatorTest, JettyWebappTest, MultiplyEvaluatorTest, TestRetryUtil, StreamExpressionToExpessionTest, SolrExampleStreamingBinaryTest, SolrExampleEmbeddedTest, LargeVolumeBinaryJettyTest, LargeVolumeJettyTest, TestSolrProperties, SolrParamTest, TermsResponseTest, TestEmbeddedSolrServer, TestNamedListCodec, TestJavaBinCodec, ContentStreamTest, SolrDocumentTest, NamedListTest, FacetFieldTest, CollectionAdminRequestRequiredParamsTest, GetByIdTest, SolrSchemalessExampleTest, TestLBHttpSolrClient, TestPolicy, CloudSolrClientMultiConstructorTest, CloudSolrClientTest]
[junit4] Completed [95/146 (1!)] on J0 in 47.13s, 16 tests, 1 error <<< FAILURES!
[...truncated 46530 lines...]
[JENKINS] Lucene-Solr-7.x-Solaris (64bit/jdk1.8.0) - Build # 294 -
Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Solaris/294/
Java: 64bit/jdk1.8.0 -XX:+UseCompressedOops -XX:+UseG1GC
1 tests failed.
FAILED: org.apache.solr.cloud.autoscaling.NodeLostTriggerTest.testListenerAcceptance
Error Message:
expected:<1> but was:<0>
Stack Trace:
java.lang.AssertionError: expected:<1> but was:<0>
at __randomizedtesting.SeedInfo.seed([410B5F7EBEC2D368:50BF0599074BC79E]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.junit.Assert.assertEquals(Assert.java:456)
at org.apache.solr.cloud.autoscaling.NodeLostTriggerTest.testListenerAcceptance(NodeLostTriggerTest.java:253)
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:1737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
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:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
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:748)
Build Log:
[...truncated 11726 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.NodeLostTriggerTest
[junit4] 2> 501292 INFO (SUITE-NodeLostTriggerTest-seed#[410B5F7EBEC2D368]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir: /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.NodeLostTriggerTest_410B5F7EBEC2D368-001/init-core-data-001
[junit4] 2> 501293 WARN (SUITE-NodeLostTriggerTest-seed#[410B5F7EBEC2D368]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=34 numCloses=34
[junit4] 2> 501293 INFO (SUITE-NodeLostTriggerTest-seed#[410B5F7EBEC2D368]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 501294 INFO (SUITE-NodeLostTriggerTest-seed#[410B5F7EBEC2D368]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
[junit4] 2> 501295 INFO (SUITE-NodeLostTriggerTest-seed#[410B5F7EBEC2D368]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 5 servers in /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.NodeLostTriggerTest_410B5F7EBEC2D368-001/tempDir-001
[junit4] 2> 501295 INFO (SUITE-NodeLostTriggerTest-seed#[410B5F7EBEC2D368]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 501297 INFO (Thread-578) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 501297 INFO (Thread-578) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 501300 ERROR (Thread-578) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
[junit4] 2> 501398 INFO (SUITE-NodeLostTriggerTest-seed#[410B5F7EBEC2D368]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:53479
[junit4] 2> 501411 INFO (jetty-launcher-577-thread-2) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 501411 INFO (jetty-launcher-577-thread-1) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 501411 INFO (jetty-launcher-577-thread-3) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 501412 INFO (jetty-launcher-577-thread-4) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 501412 INFO (jetty-launcher-577-thread-5) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 501416 INFO (jetty-launcher-577-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@7bb4d024{/solr,null,AVAILABLE}
[junit4] 2> 501418 INFO (jetty-launcher-577-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@41ec3ac6{/solr,null,AVAILABLE}
[junit4] 2> 501419 INFO (jetty-launcher-577-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@615c8d86{HTTP/1.1,[http/1.1]}{127.0.0.1:60675}
[junit4] 2> 501419 INFO (jetty-launcher-577-thread-2) [ ] o.e.j.s.Server Started @508336ms
[junit4] 2> 501419 INFO (jetty-launcher-577-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=60675}
[junit4] 2> 501419 ERROR (jetty-launcher-577-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 501419 INFO (jetty-launcher-577-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@60444ef3{HTTP/1.1,[http/1.1]}{127.0.0.1:38835}
[junit4] 2> 501419 INFO (jetty-launcher-577-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.2.0
[junit4] 2> 501419 INFO (jetty-launcher-577-thread-1) [ ] o.e.j.s.Server Started @508336ms
[junit4] 2> 501419 INFO (jetty-launcher-577-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 501419 INFO (jetty-launcher-577-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=38835}
[junit4] 2> 501419 INFO (jetty-launcher-577-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 501419 INFO (jetty-launcher-577-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-11-10T11:21:51.958Z
[junit4] 2> 501419 ERROR (jetty-launcher-577-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 501420 INFO (jetty-launcher-577-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.2.0
[junit4] 2> 501420 INFO (jetty-launcher-577-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 501420 INFO (jetty-launcher-577-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 501420 INFO (jetty-launcher-577-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-11-10T11:21:51.959Z
[junit4] 2> 501422 INFO (jetty-launcher-577-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@2055623d{/solr,null,AVAILABLE}
[junit4] 2> 501424 INFO (jetty-launcher-577-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@4e6bb425{/solr,null,AVAILABLE}
[junit4] 2> 501425 INFO (jetty-launcher-577-thread-5) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@7a196b86{/solr,null,AVAILABLE}
[junit4] 2> 501426 INFO (jetty-launcher-577-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1075518f{HTTP/1.1,[http/1.1]}{127.0.0.1:49221}
[junit4] 2> 501427 INFO (jetty-launcher-577-thread-3) [ ] o.e.j.s.Server Started @508344ms
[junit4] 2> 501427 INFO (jetty-launcher-577-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=49221}
[junit4] 2> 501427 ERROR (jetty-launcher-577-thread-3) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 501427 INFO (jetty-launcher-577-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.2.0
[junit4] 2> 501427 INFO (jetty-launcher-577-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 501427 INFO (jetty-launcher-577-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 501427 INFO (jetty-launcher-577-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-11-10T11:21:51.966Z
[junit4] 2> 501428 INFO (jetty-launcher-577-thread-4) [ ] o.e.j.s.AbstractConnector Started ServerConnector@3b560008{HTTP/1.1,[http/1.1]}{127.0.0.1:59871}
[junit4] 2> 501428 INFO (jetty-launcher-577-thread-4) [ ] o.e.j.s.Server Started @508346ms
[junit4] 2> 501428 INFO (jetty-launcher-577-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=59871}
[junit4] 2> 501429 ERROR (jetty-launcher-577-thread-4) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 501429 INFO (jetty-launcher-577-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.2.0
[junit4] 2> 501429 INFO (jetty-launcher-577-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 501429 INFO (jetty-launcher-577-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 501429 INFO (jetty-launcher-577-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-11-10T11:21:51.968Z
[junit4] 2> 501430 INFO (jetty-launcher-577-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 501430 INFO (jetty-launcher-577-thread-5) [ ] o.e.j.s.AbstractConnector Started ServerConnector@3f1dae13{HTTP/1.1,[http/1.1]}{127.0.0.1:51679}
[junit4] 2> 501430 INFO (jetty-launcher-577-thread-5) [ ] o.e.j.s.Server Started @508348ms
[junit4] 2> 501430 INFO (jetty-launcher-577-thread-5) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=51679}
[junit4] 2> 501431 ERROR (jetty-launcher-577-thread-5) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 501431 INFO (jetty-launcher-577-thread-5) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.2.0
[junit4] 2> 501431 INFO (jetty-launcher-577-thread-5) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 501431 INFO (jetty-launcher-577-thread-5) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 501431 INFO (jetty-launcher-577-thread-5) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-11-10T11:21:51.970Z
[junit4] 2> 501431 INFO (jetty-launcher-577-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 501442 INFO (jetty-launcher-577-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 501442 INFO (jetty-launcher-577-thread-5) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 501445 INFO (jetty-launcher-577-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 501446 INFO (jetty-launcher-577-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:53479/solr
[junit4] 2> 501454 INFO (jetty-launcher-577-thread-5) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:53479/solr
[junit4] 2> 501457 INFO (jetty-launcher-577-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:53479/solr
[junit4] 2> 501462 INFO (jetty-launcher-577-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:53479/solr
[junit4] 2> 501468 INFO (jetty-launcher-577-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:53479/solr
[junit4] 2> 501550 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15fa5aa23de000c, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 501585 INFO (jetty-launcher-577-thread-3) [n:127.0.0.1:49221_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 501587 INFO (jetty-launcher-577-thread-3) [n:127.0.0.1:49221_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:49221_solr
[junit4] 2> 501588 INFO (jetty-launcher-577-thread-2) [n:127.0.0.1:60675_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 501590 INFO (jetty-launcher-577-thread-3) [n:127.0.0.1:49221_solr ] o.a.s.c.Overseer Overseer (id=98979866990215181-127.0.0.1:49221_solr-n_0000000000) starting
[junit4] 2> 501591 INFO (jetty-launcher-577-thread-2) [n:127.0.0.1:60675_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:60675_solr
[junit4] 2> 501604 INFO (jetty-launcher-577-thread-4) [n:127.0.0.1:59871_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 501617 INFO (jetty-launcher-577-thread-3) [n:127.0.0.1:49221_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49221_solr
[junit4] 2> 501618 INFO (jetty-launcher-577-thread-4) [n:127.0.0.1:59871_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 501619 INFO (zkCallback-602-thread-1-processing-n:127.0.0.1:49221_solr) [n:127.0.0.1:49221_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 501620 INFO (zkCallback-606-thread-1-processing-n:127.0.0.1:60675_solr) [n:127.0.0.1:60675_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 501633 INFO (OverseerStateUpdate-98979866990215181-127.0.0.1:49221_solr-n_0000000000) [n:127.0.0.1:49221_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 501638 INFO (jetty-launcher-577-thread-4) [n:127.0.0.1:59871_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:59871_solr
[junit4] 2> 501642 INFO (zkCallback-602-thread-1-processing-n:127.0.0.1:49221_solr) [n:127.0.0.1:49221_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 501656 INFO (zkCallback-606-thread-1-processing-n:127.0.0.1:60675_solr) [n:127.0.0.1:60675_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 501659 INFO (zkCallback-605-thread-1-processing-n:127.0.0.1:59871_solr) [n:127.0.0.1:59871_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3)
[junit4] 2> 501696 INFO (zkCallback-606-thread-1-processing-n:127.0.0.1:60675_solr) [n:127.0.0.1:60675_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 501776 INFO (jetty-launcher-577-thread-3) [n:127.0.0.1:49221_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_49221.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1cf536c4
[junit4] 2> 501888 INFO (jetty-launcher-577-thread-3) [n:127.0.0.1:49221_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_49221.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1cf536c4
[junit4] 2> 501890 INFO (jetty-launcher-577-thread-3) [n:127.0.0.1:49221_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_49221.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1cf536c4
[junit4] 2> 501892 INFO (jetty-launcher-577-thread-3) [n:127.0.0.1:49221_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.NodeLostTriggerTest_410B5F7EBEC2D368-001/tempDir-001/node3/.
[junit4] 2> 501957 INFO (jetty-launcher-577-thread-2) [n:127.0.0.1:60675_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_60675.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1cf536c4
[junit4] 2> 501965 INFO (jetty-launcher-577-thread-5) [n:127.0.0.1:51679_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 501969 INFO (jetty-launcher-577-thread-5) [n:127.0.0.1:51679_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 501972 INFO (jetty-launcher-577-thread-5) [n:127.0.0.1:51679_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51679_solr
[junit4] 2> 501973 INFO (zkCallback-606-thread-1-processing-n:127.0.0.1:60675_solr) [n:127.0.0.1:60675_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 501974 INFO (zkCallback-605-thread-2-processing-n:127.0.0.1:59871_solr) [n:127.0.0.1:59871_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 501974 INFO (zkCallback-602-thread-1-processing-n:127.0.0.1:49221_solr) [n:127.0.0.1:49221_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 502060 INFO (zkCallback-598-thread-1-processing-n:127.0.0.1:51679_solr) [n:127.0.0.1:51679_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 502075 INFO (jetty-launcher-577-thread-2) [n:127.0.0.1:60675_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_60675.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1cf536c4
[junit4] 2> 502076 INFO (jetty-launcher-577-thread-2) [n:127.0.0.1:60675_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_60675.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1cf536c4
[junit4] 2> 502077 INFO (jetty-launcher-577-thread-2) [n:127.0.0.1:60675_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.NodeLostTriggerTest_410B5F7EBEC2D368-001/tempDir-001/node1/.
[junit4] 2> 502123 INFO (jetty-launcher-577-thread-5) [n:127.0.0.1:51679_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_51679.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1cf536c4
[junit4] 2> 502126 INFO (jetty-launcher-577-thread-4) [n:127.0.0.1:59871_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_59871.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1cf536c4
[junit4] 2> 502132 INFO (jetty-launcher-577-thread-5) [n:127.0.0.1:51679_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_51679.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1cf536c4
[junit4] 2> 502135 INFO (jetty-launcher-577-thread-4) [n:127.0.0.1:59871_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_59871.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1cf536c4
[junit4] 2> 502135 INFO (jetty-launcher-577-thread-4) [n:127.0.0.1:59871_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_59871.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1cf536c4
[junit4] 2> 502136 INFO (jetty-launcher-577-thread-4) [n:127.0.0.1:59871_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.NodeLostTriggerTest_410B5F7EBEC2D368-001/tempDir-001/node4/.
[junit4] 2> 502145 INFO (jetty-launcher-577-thread-5) [n:127.0.0.1:51679_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_51679.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1cf536c4
[junit4] 2> 502146 INFO (jetty-launcher-577-thread-5) [n:127.0.0.1:51679_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.NodeLostTriggerTest_410B5F7EBEC2D368-001/tempDir-001/node5/.
[junit4] 2> 502151 INFO (jetty-launcher-577-thread-1) [n:127.0.0.1:38835_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 502154 INFO (jetty-launcher-577-thread-1) [n:127.0.0.1:38835_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 502156 INFO (jetty-launcher-577-thread-1) [n:127.0.0.1:38835_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38835_solr
[junit4] 2> 502182 INFO (zkCallback-605-thread-2-processing-n:127.0.0.1:59871_solr) [n:127.0.0.1:59871_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 502182 INFO (zkCallback-606-thread-1-processing-n:127.0.0.1:60675_solr) [n:127.0.0.1:60675_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 502186 INFO (zkCallback-596-thread-1-processing-n:127.0.0.1:38835_solr) [n:127.0.0.1:38835_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 502186 INFO (zkCallback-598-thread-1-processing-n:127.0.0.1:51679_solr) [n:127.0.0.1:51679_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 502186 INFO (zkCallback-602-thread-2-processing-n:127.0.0.1:49221_solr) [n:127.0.0.1:49221_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 502269 INFO (jetty-launcher-577-thread-1) [n:127.0.0.1:38835_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_38835.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1cf536c4
[junit4] 2> 502278 INFO (jetty-launcher-577-thread-1) [n:127.0.0.1:38835_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_38835.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1cf536c4
[junit4] 2> 502278 INFO (jetty-launcher-577-thread-1) [n:127.0.0.1:38835_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_38835.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1cf536c4
[junit4] 2> 502279 INFO (jetty-launcher-577-thread-1) [n:127.0.0.1:38835_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.NodeLostTriggerTest_410B5F7EBEC2D368-001/tempDir-001/node2/.
[junit4] 2> 502384 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15fa5aa23de0010, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 502389 INFO (SUITE-NodeLostTriggerTest-seed#[410B5F7EBEC2D368]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (5)
[junit4] 2> 502405 INFO (SUITE-NodeLostTriggerTest-seed#[410B5F7EBEC2D368]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:53479/solr ready
[junit4] 2> 502457 INFO (TEST-NodeLostTriggerTest.testActionLifecycle-seed#[410B5F7EBEC2D368]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testActionLifecycle
[junit4] 2> 502460 INFO (TEST-NodeLostTriggerTest.testActionLifecycle-seed#[410B5F7EBEC2D368]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testActionLifecycle
[junit4] 2> 502499 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testTrigger
[junit4] 2> 502500 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@3b560008{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 502500 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=488330484
[junit4] 2> 502500 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 502503 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@13431906: rootName = solr_59871, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@9c41684
[junit4] 2> 502516 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 502516 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@700e145e: rootName = solr_59871, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@71bcb52e
[junit4] 2> 502523 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 502523 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@7073de9b: rootName = solr_59871, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@3c73d9ff
[junit4] 2> 502526 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:59871_solr
[junit4] 2> 502528 INFO (zkCallback-606-thread-1-processing-n:127.0.0.1:60675_solr) [n:127.0.0.1:60675_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (4)
[junit4] 2> 502528 INFO (zkCallback-596-thread-1-processing-n:127.0.0.1:38835_solr) [n:127.0.0.1:38835_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (4)
[junit4] 2> 502529 INFO (zkCallback-602-thread-2-processing-n:127.0.0.1:49221_solr) [n:127.0.0.1:49221_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (4)
[junit4] 2> 502529 INFO (zkCallback-605-thread-2-processing-n:127.0.0.1:59871_solr) [n:127.0.0.1:59871_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (4)
[junit4] 2> 502531 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 502531 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 502533 INFO (zkCallback-614-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (4)
[junit4] 2> 502534 INFO (zkCallback-598-thread-1-processing-n:127.0.0.1:51679_solr) [n:127.0.0.1:51679_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (4)
[junit4] 2> 502536 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@2055623d{/solr,null,UNAVAILABLE}
[junit4] 2> 502539 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@1075518f{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 502540 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1623723038
[junit4] 2> 502540 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 502540 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@45089f20: rootName = solr_49221, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@177a938a
[junit4] 2> 502547 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 502547 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@618c3437: rootName = solr_49221, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@71bcb52e
[junit4] 2> 502553 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 502553 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@74cc1405: rootName = solr_49221, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@3c73d9ff
[junit4] 2> 502555 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:49221_solr
[junit4] 2> 502557 INFO (zkCallback-596-thread-1-processing-n:127.0.0.1:38835_solr) [n:127.0.0.1:38835_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 502557 INFO (zkCallback-598-thread-1-processing-n:127.0.0.1:51679_solr) [n:127.0.0.1:51679_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 502557 INFO (zkCallback-602-thread-1-processing-n:127.0.0.1:49221_solr) [n:127.0.0.1:49221_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 502559 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 502561 INFO (zkCallback-606-thread-1-processing-n:127.0.0.1:60675_solr) [n:127.0.0.1:60675_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 502562 INFO (zkCallback-614-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 502562 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 502563 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.c.Overseer Overseer (id=98979866990215181-127.0.0.1:49221_solr-n_0000000000) closing
[junit4] 2> 502563 INFO (OverseerStateUpdate-98979866990215181-127.0.0.1:49221_solr-n_0000000000) [n:127.0.0.1:49221_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:49221_solr
[junit4] 2> 502564 WARN (OverseerAutoScalingTriggerThread-98979866990215181-127.0.0.1:49221_solr-n_0000000000) [n:127.0.0.1:49221_solr ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 502568 INFO (zkCallback-606-thread-1-processing-n:127.0.0.1:60675_solr) [n:127.0.0.1:60675_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:60675_solr
[junit4] 2> 502570 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@4e6bb425{/solr,null,UNAVAILABLE}
[junit4] 2> 502578 INFO (zkCallback-606-thread-1-processing-n:127.0.0.1:60675_solr) [n:127.0.0.1:60675_solr ] o.a.s.c.Overseer Overseer (id=98979866990215183-127.0.0.1:60675_solr-n_0000000001) starting
[junit4] 2> 509600 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@615c8d86{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 509601 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=259101008
[junit4] 2> 509601 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 509601 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@21b0b584: rootName = solr_60675, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@2dd674a5
[junit4] 2> 509606 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 509606 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@2ae7a070: rootName = solr_60675, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@71bcb52e
[junit4] 2> 509609 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 509609 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@ac29fef: rootName = solr_60675, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@3c73d9ff
[junit4] 2> 509611 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:60675_solr
[junit4] 2> 509612 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 509613 INFO (zkCallback-614-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 509613 INFO (zkCallback-606-thread-1-processing-n:127.0.0.1:60675_solr) [n:127.0.0.1:60675_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 509613 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 509613 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.c.Overseer Overseer (id=98979866990215183-127.0.0.1:60675_solr-n_0000000001) closing
[junit4] 2> 509613 INFO (zkCallback-596-thread-1-processing-n:127.0.0.1:38835_solr) [n:127.0.0.1:38835_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 509613 INFO (zkCallback-598-thread-1-processing-n:127.0.0.1:51679_solr) [n:127.0.0.1:51679_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 509613 INFO (OverseerStateUpdate-98979866990215183-127.0.0.1:60675_solr-n_0000000001) [n:127.0.0.1:60675_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:60675_solr
[junit4] 2> 509614 WARN (OverseerAutoScalingTriggerThread-98979866990215183-127.0.0.1:60675_solr-n_0000000001) [n:127.0.0.1:60675_solr ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 509618 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@7bb4d024{/solr,null,UNAVAILABLE}
[junit4] 2> 509619 INFO (zkCallback-598-thread-2-processing-n:127.0.0.1:51679_solr) [n:127.0.0.1:51679_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:51679_solr
[junit4] 2> 509621 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 509622 INFO (zkCallback-598-thread-2-processing-n:127.0.0.1:51679_solr) [n:127.0.0.1:51679_solr ] o.a.s.c.Overseer Overseer (id=98979866990215178-127.0.0.1:51679_solr-n_0000000003) starting
[junit4] 2> 509623 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@4f4535da{/solr,null,AVAILABLE}
[junit4] 2> 509624 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@157d9d2a{HTTP/1.1,[http/1.1]}{127.0.0.1:60675}
[junit4] 2> 509624 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.e.j.s.Server Started @516542ms
[junit4] 2> 509624 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=60675}
[junit4] 2> 509624 ERROR (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 509625 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.2.0
[junit4] 2> 509625 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 509625 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 509625 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-11-10T11:22:00.164Z
[junit4] 2> 509629 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 509638 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:53479/solr
[junit4] 2> 509666 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [n:127.0.0.1:60675_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 509671 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [n:127.0.0.1:60675_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 509674 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [n:127.0.0.1:60675_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:60675_solr
[junit4] 2> 509679 INFO (zkCallback-598-thread-2-processing-n:127.0.0.1:51679_solr) [n:127.0.0.1:51679_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 509680 INFO (zkCallback-614-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 509680 INFO (zkCallback-596-thread-1-processing-n:127.0.0.1:38835_solr) [n:127.0.0.1:38835_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 509681 INFO (zkCallback-621-thread-1-processing-n:127.0.0.1:60675_solr) [n:127.0.0.1:60675_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 509782 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [n:127.0.0.1:60675_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_60675.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1cf536c4
[junit4] 2> 509791 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [n:127.0.0.1:60675_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_60675.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1cf536c4
[junit4] 2> 509791 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [n:127.0.0.1:60675_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_60675.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1cf536c4
[junit4] 2> 509793 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [n:127.0.0.1:60675_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.NodeLostTriggerTest_410B5F7EBEC2D368-001/tempDir-001/node1/.
[junit4] 2> 514832 INFO (TEST-NodeLostTriggerTest.testTrigger-seed#[410B5F7EBEC2D368]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testTrigger
[junit4] 2> 514848 INFO (TEST-NodeLostTriggerTest.testRestoreState-seed#[410B5F7EBEC2D368]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testRestoreState
[junit4] 2> 514848 INFO (TEST-NodeLostTriggerTest.testRestoreState-seed#[410B5F7EBEC2D368]) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 514848 INFO (TEST-NodeLostTriggerTest.testRestoreState-seed#[410B5F7EBEC2D368]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6194dc3d{/solr,null,AVAILABLE}
[junit4] 2> 514848 INFO (TEST-NodeLostTriggerTest.testRestoreState-seed#[410B5F7EBEC2D368]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@7198d356{HTTP/1.1,[http/1.1]}{127.0.0.1:50554}
[junit4] 2> 514848 INFO (TEST-NodeLostTriggerTest.testRestoreState-seed#[410B5F7EBEC2D368]) [ ] o.e.j.s.Server Started @521767ms
[junit4] 2> 514848 INFO (TEST-NodeLostTriggerTest.testRestoreState-seed#[410B5F7EBEC2D368]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=50554}
[junit4] 2> 514848 ERROR (TEST-NodeLostTriggerTest.testRestoreState-seed#[410B5F7EBEC2D368]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 514848 INFO (TEST-NodeLostTriggerTest.testRestoreState-seed#[410B5F7EBEC2D368]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.2.0
[junit4] 2> 514848 INFO (TEST-NodeLostTriggerTest.testRestoreState-seed#[410B5F7EBEC2D368]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 514848 INFO (TEST-NodeLostTriggerTest.testRestoreState-seed#[410B5F7EBEC2D368]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 514848 INFO (TEST-NodeLostTriggerTest.testRestoreState-seed#[410B5F7EBEC2D368]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-11-10T11:22:05.387Z
[junit4] 2> 514854 INFO (TEST-NodeLostTriggerTest.testRestoreState-seed#[410B5F7EBEC2D368]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 514861 INFO (TEST-NodeLostTriggerTest.testRestoreState-seed#[410B5F7EBEC2D368]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:53479/solr
[junit4] 2> 514879 INFO (TEST-NodeLostTriggerTest.testRestoreState-seed#[410B5F7EBEC2D368]) [n:127.0.0.1:50554_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 514882 INFO (TEST-NodeLostTriggerTest.testRestoreState-seed#[410B5F7EBEC2D368]) [n:127.0.0.1:50554_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 514884 INFO (TEST-NodeLostTriggerTest.testRestoreState-seed#[410B5F7EBEC2D368]) [n:127.0.0.1:50554_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50554_solr
[junit4] 2> 514886 INFO (zkCallback-614-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 514886 INFO (zkCallback-621-thread-1-processing-n:127.0.0.1:60675_solr) [n:127.0.0.1:60675_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 514886 INFO (zkCallback-596-thread-1-processing-n:127.0.0.1:38835_solr) [n:127.0.0.1:38835_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 514886 INFO (zkCallback-598-thread-2-processing-n:127.0.0.1:51679_solr) [n:127.0.0.1:51679_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 514887 INFO (zkCallback-627-thread-1-processing-n:127.0.0.1:50554_solr) [n:127.0.0.1:50554_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 515017 INFO (TEST-NodeLostTriggerTest.testRestoreState-seed#[410B5F7EBEC2D368]) [n:127.0.0.1:50554_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_50554.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1cf536c4
[junit4] 2> 515023 INFO (TEST-NodeLostTriggerTest.testRestoreState-seed#[410B5F7EBEC2D368]) [n:127.0.0.1:50554_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_50554.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1cf536c4
[junit4] 2> 515024 INFO (TEST-NodeLostTriggerTest.testRestoreState-seed#[410B5F7EBEC2D368]) [n:127.0.0.1:50554_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_50554.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1cf536c4
[junit4] 2> 515025 INFO (TEST-NodeLostTriggerTest.testRestoreState-seed#[410B5F7EBEC2D368]) [n:127.0.0.1:50554_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.NodeLostTriggerTest_410B5F7EBEC2D368-001/tempDir-001/node6/.
[junit4] 2> 515058 INFO (TEST-NodeLostTriggerTest.testRestoreState-seed#[410B5F7EBEC2D368]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@7198d356{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 515058 INFO (TEST-NodeLostTriggerTest.testRestoreState-seed#[410B5F7EBEC2D368]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=120148703
[junit4] 2> 515059 INFO (TEST-NodeLostTriggerTest.testRestoreState-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 515059 INFO (TEST-NodeLostTriggerTest.testRestoreState-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@53abd5aa: rootName = solr_50554, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@365647a1
[junit4] 2> 515064 INFO (TEST-NodeLostTriggerTest.testRestoreState-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 515064 INFO (TEST-NodeLostTriggerTest.testRestoreState-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1f53262e: rootName = solr_50554, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@71bcb52e
[junit4] 2> 515070 INFO (TEST-NodeLostTriggerTest.testRestoreState-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 515070 INFO (TEST-NodeLostTriggerTest.testRestoreState-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@e756b49: rootName = solr_50554, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@3c73d9ff
[junit4] 2> 515071 INFO (TEST-NodeLostTriggerTest.testRestoreState-seed#[410B5F7EBEC2D368]) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:50554_solr
[junit4] 2> 515073 INFO (zkCallback-598-thread-2-processing-n:127.0.0.1:51679_solr) [n:127.0.0.1:51679_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 515073 INFO (zkCallback-614-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 515074 INFO (zkCallback-621-thread-1-processing-n:127.0.0.1:60675_solr) [n:127.0.0.1:60675_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 515074 INFO (zkCallback-596-thread-1-processing-n:127.0.0.1:38835_solr) [n:127.0.0.1:38835_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 515074 INFO (zkCallback-627-thread-1-processing-n:127.0.0.1:50554_solr) [n:127.0.0.1:50554_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 515074 INFO (TEST-NodeLostTriggerTest.testRestoreState-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 515087 INFO (TEST-NodeLostTriggerTest.testRestoreState-seed#[410B5F7EBEC2D368]) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 515089 INFO (TEST-NodeLostTriggerTest.testRestoreState-seed#[410B5F7EBEC2D368]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@6194dc3d{/solr,null,UNAVAILABLE}
[junit4] 2> 518096 INFO (TEST-NodeLostTriggerTest.testRestoreState-seed#[410B5F7EBEC2D368]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testRestoreState
[junit4] 2> 518120 INFO (TEST-NodeLostTriggerTest.testListenerAcceptance-seed#[410B5F7EBEC2D368]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testListenerAcceptance
[junit4] 2> 518122 INFO (TEST-NodeLostTriggerTest.testListenerAcceptance-seed#[410B5F7EBEC2D368]) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 518123 INFO (TEST-NodeLostTriggerTest.testListenerAcceptance-seed#[410B5F7EBEC2D368]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@77b2bfc3{/solr,null,AVAILABLE}
[junit4] 2> 518124 INFO (TEST-NodeLostTriggerTest.testListenerAcceptance-seed#[410B5F7EBEC2D368]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@41f04b51{HTTP/1.1,[http/1.1]}{127.0.0.1:39669}
[junit4] 2> 518124 INFO (TEST-NodeLostTriggerTest.testListenerAcceptance-seed#[410B5F7EBEC2D368]) [ ] o.e.j.s.Server Started @525043ms
[junit4] 2> 518124 INFO (TEST-NodeLostTriggerTest.testListenerAcceptance-seed#[410B5F7EBEC2D368]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=39669}
[junit4] 2> 518124 ERROR (TEST-NodeLostTriggerTest.testListenerAcceptance-seed#[410B5F7EBEC2D368]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 518124 INFO (TEST-NodeLostTriggerTest.testListenerAcceptance-seed#[410B5F7EBEC2D368]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.2.0
[junit4] 2> 518124 INFO (TEST-NodeLostTriggerTest.testListenerAcceptance-seed#[410B5F7EBEC2D368]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 518124 INFO (TEST-NodeLostTriggerTest.testListenerAcceptance-seed#[410B5F7EBEC2D368]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 518124 INFO (TEST-NodeLostTriggerTest.testListenerAcceptance-seed#[410B5F7EBEC2D368]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-11-10T11:22:08.663Z
[junit4] 2> 518143 INFO (TEST-NodeLostTriggerTest.testListenerAcceptance-seed#[410B5F7EBEC2D368]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 518152 INFO (TEST-NodeLostTriggerTest.testListenerAcceptance-seed#[410B5F7EBEC2D368]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:53479/solr
[junit4] 2> 518169 INFO (TEST-NodeLostTriggerTest.testListenerAcceptance-seed#[410B5F7EBEC2D368]) [n:127.0.0.1:39669_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 518172 INFO (TEST-NodeLostTriggerTest.testListenerAcceptance-seed#[410B5F7EBEC2D368]) [n:127.0.0.1:39669_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 518175 INFO (TEST-NodeLostTriggerTest.testListenerAcceptance-seed#[410B5F7EBEC2D368]) [n:127.0.0.1:39669_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39669_solr
[junit4] 2> 518190 INFO (zkCallback-596-thread-1-processing-n:127.0.0.1:38835_solr) [n:127.0.0.1:38835_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 518190 INFO (zkCallback-614-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 518190 INFO (zkCallback-598-thread-2-processing-n:127.0.0.1:51679_solr) [n:127.0.0.1:51679_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 518190 INFO (zkCallback-621-thread-1-processing-n:127.0.0.1:60675_solr) [n:127.0.0.1:60675_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 518191 INFO (zkCallback-633-thread-1-processing-n:127.0.0.1:39669_solr) [n:127.0.0.1:39669_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 518272 INFO (TEST-NodeLostTriggerTest.testListenerAcceptance-seed#[410B5F7EBEC2D368]) [n:127.0.0.1:39669_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39669.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1cf536c4
[junit4] 2> 518281 INFO (TEST-NodeLostTriggerTest.testListenerAcceptance-seed#[410B5F7EBEC2D368]) [n:127.0.0.1:39669_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39669.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1cf536c4
[junit4] 2> 518281 INFO (TEST-NodeLostTriggerTest.testListenerAcceptance-seed#[410B5F7EBEC2D368]) [n:127.0.0.1:39669_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39669.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1cf536c4
[junit4] 2> 518282 INFO (TEST-NodeLostTriggerTest.testListenerAcceptance-seed#[410B5F7EBEC2D368]) [n:127.0.0.1:39669_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.NodeLostTriggerTest_410B5F7EBEC2D368-001/tempDir-001/node7/.
[junit4] 2> 518341 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15fa5aa23de001b, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 518343 INFO (TEST-NodeLostTriggerTest.testListenerAcceptance-seed#[410B5F7EBEC2D368]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@41f04b51{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 518343 INFO (TEST-NodeLostTriggerTest.testListenerAcceptance-seed#[410B5F7EBEC2D368]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=741895654
[junit4] 2> 518343 INFO (TEST-NodeLostTriggerTest.testListenerAcceptance-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 518343 INFO (TEST-NodeLostTriggerTest.testListenerAcceptance-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@710fe34d: rootName = solr_39669, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@46a5141c
[junit4] 2> 518352 INFO (TEST-NodeLostTriggerTest.testListenerAcceptance-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 518352 INFO (TEST-NodeLostTriggerTest.testListenerAcceptance-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@426f2893: rootName = solr_39669, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@71bcb52e
[junit4] 2> 518359 INFO (TEST-NodeLostTriggerTest.testListenerAcceptance-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 518359 INFO (TEST-NodeLostTriggerTest.testListenerAcceptance-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@56f5645e: rootName = solr_39669, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@3c73d9ff
[junit4] 2> 518371 INFO (TEST-NodeLostTriggerTest.testListenerAcceptance-seed#[410B5F7EBEC2D368]) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:39669_solr
[junit4] 2> 518373 INFO (zkCallback-633-thread-1-processing-n:127.0.0.1:39669_solr) [n:127.0.0.1:39669_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 518375 INFO (zkCallback-614-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 518375 INFO (TEST-NodeLostTriggerTest.testListenerAcceptance-seed#[410B5F7EBEC2D368]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 518376 INFO (TEST-NodeLostTriggerTest.testListenerAcceptance-seed#[410B5F7EBEC2D368]) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 518387 INFO (TEST-NodeLostTriggerTest.testListenerAcceptance-seed#[410B5F7EBEC2D368]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@77b2bfc3{/solr,null,UNAVAILABLE}
[junit4] 2> 518392 INFO (TEST-NodeLostTriggerTest.testListenerAcceptance-seed#[410B5F7EBEC2D368]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testListenerAcceptance
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=NodeLostTriggerTest -Dtests.method=testListenerAcceptance -Dtests.seed=410B5F7EBEC2D368 -Dtests.slow=true -Dtests.locale=nl-BE -Dtests.timezone=America/Argentina/Cordoba -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[junit4] FAILURE 0.30s J1 | NodeLostTriggerTest.testListenerAcceptance <<<
[junit4] > Throwable #1: java.lang.AssertionError: expected:<1> but was:<0>
[junit4] > at __randomizedtesting.SeedInfo.seed([410B5F7EBEC2D368:50BF0599074BC79E]:0)
[junit4] > at org.apache.solr.cloud.autoscaling.NodeLostTriggerTest.testListenerAcceptance(NodeLostTriggerTest.java:253)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 518403 INFO (zkCallback-621-thread-1-processing-n:127.0.0.1:60675_solr) [n:127.0.0.1:60675_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 518403 INFO (zkCallback-596-thread-1-processing-n:127.0.0.1:38835_solr) [n:127.0.0.1:38835_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 518406 INFO (jetty-closer-578-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@3f1dae13{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 518406 INFO (jetty-closer-578-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1168652164
[junit4] 2> 518406 INFO (jetty-closer-578-thread-3) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@60444ef3{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 518406 INFO (jetty-closer-578-thread-3) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=613170123
[junit4] 2> 518407 INFO (jetty-closer-578-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 518407 INFO (jetty-closer-578-thread-3) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@7babe261: rootName = solr_38835, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@5e63df1b
[junit4] 2> 518411 INFO (jetty-closer-578-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 518412 INFO (jetty-closer-578-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@30390b77: rootName = solr_51679, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@60a7ce4f
[junit4] 2> 518412 INFO (zkCallback-598-thread-1-processing-n:127.0.0.1:51679_solr) [n:127.0.0.1:51679_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 518413 INFO (jetty-closer-578-thread-2) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@157d9d2a{HTTP/1.1,[http/1.1]}{127.0.0.1:60675}
[junit4] 2> 518414 INFO (jetty-closer-578-thread-2) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1152939530
[junit4] 2> 518414 INFO (jetty-closer-578-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 518414 INFO (jetty-closer-578-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4d97d9ae: rootName = solr_60675, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@3a9084e7
[junit4] 2> 518422 INFO (jetty-closer-578-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 518422 INFO (jetty-closer-578-thread-3) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@498a98cb: rootName = solr_38835, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@71bcb52e
[junit4] 2> 518465 INFO (jetty-closer-578-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 518465 INFO (jetty-closer-578-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@2f10eea9: rootName = solr_51679, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@71bcb52e
[junit4] 2> 518469 INFO (jetty-closer-578-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 518469 INFO (jetty-closer-578-thread-3) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@37e68290: rootName = solr_38835, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@3c73d9ff
[junit4] 2> 518474 INFO (jetty-closer-578-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 518475 INFO (jetty-closer-578-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@b3b3f49: rootName = solr_60675, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@71bcb52e
[junit4] 2> 518485 INFO (jetty-closer-578-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 518485 INFO (jetty-closer-578-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@19665307: rootName = solr_51679, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@3c73d9ff
[junit4] 2> 518486 INFO (jetty-closer-578-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 518486 INFO (jetty-closer-578-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@37294058: rootName = solr_60675, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@3c73d9ff
[junit4] 2> 518488 INFO (jetty-closer-578-thread-1) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:51679_solr
[junit4] 2> 518488 INFO (jetty-closer-578-thread-3) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:38835_solr
[junit4] 2> 518489 INFO (jetty-closer-578-thread-2) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:60675_solr
[junit4] 2> 518490 INFO (jetty-closer-578-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 518490 INFO (jetty-closer-578-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 518491 INFO (jetty-closer-578-thread-1) [ ] o.a.s.c.Overseer Overseer (id=98979866990215178-127.0.0.1:51679_solr-n_0000000003) closing
[junit4] 2> 518491 WARN (OverseerAutoScalingTriggerThread-98979866990215178-127.0.0.1:51679_solr-n_0000000003) [n:127.0.0.1:51679_solr ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 518495 INFO (OverseerStateUpdate-98979866990215178-127.0.0.1:51679_solr-n_0000000003) [n:127.0.0.1:51679_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:51679_solr
[junit4] 2> 518495 INFO (zkCallback-598-thread-1-processing-n:127.0.0.1:51679_solr) [n:127.0.0.1:51679_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (1)
[junit4] 2> 518495 INFO (jetty-closer-578-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 518496 INFO (jetty-closer-578-thread-3) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 518501 INFO (zkCallback-621-thread-1-processing-n:127.0.0.1:60675_solr) [n:127.0.0.1:60675_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (1)
[junit4] 2> 518502 INFO (zkCallback-596-thread-1-processing-n:127.0.0.1:38835_solr) [n:127.0.0.1:38835_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (1)
[junit4] 2> 518503 INFO (jetty-closer-578-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 518503 INFO (jetty-closer-578-thread-2) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 518503 INFO (jetty-closer-578-thread-3) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@41ec3ac6{/solr,null,UNAVAILABLE}
[junit4] 2> 518506 INFO (zkCallback-621-thread-3-processing-n:127.0.0.1:60675_solr) [n:127.0.0.1:60675_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 518507 INFO (zkCallback-621-thread-2-processing-n:127.0.0.1:60675_solr) [n:127.0.0.1:60675_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:60675_solr
[junit4] 2> 520004 WARN (zkCallback-598-thread-1-processing-n:127.0.0.1:51679_solr) [n:127.0.0.1:51679_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 520004 INFO (jetty-closer-578-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@7a196b86{/solr,null,UNAVAILABLE}
[junit4] 2> 520008 WARN (zkCallback-621-thread-1-processing-n:127.0.0.1:60675_solr) [n:127.0.0.1:60675_solr ] o.a.s.c.ZkController Unable to register nodeLost path for 127.0.0.1:38835_solr
[junit4] 2> org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /autoscaling/nodeLost/127.0.0.1:38835_solr
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.lambda$create$7(SolrZkClient.java:357)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.create(SolrZkClient.java:357)
[junit4] 2> at org.apache.solr.cloud.ZkController.lambda$registerLiveNodesListener$2(ZkController.java:879)
[junit4] 2> at org.apache.solr.common.cloud.ZkStateReader.lambda$refreshLiveNodes$1(ZkStateReader.java:749)
[junit4] 2> at java.util.concurrent.ConcurrentHashMap$KeySetView.forEach(ConcurrentHashMap.java:4649)
[junit4] 2> at org.apache.solr.common.cloud.ZkStateReader.refreshLiveNodes(ZkStateReader.java:748)
[junit4] 2> at org.apache.solr.common.cloud.ZkStateReader.access$1000(ZkStateReader.java:72)
[junit4] 2> at org.apache.solr.common.cloud.ZkStateReader$LiveNodeWatcher.refreshAndWatch(ZkStateReader.java:1154)
[junit4] 2> at org.apache.solr.common.cloud.ZkStateReader$LiveNodeWatcher.process(ZkStateReader.java:1149)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$1.lambda$process$0(SolrZkClient.java:262)
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 520008 WARN (zkCallback-621-thread-1-processing-n:127.0.0.1:60675_solr) [n:127.0.0.1:60675_solr ] o.a.s.c.ZkController Unable to register nodeLost path for 127.0.0.1:51679_solr
[junit4] 2> org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /autoscaling/nodeLost/127.0.0.1:51679_solr
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.lambda$create$7(SolrZkClient.java:357)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.create(SolrZkClient.java:357)
[junit4] 2> at org.apache.solr.cloud.ZkController.lambda$registerLiveNodesListener$2(ZkController.java:879)
[junit4] 2> at org.apache.solr.common.cloud.ZkStateReader.lambda$refreshLiveNodes$1(ZkStateReader.java:749)
[junit4] 2> at java.util.concurrent.ConcurrentHashMap$KeySetView.forEach(ConcurrentHashMap.java:4649)
[junit4] 2> at org.apache.solr.common.cloud.ZkStateReader.refreshLiveNodes(ZkStateReader.java:748)
[junit4] 2> at org.apache.solr.common.cloud.ZkStateReader.access$1000(ZkStateReader.java:72)
[junit4] 2> at org.apache.solr.common.cloud.ZkStateReader$LiveNodeWatcher.refreshAndWatch(ZkStateReader.java:1154)
[junit4] 2> at org.apache.solr.common.cloud.ZkStateReader$LiveNodeWatcher.process(ZkStateReader.java:1149)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$1.lambda$process$0(SolrZkClient.java:262)
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 520008 INFO (jetty-closer-578-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@4f4535da{/solr,null,UNAVAILABLE}
[junit4] 2> 520012 ERROR (SUITE-NodeLostTriggerTest-seed#[410B5F7EBEC2D368]-worker) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
[junit4] 2> 520013 INFO (SUITE-NodeLostTriggerTest-seed#[410B5F7EBEC2D368]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:53479 53479
[junit4] 2> 520078 INFO (Thread-578) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:53479 53479
[junit4] 2> 520078 WARN (Thread-578) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 9 /solr/aliases.json
[junit4] 2> 9 /solr/clusterprops.json
[junit4] 2> 8 /solr/security.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 9 /solr/clusterstate.json
[junit4] 2> 3 /solr/autoscaling.json
[junit4] 2> 2 /solr/overseer_elect/election/98979866990215188-127.0.0.1:60675_solr-n_0000000005
[junit4] 2> 2 /solr/overseer_elect/election/98979866990215183-127.0.0.1:60675_solr-n_0000000001
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 9 /solr/live_nodes
[junit4] 2> 9 /solr/collections
[junit4] 2> 3 /solr/overseer/queue
[junit4] 2> 3 /solr/autoscaling/events/.auto_add_replicas
[junit4] 2> 3 /solr/overseer/queue-work
[junit4] 2> 3 /solr/overseer/collection-queue-work
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at: /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.NodeLostTriggerTest_410B5F7EBEC2D368-001
[junit4] 2> Nov 10, 2017 11:22:10 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {}, docValues:{}, maxPointsInLeafNode=1585, maxMBSortInHeap=5.947534163339655, sim=RandomSimilarity(queryNorm=false): {}, locale=nl-BE, timezone=America/Argentina/Cordoba
[junit4] 2> NOTE: SunOS 5.11 amd64/Oracle Corporation 1.8.0_152 (64-bit)/cpus=3,threads=1,free=166810576,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [TestNumericRangeQuery64, ClassificationUpdateProcessorIntegrationTest, DeleteReplicaTest, IgnoreCommitOptimizeUpdateProcessorFactoryTest, TermVectorComponentTest, DeleteStatusTest, TestAuthorizationFramework, TestRandomFaceting, DocValuesNotIndexedTest, ZkNodePropsTest, TestEmbeddedSolrServerConstructors, TestFunctionQuery, TestTrie, TestFieldCacheSortRandom, TestStressVersions, SSLMigrationTest, CloudExitableDirectoryReaderTest, UpdateLogTest, ShardSplitTest, TestMultiValuedNumericRangeQuery, TestMacros, PropertiesRequestHandlerTest, SimplePostToolTest, SearchHandlerTest, PreAnalyzedUpdateProcessorTest, BadCopyFieldTest, DistributedFacetExistsSmallTest, ExecutePlanActionTest, BigEndianAscendingWordSerializerTest, AutoscalingHistoryHandlerTest, LukeRequestHandlerTest, TestRTimerTree, UpdateRequestProcessorFactoryTest, TestCopyFieldCollectionResource, TestFaceting, NodeLostTriggerTest]
[junit4] Completed [79/748 (1!)] on J1 in 19.30s, 4 tests, 1 failure <<< FAILURES!
[...truncated 49537 lines...]