You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2018/04/04 02:58:52 UTC
[JENKINS] Lucene-Solr-Tests-7.3 - Build # 48 - Unstable
Build: https://builds.apache.org/job/Lucene-Solr-Tests-7.3/48/
3 tests failed.
FAILED: org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration.testNodeAddedTriggerRestoreState
Error Message:
The trigger did not fire at all
Stack Trace:
java.lang.AssertionError: The trigger did not fire at all
at __randomizedtesting.SeedInfo.seed([CA6E4E49ADA1E82A:4253C73697610987]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration.testNodeAddedTriggerRestoreState(TestTriggerIntegration.java:368)
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)
FAILED: org.apache.solr.client.solrj.TestLBHttpSolrClient.testReliability
Error Message:
No live SolrServers available to handle this request
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request
at __randomizedtesting.SeedInfo.seed([D9AF7EB640850D97:1867A3F0E1E3DC3E]:0)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:726)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:638)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:194)
at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:942)
at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:957)
at org.apache.solr.client.solrj.TestLBHttpSolrClient.testReliability(TestLBHttpSolrClient.java:219)
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)
Caused by: org.apache.solr.client.solrj.SolrServerException: Timeout occured while waiting response from server at: https://127.0.0.1:35011/solr/collection1
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:654)
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.request(LBHttpSolrClient.java:663)
... 44 more
Caused by: java.net.SocketTimeoutException: Read timed out
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
at java.net.SocketInputStream.read(SocketInputStream.java:171)
at java.net.SocketInputStream.read(SocketInputStream.java:141)
at sun.security.ssl.InputRecord.readFully(InputRecord.java:465)
at sun.security.ssl.InputRecord.read(InputRecord.java:503)
at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:983)
at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:940)
at sun.security.ssl.AppInputStream.read(AppInputStream.java:105)
at org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:137)
at org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:153)
at org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:282)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:138)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:56)
at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:259)
at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:163)
at org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:165)
at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:273)
at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:125)
at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:272)
at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:185)
at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:111)
at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56)
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:542)
... 47 more
FAILED: junit.framework.TestSuite.org.apache.solr.client.solrj.io.stream.JDBCStreamTest
Error Message:
Error from server at http://127.0.0.1:46079/solr: KeeperErrorCode = NoNode for /overseer/collection-queue-work/qnr-0000000000
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:46079/solr: KeeperErrorCode = NoNode for /overseer/collection-queue-work/qnr-0000000000
at __randomizedtesting.SeedInfo.seed([D9AF7EB640850D97]:0)
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:643)
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.sendRequest(CloudSolrClient.java:1105)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:885)
at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:818)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:194)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:211)
at org.apache.solr.client.solrj.io.stream.JDBCStreamTest.setupCluster(JDBCStreamTest.java:76)
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$6.evaluate(RandomizedRunner.java:874)
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 12131 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration
[junit4] 2> 0 INFO (SUITE-TestTriggerIntegration-seed#[CA6E4E49ADA1E82A]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.3/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.sim.TestTriggerIntegration_CA6E4E49ADA1E82A-001/init-core-data-001
[junit4] 2> 726 INFO (SUITE-TestTriggerIntegration-seed#[CA6E4E49ADA1E82A]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 980 INFO (SUITE-TestTriggerIntegration-seed#[CA6E4E49ADA1E82A]-worker) [ ] o.e.j.u.log Logging initialized @13055ms to org.eclipse.jetty.util.log.Slf4jLog
[junit4] 2> 998 INFO (SUITE-TestTriggerIntegration-seed#[CA6E4E49ADA1E82A]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 1309 INFO (SUITE-TestTriggerIntegration-seed#[CA6E4E49ADA1E82A]-worker) [ ] o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find system property or JNDI)
[junit4] IGNOR/A 0.00s J0 | TestTriggerIntegration.testNodeLostTriggerRestoreState
[junit4] > Assumption #1: 'badapple' test group is disabled (@BadApple(bugUrl=https://issues.apache.org/jira/browse/SOLR-12028))
[junit4] 2> 1996 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeAddedTriggerRestoreState
[junit4] 2> 2086 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 2087 DEBUG (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 2146 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
[junit4] 2> 2163 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
[junit4] 2> 2182 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 2775 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
[junit4] 2> 2775 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion -1
[junit4] 2> 2776 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 2784 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 2801 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
[junit4] 2> 2882 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 2882 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 1
[junit4] 2> 2883 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 2883 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 2883 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 2901 DEBUG (ScheduledTrigger-6-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 2922 DEBUG (ScheduledTrigger-6-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 2975 DEBUG (ScheduledTrigger-6-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3000 DEBUG (ScheduledTrigger-6-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3036 DEBUG (ScheduledTrigger-6-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3073 DEBUG (ScheduledTrigger-6-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3101 DEBUG (simCloudManagerPool-5-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3109 DEBUG (ScheduledTrigger-6-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3137 DEBUG (simCloudManagerPool-5-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 3140 DEBUG (simCloudManagerPool-5-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
[junit4] 2> 3140 DEBUG (simCloudManagerPool-5-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_restore_trigger instantiated with properties: {event=nodeAdded, waitFor=5, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestTriggerAction}], enabled=true}
[junit4] 2> 3140 DEBUG (simCloudManagerPool-5-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
[junit4] 2> 3140 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 3140 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init
[junit4] 2> 3141 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 3146 DEBUG (ScheduledTrigger-6-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3219 DEBUG (ScheduledTrigger-6-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 3146 DEBUG (ScheduledTrigger-6-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_restore_trigger
[junit4] 2> 3220 DEBUG (ScheduledTrigger-6-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 3220 DEBUG (ScheduledTrigger-6-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10002_solr at time 5140888560842485
[junit4] 2> 3255 DEBUG (ScheduledTrigger-6-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 3272 DEBUG (ScheduledTrigger-6-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_restore_trigger
[junit4] 2> 3304 DEBUG (ScheduledTrigger-6-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 3292 DEBUG (ScheduledTrigger-6-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 3309 DEBUG (simCloudManagerPool-5-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3330 DEBUG (simCloudManagerPool-5-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4
[junit4] 2> 3330 DEBUG (simCloudManagerPool-5-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr, 127.0.0.1:10002_solr]
[junit4] 2> 3330 DEBUG (simCloudManagerPool-5-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_restore_trigger instantiated with properties: {event=nodeAdded, waitFor=0, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestTriggerAction}], enabled=true}
[junit4] 2> 3341 DEBUG (simCloudManagerPool-5-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr, 127.0.0.1:10002_solr]
[junit4] 2> 3341 DEBUG (ScheduledTrigger-6-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_restore_trigger
[junit4] 2> 3365 DEBUG (ScheduledTrigger-6-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 3365 DEBUG (ScheduledTrigger-6-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_restore_trigger firing registered processor for nodes: [127.0.0.1:10002_solr] added at times [5140888560842485], now=5140895811079985
[junit4] 2> 3366 DEBUG (ScheduledTrigger-6-thread-4) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"12439c647fb6f5T15c3qus8f0ezck17grlu6ga27",
[junit4] 2> "source":"node_added_restore_trigger",
[junit4] 2> "eventTime":5140888560842485,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[5140888560842485],
[junit4] 2> "nodeNames":["127.0.0.1:10002_solr"]}}
[junit4] 2> 3365 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4
[junit4] 2> 3367 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init
[junit4] 2> 3367 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger Adding node from marker path: 127.0.0.1:10002_solr
[junit4] 2> 3367 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 3369 DEBUG (ScheduledTrigger-6-thread-4) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, node_added_restore_trigger]
[junit4] 2> 3382 ERROR (ScheduledTrigger-6-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Unexpected exception in NodeAddedTrigger
[junit4] 2> org.apache.lucene.store.AlreadyClosedException: ScheduledTrigger node_added_restore_trigger has been closed.
[junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers$TriggerWrapper.enqueue(ScheduledTriggers.java:522)
[junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$add$4(ScheduledTriggers.java:276)
[junit4] 2> at org.apache.solr.cloud.autoscaling.NodeAddedTrigger.run(NodeAddedTrigger.java:164)
[junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers$TriggerWrapper.run(ScheduledTriggers.java:572)
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[junit4] 2> at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
[junit4] 2> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
[junit4] 2> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
[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> 3471 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeAddedTriggerRestoreState
[junit4] 2> 3562 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase
[junit4] 2>
[junit4] 2> 3562 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2> 3562 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############ FINAL CLUSTER STATS ############
[junit4] 2> 3562 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2>
[junit4] 2> 3562 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Live nodes: 3
[junit4] 2> 3564 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Empty nodes: 3
[junit4] 2> 3564 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Dead nodes: 0
[junit4] 2> 3566 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Collections: []
[junit4] 2> 3566 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Max replicas per node: 0
[junit4] 2> 3566 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Min replicas per node: 0
[junit4] 2> 3566 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Total replicas: 0
[junit4] 2> 3566 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Final Solr op counts ##########
[junit4] 2> 3589 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - autoscaling 2
[junit4] 2> 3589 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Autoscaling event counts ###########
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestTriggerIntegration -Dtests.method=testNodeAddedTriggerRestoreState -Dtests.seed=CA6E4E49ADA1E82A -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=fr -Dtests.timezone=Australia/Tasmania -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] FAILURE 1.95s J0 | TestTriggerIntegration.testNodeAddedTriggerRestoreState <<<
[junit4] > Throwable #1: java.lang.AssertionError: The trigger did not fire at all
[junit4] > at __randomizedtesting.SeedInfo.seed([CA6E4E49ADA1E82A:4253C73697610987]:0)
[junit4] > at org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration.testNodeAddedTriggerRestoreState(TestTriggerIntegration.java:368)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 3642 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeLostTrigger
[junit4] 2> 3642 DEBUG (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5
[junit4] 2> 3661 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5
[junit4] 2> 3662 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 3662 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3662 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion 5
[junit4] 2> 3678 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 3679 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Interrupted
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2014)
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2048)
[junit4] 2> at org.apache.solr.cloud.autoscaling.OverseerTriggerThread.run(OverseerTriggerThread.java:175)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 3680 DEBUG (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 3727 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
[junit4] 2> 3727 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 6
[junit4] 2> 3727 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10000_solr, 127.0.0.1:10002_solr]
[junit4] 2> 3727 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 6, lastZnodeVersion -1
[junit4] 2> 3728 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 6
[junit4] 2> 3736 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3736 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 6, lastZnodeVersion 6
[junit4] 2> 3736 DEBUG (ScheduledTrigger-9-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3771 DEBUG (ScheduledTrigger-9-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3796 DEBUG (ScheduledTrigger-9-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3824 DEBUG (ScheduledTrigger-9-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3825 DEBUG (simCloudManagerPool-8-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3826 DEBUG (simCloudManagerPool-8-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 7
[junit4] 2> 3844 DEBUG (simCloudManagerPool-8-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10000_solr, 127.0.0.1:10002_solr]
[junit4] 2> 3844 DEBUG (ScheduledTrigger-9-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3844 DEBUG (simCloudManagerPool-8-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10000_solr, 127.0.0.1:10002_solr]
[junit4] 2> 3845 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 7
[junit4] 2> 3845 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init
[junit4] 2> 3845 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3845 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 7, lastZnodeVersion 7
[junit4] 2> 3846 DEBUG (ScheduledTrigger-9-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 3865 DEBUG (ScheduledTrigger-9-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3865 DEBUG (ScheduledTrigger-9-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10002_solr
[junit4] 2> 3873 DEBUG (ScheduledTrigger-9-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 1
[junit4] 2> 3873 DEBUG (ScheduledTrigger-9-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10002_solr
[junit4] 2> 3885 DEBUG (ScheduledTrigger-9-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3893 DEBUG (ScheduledTrigger-9-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 1
[junit4] 2> 3894 DEBUG (ScheduledTrigger-9-thread-1) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10002_solr]
[junit4] 2> 3894 DEBUG (ScheduledTrigger-9-thread-1) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"1243a3fe04f3abT15c3qus8f0ezck17grlu6ga28",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":5140921201259435,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[5140921201259435],
[junit4] 2> "nodeNames":["127.0.0.1:10002_solr"]}}
[junit4] 2> 3894 DEBUG (ScheduledTrigger-9-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, node_lost_trigger]
[junit4] 2> 3918 DEBUG (AutoscalingActionExecutor-10-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"1243a3fe04f3abT15c3qus8f0ezck17grlu6ga28",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":5140921201259435,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[5140921201259435],
[junit4] 2> "_enqueue_time_":5140922252579535,
[junit4] 2> "nodeNames":["127.0.0.1:10002_solr"]}}
[junit4] 2> 3924 DEBUG (simCloudManagerPool-8-thread-3) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3924 DEBUG (simCloudManagerPool-8-thread-3) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 8
[junit4] 2> 3925 DEBUG (simCloudManagerPool-8-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10000_solr]
[junit4] 2> 3925 DEBUG (simCloudManagerPool-8-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10000_solr]
[junit4] 2> 3929 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 8
[junit4] 2> 3939 DEBUG (AutoscalingActionExecutor-10-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 3939 DEBUG (AutoscalingActionExecutor-10-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_lost_trigger after 100ms
[junit4] 2> 3939 DEBUG (AutoscalingActionExecutor-10-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 1091 ms for event id=1243a3fe04f3abT15c3qus8f0ezck17grlu6ga28
[junit4] 2> 3946 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3946 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 8, lastZnodeVersion 8
[junit4] 2> 3978 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeLostTrigger
[junit4] 2> 3978 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase
[junit4] 2>
[junit4] 2> 3978 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2> 3978 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############ FINAL CLUSTER STATS ############
[junit4] 2> 3978 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2>
[junit4] 2> 3978 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Live nodes: 1
[junit4] 2> 3978 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Empty nodes: 1
[junit4] 2> 3979 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Dead nodes: 1
[junit4] 2> 3979 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## 127.0.0.1:10002_solr
[junit4] 2> 3979 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Collections: []
[junit4] 2> 3979 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Max replicas per node: 0
[junit4] 2> 3979 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Min replicas per node: 0
[junit4] 2> 3979 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Total replicas: 0
[junit4] 2> 3979 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Final Solr op counts ##########
[junit4] 2> 3979 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - autoscaling 2
[junit4] 2> 3979 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - update 2
[junit4] 2> 3979 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Autoscaling event counts ###########
[junit4] 2> 3980 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * Trigger: node_lost_trigger
[junit4] 2> 3981 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - STARTED 1
[junit4] 2> 3981 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - SUCCEEDED 1
[junit4] 2> 3984 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testTriggerThrottling
[junit4] 2> 3984 DEBUG (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 9
[junit4] 2> 3985 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 9
[junit4] 2> 3985 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 3985 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3985 DEBUG (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimNodeStateProvider - removing dead node values: 127.0.0.1:10002_solr
[junit4] 2> 3985 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 9, lastZnodeVersion 9
[junit4] 2> 3985 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 3986 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 3986 DEBUG (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 4076 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
[junit4] 2> 4077 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 10
[junit4] 2> 4077 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10000_solr, 127.0.0.1:10003_solr]
[junit4] 2> 4077 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 10, lastZnodeVersion -1
[junit4] 2> 4077 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 10
[junit4] 2> 4078 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 4078 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 10, lastZnodeVersion 10
[junit4] 2> 4079 DEBUG (ScheduledTrigger-12-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 4112 DEBUG (ScheduledTrigger-12-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 4149 DEBUG (ScheduledTrigger-12-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 4174 DEBUG (ScheduledTrigger-12-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 4183 DEBUG (simCloudManagerPool-11-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 4184 DEBUG (simCloudManagerPool-11-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 11
[junit4] 2> 4184 DEBUG (simCloudManagerPool-11-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10000_solr, 127.0.0.1:10003_solr]
[junit4] 2> 4184 DEBUG (simCloudManagerPool-11-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10000_solr, 127.0.0.1:10003_solr]
[junit4] 2> 4185 DEBUG (simCloudManagerPool-11-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=0, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$ThrottlingTesterAction}], enabled=true}
[junit4] 2> 4185 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 11
[junit4] 2> 4185 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init
[junit4] 2> 4185 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 11, lastZnodeVersion 11
[junit4] 2> 4207 DEBUG (ScheduledTrigger-12-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 4207 DEBUG (ScheduledTrigger-12-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 4207 DEBUG (ScheduledTrigger-12-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 4208 DEBUG (simCloudManagerPool-11-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 4209 DEBUG (simCloudManagerPool-11-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 12
[junit4] 2> 4209 DEBUG (simCloudManagerPool-11-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10000_solr, 127.0.0.1:10003_solr]
[junit4] 2> 4209 DEBUG (simCloudManagerPool-11-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger2 instantiated with properties: {event=nodeAdded, waitFor=0, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$ThrottlingTesterAction}], enabled=true}
[junit4] 2> 4209 DEBUG (simCloudManagerPool-11-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10000_solr, 127.0.0.1:10003_solr]
[junit4] 2> 4210 DEBUG (simCloudManagerPool-11-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10000_solr, 127.0.0.1:10003_solr]
[junit4] 2> 4210 DEBUG (simCloudManagerPool-11-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=0, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$ThrottlingTesterAction}], enabled=true}
[junit4] 2> 4210 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 12
[junit4] 2> 4210 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init
[junit4] 2> 4210 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 12, lastZnodeVersion 12
[junit4] 2> 4211 DEBUG (ScheduledTrigger-12-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2
[junit4] 2> 4211 DEBUG (ScheduledTrigger-12-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 4228 DEBUG (ScheduledTrigger-12-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 4230 DEBUG (ScheduledTrigger-12-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 4230 DEBUG (ScheduledTrigger-12-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 4247 DEBUG (ScheduledTrigger-12-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2
[junit4] 2> 4247 DEBUG (ScheduledTrigger-12-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 4247 DEBUG (ScheduledTrigger-12-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10004_solr at time 5140939884097285
[junit4] 2> 4247 DEBUG (ScheduledTrigger-12-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger2 firing registered processor for nodes: [127.0.0.1:10004_solr] added at times [5140939884097285], now=5140939888247335
[junit4] 2> 4247 DEBUG (ScheduledTrigger-12-thread-4) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"1243a8579a6f05T15c3qus8f0ezck17grlu6ga2b",
[junit4] 2> "source":"node_added_trigger2",
[junit4] 2> "eventTime":5140939884097285,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[5140939884097285],
[junit4] 2> "nodeNames":["127.0.0.1:10004_solr"]}}
[junit4] 2> 4247 DEBUG (ScheduledTrigger-12-thread-4) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, node_added_trigger2, node_added_trigger1]
[junit4] 2> 4249 DEBUG (AutoscalingActionExecutor-13-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"1243a8579a6f05T15c3qus8f0ezck17grlu6ga2b",
[junit4] 2> "source":"node_added_trigger2",
[junit4] 2> "eventTime":5140939884097285,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[5140939884097285],
[junit4] 2> "_enqueue_time_":5140939914308835,
[junit4] 2> "nodeNames":["127.0.0.1:10004_solr"]}}
[junit4] 2> 4283 DEBUG (ScheduledTrigger-12-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10004_solr at time 5140941689851985
[junit4] 2> 4283 DEBUG (ScheduledTrigger-12-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 firing registered processor for nodes: [127.0.0.1:10004_solr] added at times [5140941689851985], now=5140941699140435
[junit4] 2> 4283 DEBUG (ScheduledTrigger-12-thread-3) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"1243a8c33c1051T15c3qus8f0ezck17grlu6ga2d",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":5140941689851985,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[5140941689851985],
[junit4] 2> "nodeNames":["127.0.0.1:10004_solr"]}}
[junit4] 2> 4249 INFO (AutoscalingActionExecutor-13-thread-1) [ ] o.a.s.c.a.s.TestTriggerIntegration action executed from node_added_trigger2
[junit4] 2> 4366 DEBUG (AutoscalingActionExecutor-13-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 4366 DEBUG (AutoscalingActionExecutor-13-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger2 after 100ms
[junit4] 2> 4366 DEBUG (AutoscalingActionExecutor-13-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger1 after 100ms
[junit4] 2> 4367 DEBUG (AutoscalingActionExecutor-13-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 5869 ms for event id=1243a8579a6f05T15c3qus8f0ezck17grlu6ga2b
[junit4] 2> 4482 DEBUG (ScheduledTrigger-12-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 4482 DEBUG (ScheduledTrigger-12-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 4482 DEBUG (ScheduledTrigger-12-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 4482 DEBUG (ScheduledTrigger-12-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 firing registered processor for nodes: [127.0.0.1:10004_solr] added at times [5140941689851985], now=5140951655385485
[junit4] 2> 4483 DEBUG (ScheduledTrigger-12-thread-4) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"1243a8c33c1051T15c3qus8f0ezck17grlu6ga2g",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":5140941689851985,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[5140941689851985],
[junit4] 2> "nodeNames":["127.0.0.1:10004_solr"]}}
[junit4] 2> 4483 DEBUG (ScheduledTrigger-12-thread-4) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, node_added_trigger2, node_added_trigger1]
[junit4] 2> 4482 DEBUG (ScheduledTrigger-12-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2
[junit4] 2> 4484 DEBUG (ScheduledTrigger-12-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 4485 DEBUG (AutoscalingActionExecutor-13-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"1243a8c33c1051T15c3qus8f0ezck17grlu6ga2g",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":5140941689851985,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[5140941689851985],
[junit4] 2> "_enqueue_time_":5140951679096635,
[junit4] 2> "nodeNames":["127.0.0.1:10004_solr"]}}
[junit4] 2> 4485 INFO (AutoscalingActionExecutor-13-thread-1) [ ] o.a.s.c.a.s.TestTriggerIntegration last action at 5140942154443585 time = 5140951808276885
[junit4] 2> 4485 INFO (AutoscalingActionExecutor-13-thread-1) [ ] o.a.s.c.a.s.TestTriggerIntegration action executed from node_added_trigger1
[junit4] 2> 4544 DEBUG (AutoscalingActionExecutor-13-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 4544 DEBUG (AutoscalingActionExecutor-13-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger2 after 100ms
[junit4] 2> 4544 DEBUG (AutoscalingActionExecutor-13-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger1 after 100ms
[junit4] 2> 4545 DEBUG (AutoscalingActionExecutor-13-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 2973 ms for event id=1243a8c33c1051T15c3qus8f0ezck17grlu6ga2g
[junit4] 2> 4548 DEBUG (simCloudManagerPool-11-thread-8) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 4548 DEBUG (simCloudManagerPool-11-thread-8) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 13
[junit4] 2> 4549 DEBUG (simCloudManagerPool-11-thread-8) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10000_solr, 127.0.0.1:10003_solr]
[junit4] 2> 4549 DEBUG (simCloudManagerPool-11-thread-8) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger2 instantiated with properties: {event=nodeAdded, waitFor=0, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$ThrottlingTesterAction}], enabled=true}
[junit4] 2> 4549 DEBUG (simCloudManagerPool-11-thread-8) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10000_solr, 127.0.0.1:10003_solr]
[junit4] 2> 4549 DEBUG (simCloudManagerPool-11-thread-8) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10000_solr, 127.0.0.1:10003_solr]
[junit4] 2> 4549 DEBUG (simCloudManagerPool-11-thread-8) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=0, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$ThrottlingTesterAction}], enabled=true}
[junit4] 2> 4549 DEBUG (simCloudManagerPool-11-thread-8) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10000_solr, 127.0.0.1:10003_solr]
[junit4] 2> 4549 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 13
[junit4] 2> 4550 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init
[junit4] 2> 4550 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 13, lastZnodeVersion 13
[junit4] 2> 4550 DEBUG (ScheduledTrigger-12-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger1 with currently live nodes: 3
[junit4] 2> 4596 DEBUG (ScheduledTrigger-12-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger1 with currently live nodes: 3
[junit4] 2> 4601 DEBUG (simCloudManagerPool-11-thread-9) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 4602 DEBUG (simCloudManagerPool-11-thread-9) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 14
[junit4] 2> 4602 DEBUG (simCloudManagerPool-11-thread-9) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10000_solr, 127.0.0.1:10003_solr]
[junit4] 2> 4602 DEBUG (simCloudManagerPool-11-thread-9) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger2 instantiated with properties: {event=nodeAdded, waitFor=0, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$ThrottlingTesterAction}], enabled=true}
[junit4] 2> 4602 DEBUG (simCloudManagerPool-11-thread-9) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10000_solr, 127.0.0.1:10003_solr]
[junit4] 2> 4602 DEBUG (simCloudManagerPool-11-thread-9) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10000_solr, 127.0.0.1:10003_solr]
[junit4] 2> 4602 DEBUG (simCloudManagerPool-11-thread-9) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=0, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$ThrottlingTesterAction}], enabled=true}
[junit4] 2> 4602 DEBUG (simCloudManagerPool-11-thread-9) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10000_solr, 127.0.0.1:10003_solr]
[junit4] 2> 4602 DEBUG (simCloudManagerPool-11-thread-9) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10000_solr, 127.0.0.1:10003_solr]
[junit4] 2> 4603 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 14
[junit4] 2> 4603 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init
[junit4] 2> 4603 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 14, lastZnodeVersion 14
[junit4] 2> 4603 DEBUG (ScheduledTrigger-12-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger2 with currently live nodes: 3
[junit4] 2> 4706 DEBUG (ScheduledTrigger-12-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 4706 DEBUG (ScheduledTrigger-12-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10004_solr
[junit4] 2> 4707 DEBUG (ScheduledTrigger-12-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2
[junit4] 2> 4707 DEBUG (ScheduledTrigger-12-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 4707 DEBUG (ScheduledTrigger-12-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger2 with currently live nodes: 2
[junit4] 2> 4707 DEBUG (ScheduledTrigger-12-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 4707 DEBUG (ScheduledTrigger-12-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10004_solr
[junit4] 2> 4707 DEBUG (ScheduledTrigger-12-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 4707 DEBUG (ScheduledTrigger-12-thread-3) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10004_solr]
[junit4] 2> 4707 DEBUG (ScheduledTrigger-12-thread-3) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"1243adb2b398dfT15c3qus8f0ezck17grlu6ga2j",
[junit4] 2> "source":"node_lost_trigger2",
[junit4] 2> "eventTime":5140962887309535,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[5140962887309535],
[junit4] 2> "nodeNames":["127.0.0.1:10004_solr"]}}
[junit4] 2> 4707 DEBUG (ScheduledTrigger-12-thread-3) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [node_lost_trigger2, .auto_add_replicas, node_added_trigger2, node_lost_trigger1, node_added_trigger1]
[junit4] 2> 4709 DEBUG (ScheduledTrigger-12-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger1 with currently live nodes: 2
[junit4] 2> 4709 DEBUG (ScheduledTrigger-12-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10004_solr
[junit4] 2> 4709 DEBUG (ScheduledTrigger-12-thread-4) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10004_solr]
[junit4] 2> 4709 DEBUG (ScheduledTrigger-12-thread-4) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"1243adb8f505b7T15c3qus8f0ezck17grlu6ga2l",
[junit4] 2> "source":"node_lost_trigger1",
[junit4] 2> "eventTime":5140962992260535,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[5140962992260535],
[junit4] 2> "nodeNames":["127.0.0.1:10004_solr"]}}
[junit4] 2> 4724 DEBUG (AutoscalingActionExecutor-13-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"1243adb2b398dfT15c3qus8f0ezck17grlu6ga2j",
[junit4] 2> "source":"node_lost_trigger2",
[junit4] 2> "eventTime":5140962887309535,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[5140962887309535],
[junit4] 2> "_enqueue_time_":5140962908389035,
[junit4] 2> "nodeNames":["127.0.0.1:10004_solr"]}}
[junit4] 2> 4747 DEBUG (ScheduledTrigger-12-thread-4) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger processor for lost nodes: [127.0.0.1:10004_solr] is not ready, will try later
[junit4] 2> 4747 INFO (AutoscalingActionExecutor-13-thread-1) [ ] o.a.s.c.a.s.TestTriggerIntegration action executed from node_lost_trigger2
[junit4] 2> 4748 DEBUG (AutoscalingActionExecutor-13-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_lost_trigger2 after 100ms
[junit4] 2> 4748 DEBUG (AutoscalingActionExecutor-13-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 4748 DEBUG (AutoscalingActionExecutor-13-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger2 after 100ms
[junit4] 2> 4748 DEBUG (AutoscalingActionExecutor-13-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_lost_trigger1 after 100ms
[junit4] 2> 4748 DEBUG (AutoscalingActionExecutor-13-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger1 after 100ms
[junit4] 2> 4748 DEBUG (AutoscalingActionExecutor-13-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 1308 ms for event id=1243adb2b398dfT15c3qus8f0ezck17grlu6ga2j
[junit4] 2> 4848 DEBUG (ScheduledTrigger-12-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger2 with currently live nodes: 2
[junit4] 2> 4848 DEBUG (ScheduledTrigger-12-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2
[junit4] 2> 4848 DEBUG (ScheduledTrigger-12-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 4848 DEBUG (ScheduledTrigger-12-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger1 with currently live nodes: 2
[junit4] 2> 4848 DEBUG (ScheduledTrigger-12-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 4848 DEBUG (ScheduledTrigger-12-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 4849 DEBUG (ScheduledTrigger-12-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 4848 DEBUG (ScheduledTrigger-12-thread-2) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10004_solr]
[junit4] 2> 4849 DEBUG (ScheduledTrigger-12-thread-2) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"1243adb8f505b7T15c3qus8f0ezck17grlu6ga2o",
[junit4] 2> "source":"node_lost_trigger1",
[junit4] 2> "eventTime":5140962992260535,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[5140962992260535],
[junit4] 2> "nodeNames":["127.0.0.1:10004_solr"]}}
[junit4] 2> 4849 DEBUG (ScheduledTrigger-12-thread-2) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [node_lost_trigger2, .auto_add_replicas, node_added_trigger2, node_lost_trigger1, node_added_trigger1]
[junit4] 2> 4850 DEBUG (AutoscalingActionExecutor-13-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"1243adb8f505b7T15c3qus8f0ezck17grlu6ga2o",
[junit4] 2> "source":"node_lost_trigger1",
[junit4] 2> "eventTime":5140962992260535,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[5140962992260535],
[junit4] 2> "_enqueue_time_":5140969996927085,
[junit4] 2> "nodeNames":["127.0.0.1:10004_solr"]}}
[junit4] 2> 4850 INFO (AutoscalingActionExecutor-13-thread-1) [ ] o.a.s.c.a.s.TestTriggerIntegration last action at 5140964887877285 time = 5140970067116785
[junit4] 2> 4851 INFO (AutoscalingActionExecutor-13-thread-1) [ ] o.a.s.c.a.s.TestTriggerIntegration action executed from node_lost_trigger1
[junit4] 2> 4851 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testTriggerThrottling
[junit4] 2> 4851 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase
[junit4] 2>
[junit4] 2> 4851 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2> 4851 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############ FINAL CLUSTER STATS ############
[junit4] 2> 4851 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2>
[junit4] 2> 4851 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Live nodes: 2
[junit4] 2> 4851 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Empty nodes: 2
[junit4] 2> 4851 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Dead nodes: 1
[junit4] 2> 4851 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## 127.0.0.1:10004_solr
[junit4] 2> 4851 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Collections: []
[junit4] 2> 4851 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Max replicas per node: 0
[junit4] 2> 4851 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Min replicas per node: 0
[junit4] 2> 4851 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Total replicas: 0
[junit4] 2> 4851 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Final Solr op counts ##########
[junit4] 2> 4851 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - autoscaling 4
[junit4] 2> 4864 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - update 9
[junit4] 2> 4864 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Autoscaling event counts ###########
[junit4] 2> 4864 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * Trigger: node_added_trigger1
[junit4] 2> 4864 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - IGNORED 1
[junit4] 2> 4864 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - STARTED 1
[junit4] 2> 4864 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - SUCCEEDED 1
[junit4] 2> 4864 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * Trigger: node_added_trigger2
[junit4] 2> 4864 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - STARTED 1
[junit4] 2> 4864 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - SUCCEEDED 1
[junit4] 2> 4865 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * Trigger: node_lost_trigger1
[junit4] 2> 4865 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - IGNORED 1
[junit4] 2> 4865 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - STARTED 1
[junit4] 2> 4865 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * Trigger: node_lost_trigger2
[junit4] 2> 4865 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - STARTED 1
[junit4] 2> 4865 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - SUCCEEDED 1
[junit4] 2> 4909 DEBUG (AutoscalingActionExecutor-13-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_lost_trigger2 after 100ms
[junit4] 2> 4909 DEBUG (AutoscalingActionExecutor-13-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 4909 DEBUG (AutoscalingActionExecutor-13-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger2 after 100ms
[junit4] 2> 4909 DEBUG (AutoscalingActionExecutor-13-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_lost_trigger1 after 100ms
[junit4] 2> 4909 DEBUG (AutoscalingActionExecutor-13-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger1 after 100ms
[junit4] 2> 4909 DEBUG (AutoscalingActionExecutor-13-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 2932 ms for event id=1243adb8f505b7T15c3qus8f0ezck17grlu6ga2o
[junit4] 2> 4923 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeAddedTrigger
[junit4] 2> 4923 DEBUG (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 15
[junit4] 2> 4923 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 15
[junit4] 2> 4924 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 4924 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 4924 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 15, lastZnodeVersion 15
[junit4] 2> 4924 DEBUG (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimNodeStateProvider - removing dead node values: 127.0.0.1:10004_solr
[junit4] 2> 4924 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 4924 DEBUG (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 4945 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 4953 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
[junit4] 2> 4954 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 16
[junit4] 2> 4954 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10000_solr, 127.0.0.1:10003_solr]
[junit4] 2> 4954 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 16, lastZnodeVersion -1
[junit4] 2> 4954 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 16
[junit4] 2> 4973 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 4973 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 16, lastZnodeVersion 16
[junit4] 2> 4978 DEBUG (ScheduledTrigger-15-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 5026 DEBUG (ScheduledTrigger-15-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 5047 DEBUG (ScheduledTrigger-15-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 5104 DEBUG (ScheduledTrigger-15-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 5104 DEBUG (simCloudManagerPool-14-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 5105 DEBUG (simCloudManagerPool-14-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 17
[junit4] 2> 5105 DEBUG (simCloudManagerPool-14-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10000_solr, 127.0.0.1:10003_solr]
[junit4] 2> 5105 DEBUG (simCloudManagerPool-14-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10000_solr, 127.0.0.1:10003_solr]
[junit4] 2> 5105 DEBUG (simCloudManagerPool-14-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=2, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestTriggerAction}], enabled=true}
[junit4] 2> 5120 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 17
[junit4] 2> 5120 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init
[junit4] 2> 5120 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 17, lastZnodeVersion 17
[junit4] 2> 5120 DEBUG (ScheduledTrigger-15-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 5120 DEBUG (ScheduledTrigger-15-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 5121 DEBUG (ScheduledTrigger-15-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10005_solr at time 5140983568529235
[junit4] 2> 5140 DEBUG (ScheduledTrigger-15-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 5141 DEBUG (ScheduledTrigger-15-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 5141 DEBUG (ScheduledTrigger-15-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 5172 DEBUG (ScheduledTrigger-15-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 5173 DEBUG (ScheduledTrigger-15-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 5173 DEBUG (ScheduledTrigger-15-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 5173 DEBUG (ScheduledTrigger-15-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger firing registered processor for nodes: [127.0.0.1:10005_solr] added at times [5140983568529235], now=5140986184934085
[junit4] 2> 5173 DEBUG (ScheduledTrigger-15-thread-4) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"1243b28365f753T15c3qus8f0ezck17grlu6ga2r",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":5140983568529235,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[5140983568529235],
[junit4] 2> "nodeNames":["127.0.0.1:10005_solr"]}}
[junit4] 2> 5193 DEBUG (ScheduledTrigger-15-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 5229 DEBUG (ScheduledTrigger-15-thread-4) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, node_added_trigger]
[junit4] 2> 5250 DEBUG (AutoscalingActionExecutor-16-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"1243b28365f753T15c3qus8f0ezck17grlu6ga2r",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":5140983568529235,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[5140983568529235],
[junit4] 2> "_enqueue_time_":5140989028372685,
[junit4] 2> "nodeNames":["127.0.0.1:10005_solr"]}}
[junit4] 2> 5267 DEBUG (AutoscalingActionExecutor-16-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 5267 DEBUG (AutoscalingActionExecutor-16-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger after 100ms
[junit4] 2> 5267 DEBUG (AutoscalingActionExecutor-16-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 833 ms for event id=1243b28365f753T15c3qus8f0ezck17grlu6ga2r
[junit4] 2> 5269 DEBUG (simCloudManagerPool-14-thread-4) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 5302 DEBUG (simCloudManagerPool-14-thread-4) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 18
[junit4] 2> 5303 DEBUG (simCloudManagerPool-14-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10005_solr, 127.0.0.1:10000_solr, 127.0.0.1:10003_solr]
[junit4] 2> 5303 DEBUG (simCloudManagerPool-14-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10005_solr, 127.0.0.1:10000_solr, 127.0.0.1:10003_solr]
[junit4] 2> 5303 DEBUG (simCloudManagerPool-14-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=2, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestTriggerAction}], enabled=true}
[junit4] 2> 5319 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 18
[junit4] 2> 5319 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 18, lastZnodeVersion 18
[junit4] 2> 5375 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeAddedTrigger
[junit4] 2> 5376 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase
[junit4] 2>
[junit4] 2> 5376 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2> 5376 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############ FINAL CLUSTER STATS ############
[junit4] 2> 5376 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2>
[junit4] 2> 5376 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Live nodes: 3
[junit4] 2> 5376 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Empty nodes: 3
[junit4] 2> 5376 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Dead nodes: 0
[junit4] 2> 5376 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Collections: []
[junit4] 2> 5376 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Max replicas per node: 0
[junit4] 2> 5376 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Min replicas per node: 0
[junit4] 2> 5376 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Total replicas: 0
[junit4] 2> 5376 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Final Solr op counts ##########
[junit4] 2> 5376 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - autoscaling 2
[junit4] 2> 5376 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - update 2
[junit4] 2> 5376 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Autoscaling event counts ###########
[junit4] 2> 5376 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * Trigger: node_added_trigger
[junit4] 2> 5376 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - STARTED 1
[junit4] 2> 5377 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[CA6E4E49ADA1E82A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - SUCCEEDED 1
[junit4] 2> 5377 DEBUG (ScheduledTrigger-15-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 5378 DEBUG (ScheduledTrigger-15-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] IGNOR/A 0.00s J0 | TestTriggerIntegration.testEventFromRestoredState
[junit4] > Assumption #1: 'badapp
[...truncated too long message...]
essing-n:127.0.0.1:46079_solr) [n:127.0.0.1:46079_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (1)
[junit4] 2> 531490 INFO (zkCallback-266-thread-5-processing-n:127.0.0.1:44458_solr) [n:127.0.0.1:44458_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (1)
[junit4] 2> 531492 INFO (zkCallback-262-thread-5-processing-n:127.0.0.1:42806_solr) [n:127.0.0.1:42806_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (1)
[junit4] 2> 531492 INFO (zkCallback-254-thread-6-processing-n:127.0.0.1:46079_solr) [n:127.0.0.1:46079_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (1)
[junit4] 2> 531510 INFO (jetty-closer-213-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72394843383201815-127.0.0.1:35881_solr-n_0000000004) closing
[junit4] 2> 531524 INFO (zkCallback-237-thread-6-processing-n:127.0.0.1:42806_solr) [n:127.0.0.1:42806_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (1)
[junit4] 2> 531524 INFO (jetty-closer-213-thread-2) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:42806_solr
[junit4] 2> 531525 WARN (OverseerAutoScalingTriggerThread-72394843383201815-127.0.0.1:35881_solr-n_0000000004) [n:127.0.0.1:35881_solr ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 531528 INFO (OverseerStateUpdate-72394843383201815-127.0.0.1:35881_solr-n_0000000004) [n:127.0.0.1:35881_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:35881_solr
[junit4] 2> 531529 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x10132b9fb6d0019, likely client has closed socket
[junit4] 2> 531578 INFO (jetty-closer-213-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 531578 INFO (zkCallback-258-thread-5-processing-n:127.0.0.1:35881_solr) [n:127.0.0.1:35881_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 531668 INFO (zkCallback-239-thread-6-processing-n:127.0.0.1:35881_solr) [n:127.0.0.1:35881_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 531668 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x10132b9fb6d001b, likely client has closed socket
[junit4] 2> 531668 INFO (zkCallback-237-thread-7-processing-n:127.0.0.1:42806_solr) [n:127.0.0.1:42806_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 531668 INFO (zkCallback-262-thread-5-processing-n:127.0.0.1:42806_solr) [n:127.0.0.1:42806_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 531695 WARN (zkCallback-246-thread-7-processing-n:127.0.0.1:44458_solr) [n:127.0.0.1:44458_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 531698 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x10132b9fb6d0015, likely client has closed socket
[junit4] 2> 531723 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x10132b9fb6d0017, likely client has closed socket
[junit4] 2> 531728 INFO (jetty-closer-213-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@14f650{/solr,null,UNAVAILABLE}
[junit4] 2> 531728 INFO (jetty-closer-213-thread-4) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@531b899d{/solr,null,UNAVAILABLE}
[junit4] 2> 531729 INFO (jetty-closer-213-thread-1) [ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 531729 INFO (zkCallback-237-thread-8-processing-n:127.0.0.1:42806_solr) [n:127.0.0.1:42806_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:42806_solr
[junit4] 2> 531729 INFO (jetty-closer-213-thread-4) [ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 533181 WARN (zkCallback-241-thread-9-processing-n:127.0.0.1:46079_solr) [n:127.0.0.1:46079_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 533202 INFO (jetty-closer-213-thread-3) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@6afe2b9c{/solr,null,UNAVAILABLE}
[junit4] 2> 533202 INFO (jetty-closer-213-thread-3) [ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 533253 INFO (jetty-closer-213-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@76219de5{/solr,null,UNAVAILABLE}
[junit4] 2> 533254 INFO (jetty-closer-213-thread-2) [ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 533323 ERROR (SUITE-JDBCStreamTest-seed#[D9AF7EB640850D97]-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> 533328 INFO (SUITE-JDBCStreamTest-seed#[D9AF7EB640850D97]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:32955 32955
[junit4] 2> 533430 INFO (Thread-177) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:32955 32955
[junit4] 2> 533430 WARN (Thread-177) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 18 /solr/aliases.json
[junit4] 2> 18 /solr/clusterprops.json
[junit4] 2> 8 /solr/security.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 18 /solr/clusterstate.json
[junit4] 2> 8 /solr/collections/jdbc/state.json
[junit4] 2> 2 /solr/autoscaling.json
[junit4] 2> 2 /solr/overseer_elect/election/72394843383201815-127.0.0.1:35881_solr-n_0000000004
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 18 /solr/live_nodes
[junit4] 2> 18 /solr/collections
[junit4] 2> 2 /solr/overseer/queue
[junit4] 2> 2 /solr/autoscaling/events/.auto_add_replicas
[junit4] 2> 2 /solr/overseer/collection-queue-work
[junit4] 2> 2 /solr/overseer/queue-work
[junit4] 2>
[junit4] 2> 533441 INFO (SUITE-JDBCStreamTest-seed#[D9AF7EB640850D97]-worker) [ ] o.a.s.SolrTestCaseJ4 ------------------------------------------------------- Done waiting for tracked resources to be released
[junit4] 2> Apr 04, 2018 2:26:44 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=410, maxMBSortInHeap=5.563828939043081, sim=RandomSimilarity(queryNorm=false): {}, locale=es-VE, timezone=Europe/Dublin
[junit4] 2> NOTE: Linux 4.4.0-112-generic amd64/Oracle Corporation 1.8.0_152 (64-bit)/cpus=4,threads=1,free=156238096,total=381157376
[junit4] 2> NOTE: All tests run in this JVM: [CoalesceEvaluatorTest, JdbcDriverTest, SolrExceptionTest, AddEvaluatorTest, CosineEvaluatorTest, MultiplyEvaluatorTest, SolrExampleBinaryTest, PowerEvaluatorTest, TestSolrJErrorHandling, TestJavaBinCodec, TestHash, SolrParamTest, ArcCosineEvaluatorTest, TestSuggesterResponse, RegressionEvaluatorTest, SolrExampleXMLTest, CommonParamsTest, TestCloudSolrClientConnections, JettyWebappTest, TestValidatingJsonMap, CloudSolrClientTest, CloudSolrClientBuilderTest, LessThanEqualToEvaluatorTest, SelectWithEvaluatorsTest, TestCollectionAdminRequest, JDBCStreamTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=JDBCStreamTest -Dtests.seed=D9AF7EB640850D97 -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=es-VE -Dtests.timezone=Europe/Dublin -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[junit4] ERROR 0.00s J2 | JDBCStreamTest (suite) <<<
[junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:46079/solr: KeeperErrorCode = NoNode for /overseer/collection-queue-work/qnr-0000000000
[junit4] > at __randomizedtesting.SeedInfo.seed([D9AF7EB640850D97]:0)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:643)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:255)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:244)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:483)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:413)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1105)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:885)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:818)
[junit4] > at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:194)
[junit4] > at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:211)
[junit4] > at org.apache.solr.client.solrj.io.stream.JDBCStreamTest.setupCluster(JDBCStreamTest.java:76)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] Completed [145/146 (2!)] on J2 in 192.30s, 0 tests, 1 error <<< FAILURES!
[...truncated 48643 lines...]
[JENKINS] Lucene-Solr-Tests-7.3 - Build # 49 - Still Unstable
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-Tests-7.3/49/
1 tests failed.
FAILED: org.apache.solr.handler.PingRequestHandlerTest.testPingInClusterWithNoHealthCheck
Error Message:
Error from server at https://127.0.0.1:40047/solr: KeeperErrorCode = Session expired for /configs/solrCloudCollectionConfig
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at https://127.0.0.1:40047/solr: KeeperErrorCode = Session expired for /configs/solrCloudCollectionConfig
at __randomizedtesting.SeedInfo.seed([B5C5E7D1136C9683:5B1659019680AC67]:0)
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:643)
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.sendRequest(CloudSolrClient.java:1105)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:885)
at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:818)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:194)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:211)
at org.apache.solr.handler.PingRequestHandlerTest.testPingInClusterWithNoHealthCheck(PingRequestHandlerTest.java:195)
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 13856 lines...]
[junit4] Suite: org.apache.solr.handler.PingRequestHandlerTest
[junit4] 2> Creating dataDir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.3/solr/build/solr-core/test/J1/temp/solr.handler.PingRequestHandlerTest_B5C5E7D1136C9683-001/init-core-data-001
[junit4] 2> 4325251 WARN (SUITE-PingRequestHandlerTest-seed#[B5C5E7D1136C9683]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=3 numCloses=3
[junit4] 2> 4325288 INFO (SUITE-PingRequestHandlerTest-seed#[B5C5E7D1136C9683]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 4325289 INFO (SUITE-PingRequestHandlerTest-seed#[B5C5E7D1136C9683]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 4325290 INFO (SUITE-PingRequestHandlerTest-seed#[B5C5E7D1136C9683]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 4325290 INFO (SUITE-PingRequestHandlerTest-seed#[B5C5E7D1136C9683]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore
[junit4] 2> 4325290 INFO (SUITE-PingRequestHandlerTest-seed#[B5C5E7D1136C9683]-worker) [ ] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.3/solr/core/src/test-files/solr/collection1/lib, /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.3/solr/core/src/test-files/solr/collection1/lib/classes]
[junit4] 2> 4325530 INFO (SUITE-PingRequestHandlerTest-seed#[B5C5E7D1136C9683]-worker) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.3.1
[junit4] 2> 4325638 INFO (SUITE-PingRequestHandlerTest-seed#[B5C5E7D1136C9683]-worker) [ ] o.a.s.s.IndexSchema [null] Schema name=test
[junit4] 2> 4326378 INFO (SUITE-PingRequestHandlerTest-seed#[B5C5E7D1136C9683]-worker) [ ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 4326542 INFO (SUITE-PingRequestHandlerTest-seed#[B5C5E7D1136C9683]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3afd36ec
[junit4] 2> 4326578 INFO (SUITE-PingRequestHandlerTest-seed#[B5C5E7D1136C9683]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3afd36ec
[junit4] 2> 4326578 INFO (SUITE-PingRequestHandlerTest-seed#[B5C5E7D1136C9683]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3afd36ec
[junit4] 2> 4326596 INFO (coreLoadExecutor-5912-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 4326599 INFO (coreLoadExecutor-5912-thread-1) [ x:collection1] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.3/solr/core/src/test-files/solr/collection1/lib, /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.3/solr/core/src/test-files/solr/collection1/lib/classes]
[junit4] 2> 4326798 INFO (coreLoadExecutor-5912-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.3.1
[junit4] 2> 4327031 INFO (coreLoadExecutor-5912-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 4327598 INFO (coreLoadExecutor-5912-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 4327655 INFO (coreLoadExecutor-5912-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.3/solr/core/src/test-files/solr/collection1, trusted=true
[junit4] 2> 4327655 INFO (coreLoadExecutor-5912-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@3afd36ec
[junit4] 2> 4327655 INFO (coreLoadExecutor-5912-thread-1) [ x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 4327655 INFO (coreLoadExecutor-5912-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.3/solr/core/src/test-files/solr/collection1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.3/solr/build/solr-core/test/J1/temp/solr.handler.PingRequestHandlerTest_B5C5E7D1136C9683-001/init-core-data-001/]
[junit4] 2> 4327674 INFO (coreLoadExecutor-5912-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=13, maxMergeAtOnceExplicit=42, maxMergedSegmentMB=67.3876953125, floorSegmentMB=1.7060546875, forceMergeDeletesPctAllowed=27.74553596245228, segmentsPerTier=22.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.26082182296840317
[junit4] 2> 4328188 INFO (coreLoadExecutor-5912-thread-1) [ x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 4328188 INFO (coreLoadExecutor-5912-thread-1) [ x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 4328201 INFO (coreLoadExecutor-5912-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 4328202 INFO (coreLoadExecutor-5912-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 4328221 INFO (coreLoadExecutor-5912-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1907628666, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 4328221 INFO (coreLoadExecutor-5912-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@6bb02e38[collection1] main]
[junit4] 2> 4328222 INFO (coreLoadExecutor-5912-thread-1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
[junit4] 2> 4328367 INFO (coreLoadExecutor-5912-thread-1) [ x:collection1] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 4328565 INFO (coreLoadExecutor-5912-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 4328565 INFO (searcherExecutor-5913-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
[junit4] 2> 4328565 INFO (coreLoadExecutor-5912-thread-1) [ x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1598850873388171264
[junit4] 2> 4328565 INFO (searcherExecutor-5913-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
[junit4] 2> 4328565 INFO (searcherExecutor-5913-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
[junit4] 2> 4328565 INFO (searcherExecutor-5913-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
[junit4] 2> 4328566 INFO (searcherExecutor-5913-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
[junit4] 2> 4328566 INFO (searcherExecutor-5913-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
[junit4] 2> 4328566 INFO (searcherExecutor-5913-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
[junit4] 2> 4328566 INFO (searcherExecutor-5913-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
[junit4] 2> 4328567 INFO (searcherExecutor-5913-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
[junit4] 2> 4328567 INFO (searcherExecutor-5913-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@6bb02e38[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 4328571 INFO (SUITE-PingRequestHandlerTest-seed#[B5C5E7D1136C9683]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore end
[junit4] 2> 4328640 INFO (TEST-PingRequestHandlerTest.testEnablingServer-seed#[B5C5E7D1136C9683]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testEnablingServer
[junit4] 2> 4328641 INFO (TEST-PingRequestHandlerTest.testEnablingServer-seed#[B5C5E7D1136C9683]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={wt=xml} hits=0 status=0 QTime=0
[junit4] 2> 4328642 INFO (TEST-PingRequestHandlerTest.testEnablingServer-seed#[B5C5E7D1136C9683]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testEnablingServer
[junit4] 2> 4328732 INFO (TEST-PingRequestHandlerTest.testDisablingServer-seed#[B5C5E7D1136C9683]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testDisablingServer
[junit4] 2> 4328733 INFO (TEST-PingRequestHandlerTest.testDisablingServer-seed#[B5C5E7D1136C9683]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={wt=xml} hits=0 status=0 QTime=0
[junit4] 2> 4328733 INFO (TEST-PingRequestHandlerTest.testDisablingServer-seed#[B5C5E7D1136C9683]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testDisablingServer
[junit4] 2> 4328774 INFO (TEST-PingRequestHandlerTest.testBadActionRaisesException-seed#[B5C5E7D1136C9683]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testBadActionRaisesException
[junit4] 2> 4328775 INFO (TEST-PingRequestHandlerTest.testBadActionRaisesException-seed#[B5C5E7D1136C9683]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testBadActionRaisesException
[junit4] 2> 4328832 INFO (TEST-PingRequestHandlerTest.testGettingStatus-seed#[B5C5E7D1136C9683]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testGettingStatus
[junit4] 2> 4328833 INFO (TEST-PingRequestHandlerTest.testGettingStatus-seed#[B5C5E7D1136C9683]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testGettingStatus
[junit4] 2> 4328957 INFO (TEST-PingRequestHandlerTest.testPingWithNoHealthCheck-seed#[B5C5E7D1136C9683]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testPingWithNoHealthCheck
[junit4] 2> 4328957 INFO (TEST-PingRequestHandlerTest.testPingWithNoHealthCheck-seed#[B5C5E7D1136C9683]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={wt=xml} hits=0 status=0 QTime=0
[junit4] 2> 4328957 INFO (TEST-PingRequestHandlerTest.testPingWithNoHealthCheck-seed#[B5C5E7D1136C9683]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={action=ping&wt=xml} hits=0 status=0 QTime=0
[junit4] 2> 4328957 INFO (TEST-PingRequestHandlerTest.testPingWithNoHealthCheck-seed#[B5C5E7D1136C9683]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testPingWithNoHealthCheck
[junit4] 2> 4329049 INFO (TEST-PingRequestHandlerTest.testPingInClusterWithNoHealthCheck-seed#[B5C5E7D1136C9683]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testPingInClusterWithNoHealthCheck
[junit4] 2> 4329050 INFO (TEST-PingRequestHandlerTest.testPingInClusterWithNoHealthCheck-seed#[B5C5E7D1136C9683]) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 5 servers in /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.3/solr/build/solr-core/test/J1/temp/solr.handler.PingRequestHandlerTest_B5C5E7D1136C9683-001/tempDir-001
[junit4] 2> 4329050 INFO (TEST-PingRequestHandlerTest.testPingInClusterWithNoHealthCheck-seed#[B5C5E7D1136C9683]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 4329050 INFO (Thread-4203) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 4329050 INFO (Thread-4203) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 4329081 ERROR (Thread-4203) [ ] 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> 4329158 INFO (TEST-PingRequestHandlerTest.testPingInClusterWithNoHealthCheck-seed#[B5C5E7D1136C9683]) [ ] o.a.s.c.ZkTestServer start zk server on port:41596
[junit4] 2> 4329248 INFO (zkConnectionManagerCallback-3247-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4329286 INFO (jetty-launcher-3244-thread-1) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T16:27:37-05:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 4329288 INFO (jetty-launcher-3244-thread-2) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T16:27:37-05:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 4329306 INFO (jetty-launcher-3244-thread-3) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T16:27:37-05:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 4329307 INFO (jetty-launcher-3244-thread-4) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T16:27:37-05:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 4329334 INFO (jetty-launcher-3244-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 4329334 INFO (jetty-launcher-3244-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 4329334 INFO (jetty-launcher-3244-thread-2) [ ] o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 4329334 INFO (jetty-launcher-3244-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@3a607178{/solr,null,AVAILABLE}
[junit4] 2> 4329335 INFO (jetty-launcher-3244-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@74aed852{SSL,[ssl, http/1.1]}{127.0.0.1:43438}
[junit4] 2> 4329335 INFO (jetty-launcher-3244-thread-2) [ ] o.e.j.s.Server Started @4352395ms
[junit4] 2> 4329335 INFO (jetty-launcher-3244-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=43438}
[junit4] 2> 4329335 ERROR (jetty-launcher-3244-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 4329385 INFO (jetty-launcher-3244-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.3.1
[junit4] 2> 4329401 INFO (jetty-launcher-3244-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 4329402 INFO (jetty-launcher-3244-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 4329402 INFO (jetty-launcher-3244-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-04-26T22:50:14.551Z
[junit4] 2> 4329431 INFO (jetty-launcher-3244-thread-5) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T16:27:37-05:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 4329431 INFO (jetty-launcher-3244-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 4329431 INFO (jetty-launcher-3244-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 4329432 INFO (jetty-launcher-3244-thread-1) [ ] o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 4329432 INFO (jetty-launcher-3244-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@aa7a730{/solr,null,AVAILABLE}
[junit4] 2> 4329432 INFO (jetty-launcher-3244-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@d58121b{SSL,[ssl, http/1.1]}{127.0.0.1:40047}
[junit4] 2> 4329432 INFO (jetty-launcher-3244-thread-1) [ ] o.e.j.s.Server Started @4352492ms
[junit4] 2> 4329433 INFO (jetty-launcher-3244-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=40047}
[junit4] 2> 4329433 ERROR (jetty-launcher-3244-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 4329433 INFO (jetty-launcher-3244-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.3.1
[junit4] 2> 4329433 INFO (jetty-launcher-3244-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 4329433 INFO (jetty-launcher-3244-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 4329433 INFO (jetty-launcher-3244-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-04-26T22:50:14.582Z
[junit4] 2> 4329442 INFO (jetty-launcher-3244-thread-4) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 4329443 INFO (jetty-launcher-3244-thread-4) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 4329443 INFO (jetty-launcher-3244-thread-4) [ ] o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 4329443 INFO (jetty-launcher-3244-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@d76654{/solr,null,AVAILABLE}
[junit4] 2> 4329443 INFO (jetty-launcher-3244-thread-4) [ ] o.e.j.s.AbstractConnector Started ServerConnector@49653d07{SSL,[ssl, http/1.1]}{127.0.0.1:41067}
[junit4] 2> 4329443 INFO (jetty-launcher-3244-thread-4) [ ] o.e.j.s.Server Started @4352503ms
[junit4] 2> 4329443 INFO (jetty-launcher-3244-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=41067}
[junit4] 2> 4329443 ERROR (jetty-launcher-3244-thread-4) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 4329446 INFO (jetty-launcher-3244-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.3.1
[junit4] 2> 4329446 INFO (jetty-launcher-3244-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 4329446 INFO (jetty-launcher-3244-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 4329446 INFO (jetty-launcher-3244-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-04-26T22:50:14.595Z
[junit4] 2> 4329479 INFO (zkConnectionManagerCallback-3249-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4329479 INFO (jetty-launcher-3244-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 4329504 INFO (jetty-launcher-3244-thread-3) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 4329504 INFO (jetty-launcher-3244-thread-3) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 4329504 INFO (jetty-launcher-3244-thread-3) [ ] o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 4329504 INFO (jetty-launcher-3244-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@36a052a{/solr,null,AVAILABLE}
[junit4] 2> 4329505 INFO (jetty-launcher-3244-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@73adf1e9{SSL,[ssl, http/1.1]}{127.0.0.1:39342}
[junit4] 2> 4329505 INFO (jetty-launcher-3244-thread-3) [ ] o.e.j.s.Server Started @4352565ms
[junit4] 2> 4329505 INFO (jetty-launcher-3244-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=39342}
[junit4] 2> 4329505 ERROR (jetty-launcher-3244-thread-3) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 4329505 INFO (jetty-launcher-3244-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.3.1
[junit4] 2> 4329505 INFO (jetty-launcher-3244-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 4329505 INFO (jetty-launcher-3244-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 4329505 INFO (jetty-launcher-3244-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-04-26T22:50:14.654Z
[junit4] 2> 4329564 INFO (zkConnectionManagerCallback-3251-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4329565 INFO (jetty-launcher-3244-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 4329617 INFO (jetty-launcher-3244-thread-5) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 4329617 INFO (jetty-launcher-3244-thread-5) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 4329617 INFO (jetty-launcher-3244-thread-5) [ ] o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 4329653 INFO (jetty-launcher-3244-thread-5) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@70f937ba{/solr,null,AVAILABLE}
[junit4] 2> 4329653 INFO (jetty-launcher-3244-thread-5) [ ] o.e.j.s.AbstractConnector Started ServerConnector@3858be78{SSL,[ssl, http/1.1]}{127.0.0.1:46166}
[junit4] 2> 4329653 INFO (jetty-launcher-3244-thread-5) [ ] o.e.j.s.Server Started @4352713ms
[junit4] 2> 4329653 INFO (jetty-launcher-3244-thread-5) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=46166}
[junit4] 2> 4329666 ERROR (jetty-launcher-3244-thread-5) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 4329666 INFO (jetty-launcher-3244-thread-5) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.3.1
[junit4] 2> 4329666 INFO (jetty-launcher-3244-thread-5) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 4329666 INFO (jetty-launcher-3244-thread-5) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 4329666 INFO (jetty-launcher-3244-thread-5) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-04-26T22:50:14.815Z
[junit4] 2> 4329710 INFO (zkConnectionManagerCallback-3253-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4329711 INFO (jetty-launcher-3244-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 4329726 INFO (zkConnectionManagerCallback-3255-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4329748 INFO (jetty-launcher-3244-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 4329796 INFO (jetty-launcher-3244-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41596/solr
[junit4] 2> 4329833 INFO (zkConnectionManagerCallback-3261-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4329946 INFO (jetty-launcher-3244-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41596/solr
[junit4] 2> 4329947 INFO (jetty-launcher-3244-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41596/solr
[junit4] 2> 4329985 INFO (zkConnectionManagerCallback-3257-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4330016 INFO (zkConnectionManagerCallback-3270-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4330150 INFO (jetty-launcher-3244-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41596/solr
[junit4] 2> 4330166 INFO (jetty-launcher-3244-thread-5) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 4330199 INFO (zkConnectionManagerCallback-3267-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4330203 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x101a868e9a10008, likely client has closed socket
[junit4] 2> 4330236 INFO (zkConnectionManagerCallback-3275-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4330408 INFO (zkConnectionManagerCallback-3277-thread-1-processing-n:127.0.0.1:39342_solr) [n:127.0.0.1:39342_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4330474 INFO (zkConnectionManagerCallback-3273-thread-1-processing-n:127.0.0.1:43438_solr) [n:127.0.0.1:43438_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4330600 INFO (jetty-launcher-3244-thread-5) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41596/solr
[junit4] 2> 4330613 INFO (jetty-launcher-3244-thread-2) [n:127.0.0.1:43438_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 4330675 INFO (zkConnectionManagerCallback-3279-thread-1-processing-n:127.0.0.1:40047_solr) [n:127.0.0.1:40047_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4330690 INFO (zkConnectionManagerCallback-3287-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4330690 INFO (zkConnectionManagerCallback-3282-thread-1-processing-n:127.0.0.1:41067_solr) [n:127.0.0.1:41067_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4330702 INFO (jetty-launcher-3244-thread-2) [n:127.0.0.1:43438_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:43438_solr
[junit4] 2> 4330730 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x101a868e9a1000d, likely client has closed socket
[junit4] 2> 4330778 INFO (zkConnectionManagerCallback-3289-thread-1-processing-n:127.0.0.1:46166_solr) [n:127.0.0.1:46166_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4330796 INFO (jetty-launcher-3244-thread-2) [n:127.0.0.1:43438_solr ] o.a.s.c.Overseer Overseer (id=72524237564346377-127.0.0.1:43438_solr-n_0000000000) starting
[junit4] 2> 4331240 INFO (jetty-launcher-3244-thread-4) [n:127.0.0.1:41067_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 4331274 INFO (jetty-launcher-3244-thread-4) [n:127.0.0.1:41067_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41067_solr
[junit4] 2> 4331425 INFO (zkCallback-3272-thread-1-processing-n:127.0.0.1:43438_solr) [n:127.0.0.1:43438_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 4331425 INFO (zkCallback-3281-thread-1-processing-n:127.0.0.1:41067_solr) [n:127.0.0.1:41067_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 4331551 INFO (zkConnectionManagerCallback-3296-thread-1-processing-n:127.0.0.1:43438_solr) [n:127.0.0.1:43438_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4331577 INFO (jetty-launcher-3244-thread-1) [n:127.0.0.1:40047_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 4331644 INFO (jetty-launcher-3244-thread-2) [n:127.0.0.1:43438_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 4331649 INFO (jetty-launcher-3244-thread-5) [n:127.0.0.1:46166_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 4331651 INFO (jetty-launcher-3244-thread-1) [n:127.0.0.1:40047_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 4331687 INFO (jetty-launcher-3244-thread-1) [n:127.0.0.1:40047_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40047_solr
[junit4] 2> 4331687 INFO (jetty-launcher-3244-thread-5) [n:127.0.0.1:46166_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 4331744 INFO (jetty-launcher-3244-thread-5) [n:127.0.0.1:46166_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46166_solr
[junit4] 2> 4331750 INFO (jetty-launcher-3244-thread-2) [n:127.0.0.1:43438_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:41596/solr ready
[junit4] 2> 4331750 INFO (zkCallback-3272-thread-1-processing-n:127.0.0.1:43438_solr) [n:127.0.0.1:43438_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 4331770 INFO (zkCallback-3272-thread-1-processing-n:127.0.0.1:43438_solr) [n:127.0.0.1:43438_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 4331770 INFO (zkCallback-3281-thread-1-processing-n:127.0.0.1:41067_solr) [n:127.0.0.1:41067_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3)
[junit4] 2> 4331896 INFO (zkCallback-3278-thread-1-processing-n:127.0.0.1:40047_solr) [n:127.0.0.1:40047_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 4331896 INFO (zkCallback-3295-thread-1-processing-n:127.0.0.1:43438_solr) [n:127.0.0.1:43438_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3)
[junit4] 2> 4331943 INFO (jetty-launcher-3244-thread-4) [n:127.0.0.1:41067_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41067.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3afd36ec
[junit4] 2> 4331976 INFO (jetty-launcher-3244-thread-4) [n:127.0.0.1:41067_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41067.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3afd36ec
[junit4] 2> 4331996 INFO (jetty-launcher-3244-thread-4) [n:127.0.0.1:41067_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41067.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3afd36ec
[junit4] 2> 4332106 INFO (zkCallback-3288-thread-1-processing-n:127.0.0.1:46166_solr) [n:127.0.0.1:46166_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3)
[junit4] 2> 4332123 INFO (jetty-launcher-3244-thread-4) [n:127.0.0.1:41067_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.3/solr/build/solr-core/test/J1/temp/solr.handler.PingRequestHandlerTest_B5C5E7D1136C9683-001/tempDir-001/node4/.
[junit4] 2> 4332164 INFO (zkCallback-3278-thread-2-processing-n:127.0.0.1:40047_solr) [n:127.0.0.1:40047_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 4332186 INFO (jetty-launcher-3244-thread-2) [n:127.0.0.1:43438_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43438_solr
[junit4] 2> 4332238 INFO (zkCallback-3281-thread-1-processing-n:127.0.0.1:41067_solr) [n:127.0.0.1:41067_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 4332253 INFO (zkCallback-3278-thread-2-processing-n:127.0.0.1:40047_solr) [n:127.0.0.1:40047_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 4332254 INFO (zkCallback-3295-thread-1-processing-n:127.0.0.1:43438_solr) [n:127.0.0.1:43438_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 4332254 INFO (zkCallback-3288-thread-1-processing-n:127.0.0.1:46166_solr) [n:127.0.0.1:46166_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 4332320 INFO (zkConnectionManagerCallback-3300-thread-1-processing-n:127.0.0.1:41067_solr) [n:127.0.0.1:41067_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4332342 INFO (zkCallback-3272-thread-1-processing-n:127.0.0.1:43438_solr) [n:127.0.0.1:43438_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 4332765 INFO (jetty-launcher-3244-thread-4) [n:127.0.0.1:41067_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 4332789 INFO (jetty-launcher-3244-thread-1) [n:127.0.0.1:40047_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40047.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3afd36ec
[junit4] 2> 4332804 INFO (jetty-launcher-3244-thread-5) [n:127.0.0.1:46166_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46166.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3afd36ec
[junit4] 2> 4332859 INFO (jetty-launcher-3244-thread-4) [n:127.0.0.1:41067_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:41596/solr ready
[junit4] 2> 4332899 INFO (jetty-launcher-3244-thread-1) [n:127.0.0.1:40047_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40047.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3afd36ec
[junit4] 2> 4332899 INFO (jetty-launcher-3244-thread-1) [n:127.0.0.1:40047_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40047.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3afd36ec
[junit4] 2> 4332971 INFO (jetty-launcher-3244-thread-1) [n:127.0.0.1:40047_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.3/solr/build/solr-core/test/J1/temp/solr.handler.PingRequestHandlerTest_B5C5E7D1136C9683-001/tempDir-001/node1/.
[junit4] 2> 4333006 INFO (jetty-launcher-3244-thread-5) [n:127.0.0.1:46166_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46166.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3afd36ec
[junit4] 2> 4333006 INFO (jetty-launcher-3244-thread-5) [n:127.0.0.1:46166_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46166.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3afd36ec
[junit4] 2> 4333008 INFO (jetty-launcher-3244-thread-5) [n:127.0.0.1:46166_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.3/solr/build/solr-core/test/J1/temp/solr.handler.PingRequestHandlerTest_B5C5E7D1136C9683-001/tempDir-001/node5/.
[junit4] 2> 4333188 INFO (zkConnectionManagerCallback-3305-thread-1-processing-n:127.0.0.1:40047_solr) [n:127.0.0.1:40047_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4333209 INFO (jetty-launcher-3244-thread-1) [n:127.0.0.1:40047_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 4333211 INFO (jetty-launcher-3244-thread-3) [n:127.0.0.1:39342_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 4333246 INFO (jetty-launcher-3244-thread-1) [n:127.0.0.1:40047_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:41596/solr ready
[junit4] 2> 4333262 INFO (zkConnectionManagerCallback-3308-thread-1-processing-n:127.0.0.1:46166_solr) [n:127.0.0.1:46166_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4333263 INFO (jetty-launcher-3244-thread-5) [n:127.0.0.1:46166_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 4333338 INFO (jetty-launcher-3244-thread-3) [n:127.0.0.1:39342_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 4333351 INFO (jetty-launcher-3244-thread-2) [n:127.0.0.1:43438_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43438.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3afd36ec
[junit4] 2> 4333351 INFO (jetty-launcher-3244-thread-5) [n:127.0.0.1:46166_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:41596/solr ready
[junit4] 2> 4333387 INFO (jetty-launcher-3244-thread-3) [n:127.0.0.1:39342_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39342_solr
[junit4] 2> 4333407 INFO (zkCallback-3281-thread-1-processing-n:127.0.0.1:41067_solr) [n:127.0.0.1:41067_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 4333407 INFO (zkCallback-3288-thread-1-processing-n:127.0.0.1:46166_solr) [n:127.0.0.1:46166_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 4333407 INFO (zkCallback-3278-thread-2-processing-n:127.0.0.1:40047_solr) [n:127.0.0.1:40047_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 4333407 INFO (zkCallback-3295-thread-1-processing-n:127.0.0.1:43438_solr) [n:127.0.0.1:43438_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 4333426 INFO (zkCallback-3272-thread-2-processing-n:127.0.0.1:43438_solr) [n:127.0.0.1:43438_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 4333570 INFO (zkCallback-3307-thread-1-processing-n:127.0.0.1:46166_solr) [n:127.0.0.1:46166_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 4333570 INFO (zkCallback-3299-thread-1-processing-n:127.0.0.1:41067_solr) [n:127.0.0.1:41067_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 4333592 INFO (zkCallback-3276-thread-1-processing-n:127.0.0.1:39342_solr) [n:127.0.0.1:39342_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 4333593 INFO (jetty-launcher-3244-thread-2) [n:127.0.0.1:43438_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43438.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3afd36ec
[junit4] 2> 4333593 INFO (jetty-launcher-3244-thread-2) [n:127.0.0.1:43438_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43438.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3afd36ec
[junit4] 2> 4333664 INFO (jetty-launcher-3244-thread-2) [n:127.0.0.1:43438_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.3/solr/build/solr-core/test/J1/temp/solr.handler.PingRequestHandlerTest_B5C5E7D1136C9683-001/tempDir-001/node2/.
[junit4] 2> 4333664 INFO (zkCallback-3304-thread-1-processing-n:127.0.0.1:40047_solr) [n:127.0.0.1:40047_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 4334340 INFO (jetty-launcher-3244-thread-3) [n:127.0.0.1:39342_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39342.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3afd36ec
[junit4] 2> 4334411 INFO (jetty-launcher-3244-thread-3) [n:127.0.0.1:39342_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39342.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3afd36ec
[junit4] 2> 4334411 INFO (jetty-launcher-3244-thread-3) [n:127.0.0.1:39342_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39342.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3afd36ec
[junit4] 2> 4334412 INFO (jetty-launcher-3244-thread-3) [n:127.0.0.1:39342_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.3/solr/build/solr-core/test/J1/temp/solr.handler.PingRequestHandlerTest_B5C5E7D1136C9683-001/tempDir-001/node3/.
[junit4] 2> 4334477 INFO (zkConnectionManagerCallback-3312-thread-1-processing-n:127.0.0.1:39342_solr) [n:127.0.0.1:39342_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4334477 INFO (jetty-launcher-3244-thread-3) [n:127.0.0.1:39342_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (5)
[junit4] 2> 4334478 INFO (jetty-launcher-3244-thread-3) [n:127.0.0.1:39342_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:41596/solr ready
[junit4] 2> 4335167 INFO (zkConnectionManagerCallback-3314-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4335187 INFO (zkConnectionManagerCallback-3317-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4343411 WARN (jetty-launcher-3244-thread-3-SendThread(127.0.0.1:41596)) [n:127.0.0.1:39342_solr ] o.a.z.ClientCnxn Client session timed out, have not heard from server in 8933ms for sessionid 0x101a868e9a10014
[junit4] 2> 4344137 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x101a868e9a10014, likely client has closed socket
[junit4] 2> 4343531 WARN (jetty-launcher-3244-thread-4-SendThread(127.0.0.1:41596)) [n:127.0.0.1:41067_solr ] o.a.z.ClientCnxn Client session timed out, have not heard from server in 6774ms for sessionid 0x101a868e9a10011
[junit4] 2> 4343531 WARN (jetty-launcher-3244-thread-2-SendThread(127.0.0.1:41596)) [n:127.0.0.1:43438_solr ] o.a.z.ClientCnxn Client session timed out, have not heard from server in 9611ms for sessionid 0x101a868e9a10010
[junit4] 2> 4343531 WARN (jetty-launcher-3244-thread-5-SendThread(127.0.0.1:41596)) [n:127.0.0.1:46166_solr ] o.a.z.ClientCnxn Client session timed out, have not heard from server in 6773ms for sessionid 0x101a868e9a10013
[junit4] 2> 4344153 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x101a868e9a10010, likely client has closed socket
[junit4] 2> 4344153 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x101a868e9a10013, likely client has closed socket
[junit4] 2> 4344153 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x101a868e9a10011, likely client has closed socket
[junit4] 2> 4344258 WARN (zkConnectionManagerCallback-3300-thread-1-processing-n:127.0.0.1:41067_solr) [n:127.0.0.1:41067_solr ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@4daea7e0 name: ZooKeeperConnection Watcher:127.0.0.1:41596/solr got event WatchedEvent state:Disconnected type:None path:null path: null type: None
[junit4] 2> 4344258 WARN (zkConnectionManagerCallback-3300-thread-1-processing-n:127.0.0.1:41067_solr) [n:127.0.0.1:41067_solr ] o.a.s.c.c.ConnectionManager zkClient has disconnected
[junit4] 2> 4344259 WARN (zkConnectionManagerCallback-3296-thread-1-processing-n:127.0.0.1:43438_solr) [n:127.0.0.1:43438_solr ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@e566c2c name: ZooKeeperConnection Watcher:127.0.0.1:41596/solr got event WatchedEvent state:Disconnected type:None path:null path: null type: None
[junit4] 2> 4344259 WARN (zkConnectionManagerCallback-3296-thread-1-processing-n:127.0.0.1:43438_solr) [n:127.0.0.1:43438_solr ] o.a.s.c.c.ConnectionManager zkClient has disconnected
[junit4] 2> 4344268 WARN (zkConnectionManagerCallback-3312-thread-1-processing-n:127.0.0.1:39342_solr) [n:127.0.0.1:39342_solr ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@52cbb06b name: ZooKeeperConnection Watcher:127.0.0.1:41596/solr got event WatchedEvent state:Disconnected type:None path:null path: null type: None
[junit4] 2> 4344269 WARN (zkConnectionManagerCallback-3312-thread-1-processing-n:127.0.0.1:39342_solr) [n:127.0.0.1:39342_solr ] o.a.s.c.c.ConnectionManager zkClient has disconnected
[junit4] 2> 4344282 WARN (zkConnectionManagerCallback-3308-thread-1-processing-n:127.0.0.1:46166_solr) [n:127.0.0.1:46166_solr ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@57d1be29 name: ZooKeeperConnection Watcher:127.0.0.1:41596/solr got event WatchedEvent state:Disconnected type:None path:null path: null type: None
[junit4] 2> 4344283 WARN (zkConnectionManagerCallback-3308-thread-1-processing-n:127.0.0.1:46166_solr) [n:127.0.0.1:46166_solr ] o.a.s.c.c.ConnectionManager zkClient has disconnected
[junit4] 2> 4344868 INFO (zkConnectionManagerCallback-3320-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4344869 INFO (TEST-PingRequestHandlerTest.testPingInClusterWithNoHealthCheck-seed#[B5C5E7D1136C9683]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (5)
[junit4] 2> 4344870 INFO (TEST-PingRequestHandlerTest.testPingInClusterWithNoHealthCheck-seed#[B5C5E7D1136C9683]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:41596/solr ready
[junit4] 2> 4345305 INFO (qtp1852841923-15894) [n:127.0.0.1:40047_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&collection.configName=solrCloudCollectionConfig&name=testSolrCloudCollection&nrtReplicas=2&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 4345322 INFO (zkConnectionManagerCallback-3308-thread-1-processing-n:127.0.0.1:46166_solr) [n:127.0.0.1:46166_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4345439 INFO (OverseerThreadFactory-5942-thread-1-processing-n:127.0.0.1:43438_solr) [n:127.0.0.1:43438_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection testSolrCloudCollection
[junit4] 2> 4345460 WARN (jetty-launcher-3244-thread-2-SendThread(127.0.0.1:41596)) [n:127.0.0.1:43438_solr ] o.a.z.ClientCnxn Unable to reconnect to ZooKeeper service, session 0x101a868e9a10010 has expired
[junit4] 2> 4345468 WARN (zkConnectionManagerCallback-3296-thread-1-processing-n:127.0.0.1:43438_solr) [n:127.0.0.1:43438_solr ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@e566c2c name: ZooKeeperConnection Watcher:127.0.0.1:41596/solr got event WatchedEvent state:Expired type:None path:null path: null type: None
[junit4] 2> 4345468 WARN (zkConnectionManagerCallback-3296-thread-1-processing-n:127.0.0.1:43438_solr) [n:127.0.0.1:43438_solr ] o.a.s.c.c.ConnectionManager Our previous ZooKeeper session was expired. Attempting to reconnect to recover relationship with ZooKeeper...
[junit4] 2> 4345468 WARN (zkConnectionManagerCallback-3296-thread-1-processing-n:127.0.0.1:43438_solr) [n:127.0.0.1:43438_solr ] o.a.s.c.c.DefaultConnectionStrategy Connection expired - starting a new one...
[junit4] 2> 4345549 INFO (zkConnectionManagerCallback-3296-thread-1-processing-n:127.0.0.1:43438_solr-EventThread) [n:127.0.0.1:43438_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4345549 INFO (zkConnectionManagerCallback-3296-thread-1-processing-n:127.0.0.1:43438_solr) [n:127.0.0.1:43438_solr ] o.a.s.c.c.ConnectionManager Connection with ZooKeeper reestablished.
[junit4] 2> 4345585 ERROR (OverseerThreadFactory-5942-thread-1-processing-n:127.0.0.1:43438_solr) [n:127.0.0.1:43438_solr ] o.a.s.c.a.c.OverseerCollectionMessageHandler Collection: testSolrCloudCollection operation: create failed:org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /configs/solrCloudCollectionConfig
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:130)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:54)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1105)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.lambda$exists$3(SolrZkClient.java:316)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:316)
[junit4] 2> at org.apache.solr.client.solrj.impl.ZkDistribStateManager.hasData(ZkDistribStateManager.java:58)
[junit4] 2> at org.apache.solr.cloud.api.collections.OverseerCollectionMessageHandler.validateConfigOrThrowSolrException(OverseerCollectionMessageHandler.java:737)
[junit4] 2> at org.apache.solr.cloud.api.collections.CreateCollectionCmd.call(CreateCollectionCmd.java:114)
[junit4] 2> at org.apache.solr.cloud.api.collections.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:252)
[junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:469)
[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>
[junit4] 2> 4345676 INFO (zkConnectionManagerCallback-3296-thread-1-processing-n:127.0.0.1:43438_solr) [n:127.0.0.1:43438_solr ] o.a.s.c.c.DefaultConnectionStrategy Reconnected to ZooKeeper
[junit4] 2> 4345677 INFO (zkConnectionManagerCallback-3296-thread-1-processing-n:127.0.0.1:43438_solr) [n:127.0.0.1:43438_solr ] o.a.s.c.c.ConnectionManager zkClient Connected:true
[junit4] 2> 4345876 INFO (qtp1852841923-15894) [n:127.0.0.1:40047_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=2&collection.configName=solrCloudCollectionConfig&name=testSolrCloudCollection&nrtReplicas=2&action=CREATE&numShards=2&wt=javabin&version=2} status=500 QTime=571
[junit4] 2> 4345877 ERROR (qtp1852841923-15894) [n:127.0.0.1:40047_solr ] o.a.s.s.HttpSolrCall null:org.apache.solr.common.SolrException: KeeperErrorCode = Session expired for /configs/solrCloudCollectionConfig
[junit4] 2> at org.apache.solr.client.solrj.SolrResponse.getException(SolrResponse.java:53)
[junit4] 2> at org.apache.solr.handler.admin.CollectionsHandler.invokeAction(CollectionsHandler.java:258)
[junit4] 2> at org.apache.solr.handler.admin.CollectionsHandler.handleRequestBody(CollectionsHandler.java:230)
[junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:195)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdmin(HttpSolrCall.java:736)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:717)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:498)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:384)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:330)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1637)
[junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:139)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1637)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:533)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:188)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:188)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1253)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:168)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:166)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1155)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
[junit4] 2> at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:527)
[junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
[junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:530)
[junit4] 2> at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:347)
[junit4] 2> at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:256)
[junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:279)
[junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:102)
[junit4] 2> at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:289)
[junit4] 2> at org.eclipse.jetty.io.ssl.SslConnection$3.succeeded(SslConnection.java:149)
[junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:102)
[junit4] 2> at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:124)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:247)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produce(EatWhatYouKill.java:140)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131)
[junit4] 2> at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:382)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 4346120 INFO (jetty-closer-3245-thread-4) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@74aed852{SSL,[ssl, http/1.1]}{127.0.0.1:0}
[junit4] 2> 4346120 INFO (jetty-closer-3245-thread-2) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@49653d07{SSL,[ssl, http/1.1]}{127.0.0.1:0}
[junit4] 2> 4346130 INFO (jetty-closer-3245-thread-4) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=2005436145
[junit4] 2> 4346131 INFO (jetty-closer-3245-thread-4) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 4346131 INFO (jetty-closer-3245-thread-4) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@3961b8b: rootName = solr_43438, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@6b99d5b6
[junit4] 2> 4346132 INFO (jetty-closer-3245-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@d58121b{SSL,[ssl, http/1.1]}{127.0.0.1:0}
[junit4] 2> 4346146 INFO (zkConnectionManagerCallback-3300-thread-1-processing-n:127.0.0.1:41067_solr) [n:127.0.0.1:41067_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4346259 WARN (jetty-launcher-3244-thread-3-SendThread(127.0.0.1:41596)) [n:127.0.0.1:39342_solr ] o.a.z.ClientCnxn Unable to reconnect to ZooKeeper service, session 0x101a868e9a10014 has expired
[junit4] 2> 4346259 WARN (zkConnectionManagerCallback-3312-thread-1-processing-n:127.0.0.1:39342_solr) [n:127.0.0.1:39342_solr ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@52cbb06b name: ZooKeeperConnection Watcher:127.0.0.1:41596/solr got event WatchedEvent state:Expired type:None path:null path: null type: None
[junit4] 2> 4346260 WARN (zkConnectionManagerCallback-3312-thread-1-processing-n:127.0.0.1:39342_solr) [n:127.0.0.1:39342_solr ] o.a.s.c.c.ConnectionManager Our previous ZooKeeper session was expired. Attempting to reconnect to recover relationship with ZooKeeper...
[junit4] 2> 4346260 WARN (zkConnectionManagerCallback-3312-thread-1-processing-n:127.0.0.1:39342_solr) [n:127.0.0.1:39342_solr ] o.a.s.c.c.DefaultConnectionStrategy Connection expired - starting a new one...
[junit4] 2> 4346261 INFO (jetty-closer-3245-thread-3) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@3858be78{SSL,[ssl, http/1.1]}{127.0.0.1:0}
[junit4] 2> 4346261 INFO (jetty-closer-3245-thread-5) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@73adf1e9{SSL,[ssl, http/1.1]}{127.0.0.1:0}
[junit4] 2> 4346261 INFO (jetty-closer-3245-thread-2) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=636584105
[junit4] 2> 4346262 INFO (jetty-closer-3245-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=257578446
[junit4] 2> 4346277 INFO (jetty-closer-3245-thread-4) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 4346278 INFO (jetty-closer-3245-thread-4) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@3ceb934: rootName = solr_43438, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@54dafa64
[junit4] 2> 4346297 INFO (jetty-closer-3245-thread-4) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 4346297 INFO (jetty-closer-3245-thread-4) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4903008f: rootName = solr_43438, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@58e530b9
[junit4] 2> 4346299 INFO (jetty-closer-3245-thread-4) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:43438_solr
[junit4] 2> 4346455 INFO (jetty-closer-3245-thread-3) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1756870342
[junit4] 2> 4346456 INFO (jetty-closer-3245-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 4346456 INFO (jetty-closer-3245-thread-5) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=112393377
[junit4] 2> 4346456 INFO (jetty-closer-3245-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@53323a74: rootName = solr_40047, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@2aa83991
[junit4] 2> 4346456 INFO (jetty-closer-3245-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 4346456 INFO (jetty-closer-3245-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@3fe831ca: rootName = solr_41067, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@2362d6be
[junit4] 2> 4346457 INFO (jetty-closer-3245-thread-5) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 4346457 INFO (jetty-closer-3245-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 4346457 INFO (jetty-closer-3245-thread-5) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@5ec5eb18: rootName = solr_39342, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@54dda500
[junit4] 2> 4346457 INFO (jetty-closer-3245-thread-3) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@375e3e85: rootName = solr_46166, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@710efb3d
[junit4] 2> 4346513 INFO (jetty-closer-3245-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 4346513 INFO (jetty-closer-3245-thread-3) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@12634cdf: rootName = solr_46166, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@54dafa64
[junit4] 2> 4346527 INFO (zkConnectionManagerCallback-3312-thread-1-processing-n:127.0.0.1:39342_solr-EventThread) [n:127.0.0.1:39342_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4346527 INFO (zkConnectionManagerCallback-3312-thread-1-processing-n:127.0.0.1:39342_solr) [n:127.0.0.1:39342_solr ] o.a.s.c.c.ConnectionManager Connection with ZooKeeper reestablished.
[junit4] 2> 4346675 INFO (jetty-closer-3245-thread-5) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 4346675 INFO (jetty-closer-3245-thread-5) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@3893e46a: rootName = solr_39342, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@54dafa64
[junit4] 2> 4346675 INFO (jetty-closer-3245-thread-4) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 4346694 INFO (jetty-closer-3245-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 4346695 INFO (jetty-closer-3245-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1d582c29: rootName = solr_40047, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@54dafa64
[junit4] 2> 4346712 INFO (jetty-closer-3245-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 4346712 INFO (jetty-closer-3245-thread-3) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@3efd9aad: rootName = solr_46166, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@58e530b9
[junit4] 2> 4346782 INFO (zkCallback-3278-thread-2-processing-n:127.0.0.1:40047_solr) [n:127.0.0.1:40047_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (4)
[junit4] 2> 4346783 INFO (zkCallback-3304-thread-1-processing-n:127.0.0.1:40047_solr) [n:127.0.0.1:40047_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (4)
[junit4] 2> 4346783 INFO (jetty-closer-3245-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 4346784 INFO (jetty-closer-3245-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@592273ab: rootName = solr_41067, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@54dafa64
[junit4] 2> 4346785 INFO (zkCallback-3276-thread-1-processing-n:127.0.0.1:39342_solr) [n:127.0.0.1:39342_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (4)
[junit4] 2> 4346805 INFO (jetty-closer-3245-thread-5) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 4346805 INFO (jetty-closer-3245-thread-5) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@a60374d: rootName = solr_39342, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@58e530b9
[junit4] 2> 4346814 INFO (zkCallback-3281-thread-1-processing-n:127.0.0.1:41067_solr) [n:127.0.0.1:41067_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (4)
[junit4] 2> 4346818 INFO (zkCallback-3307-thread-5-processing-n:127.0.0.1:46166_solr) [n:127.0.0.1:46166_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (4)
[junit4] 2> 4346819 INFO (zkConnectionManagerCallback-3312-thread-1-processing-n:127.0.0.1:39342_solr) [n:127.0.0.1:39342_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (4)
[junit4] 2> 4346819 INFO (jetty-closer-3245-thread-3) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:46166_solr
[junit4] 2> 4346820 INFO (zkCallback-3299-thread-4-processing-n:127.0.0.1:41067_solr) [n:127.0.0.1:41067_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (4)
[junit4] 2> 4346820 INFO (zkCallback-3272-thread-2-processing-n:127.0.0.1:43438_solr) [n:127.0.0.1:43438_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (4)
[junit4] 2> 4346820 INFO (zkCallback-3288-thread-1-processing-n:127.0.0.1:46166_solr) [n:127.0.0.1:46166_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (4)
[junit4] 2> 4346839 INFO (jetty-closer-3245-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 4346839 INFO (jetty-closer-3245-thread-3) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 4346840 INFO (zkCallback-3304-thread-1-processing-n:127.0.0.1:40047_solr) [n:127.0.0.1:40047_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 4346840 INFO (zkCallback-3278-thread-2-processing-n:127.0.0.1:40047_solr) [n:127.0.0.1:40047_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 4346851 INFO (jetty-closer-3245-thread-4) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 4346855 INFO (zkCallback-3295-thread-2-processing-n:127.0.0.1:43438_solr) [n:127.0.0.1:43438_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (3)
[junit4] 2> 4346855 INFO (zkCallback-3299-thread-4-processing-n:127.0.0.1:41067_solr) [n:127.0.0.1:41067_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 4346855 INFO (zkCallback-3272-thread-1-processing-n:127.0.0.1:43438_solr) [n:127.0.0.1:43438_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 4346856 INFO (jetty-closer-3245-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 4346856 INFO (jetty-closer-3245-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 4346856 INFO (jetty-closer-3245-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4c60d31e: rootName = solr_41067, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@58e530b9
[junit4] 2> 4346856 INFO (jetty-closer-3245-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@2deb6755: rootName = solr_40047, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@58e530b9
[junit4] 2> 4346871 INFO (jetty-closer-3245-thread-4) [ ] o.a.s.c.Overseer Overseer (id=72524237564346377-127.0.0.1:43438_solr-n_0000000000) closing
[junit4] 2> 4346875 INFO (zkCallback-3307-thread-5-processing-n:127.0.0.1:46166_solr) [n:127.0.0.1:46166_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 4346875 WARN (OverseerAutoScalingTriggerThread-72524237564346377-127.0.0.1:43438_solr-n_0000000000) [n:127.0.0.1:43438_solr ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 4347074 INFO (zkCallback-3281-thread-2-processing-n:127.0.0.1:41067_solr) [n:127.0.0.1:41067_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 4347074 INFO (zkCallback-3288-thread-2-processing-n:127.0.0.1:46166_solr) [n:127.0.0.1:46166_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 4347075 INFO (jetty-closer-3245-thread-5) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:39342_solr
[junit4] 2> 4347076 INFO (jetty-closer-3245-thread-2) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:41067_solr
[junit4] 2> 4347077 INFO (jetty-closer-3245-thread-5) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 4347077 INFO (jetty-closer-3245-thread-5) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 4347090 INFO (zkCallback-3295-thread-2-processing-n:127.0.0.1:43438_solr) [n:127.0.0.1:43438_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 4347090 INFO (zkCallback-3307-thread-5-processing-n:127.0.0.1:46166_solr) [n:127.0.0.1:46166_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 4347090 INFO (zkCallback-3299-thread-4-processing-n:127.0.0.1:41067_solr) [n:127.0.0.1:41067_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 4347107 INFO (zkCallback-3272-thread-3-processing-n:127.0.0.1:43438_solr) [n:127.0.0.1:43438_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 4347126 INFO (zkCallback-3311-thread-1-processing-n:127.0.0.1:39342_solr) [n:127.0.0.1:39342_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 4347219 INFO (jetty-closer-3245-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 4347219 INFO (jetty-closer-3245-thread-2) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 4347237 INFO (zkCallback-3299-thread-4-processing-n:127.0.0.1:41067_solr) [n:127.0.0.1:41067_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 4347237 INFO (zkCallback-3281-thread-2-processing-n:127.0.0.1:41067_solr) [n:127.0.0.1:41067_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (1)
[junit4] 2> 4347237 INFO (zkCallback-3295-thread-2-processing-n:127.0.0.1:43438_solr) [n:127.0.0.1:43438_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 4347237 INFO (zkCallback-3272-thread-3-processing-n:127.0.0.1:43438_solr) [n:127.0.0.1:43438_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 4347237 INFO (zkCallback-3278-thread-2-processing-n:127.0.0.1:40047_solr) [n:127.0.0.1:40047_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (1)
[junit4] 2> 4347110 INFO (zkConnectionManagerCallback-3312-thread-1-processing-n:127.0.0.1:39342_solr) [n:127.0.0.1:39342_solr ] o.a.s.c.c.DefaultConnectionStrategy Reconnected to ZooKeeper
[junit4] 2> 4347239 INFO (zkConnectionManagerCallback-3312-thread-1-processing-n:127.0.0.1:39342_solr) [n:127.0.0.1:39342_solr ] o.a.s.c.c.ConnectionManager zkClient Connected:true
[junit4] 2> 4347110 INFO (OverseerStateUpdate-72524237564346377-127.0.0.1:43438_solr-n_0000000000) [n:127.0.0.1:43438_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:43438_solr
[junit4] 2> 4347252 INFO (zkCallback-3311-thread-4-processing-n:127.0.0.1:39342_solr) [n:127.0.0.1:39342_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (1)
[junit4] 2> 4347253 INFO (jetty-closer-3245-thread-1) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:40047_solr
[junit4] 2> 4347254 INFO (jetty-closer-3245-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 4347254 INFO (jetty-closer-3245-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 4347254 INFO (zkCallback-3311-thread-4-processing-n:127.0.0.1:39342_solr) [n:127.0.0.1:39342_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 4347254 INFO (zkCallback-3278-thread-2-processing-n:127.0.0.1:40047_solr) [n:127.0.0.1:40047_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 4347254 INFO (zkCallback-3281-thread-2-processing-n:127.0.0.1:41067_solr) [n:127.0.0.1:41067_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 4347254 INFO (zkCallback-3295-thread-2-processing-n:127.0.0.1:43438_solr) [n:127.0.0.1:43438_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 4347255 INFO (zkCallback-3299-thread-4-processing-n:127.0.0.1:41067_solr) [n:127.0.0.1:41067_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 4347248 INFO (zkCallback-3304-thread-1-processing-n:127.0.0.1:40047_solr) [n:127.0.0.1:40047_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 4347218 INFO (zkCallback-3276-thread-2-processing-n:127.0.0.1:39342_solr) [n:127.0.0.1:39342_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 4347747 INFO (zkCallback-3272-thread-1-processing-n:127.0.0.1:43438_solr) [n:127.0.0.1:43438_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 4347914 INFO (zkCallback-3288-thread-2-processing-n:127.0.0.1:46166_solr) [n:127.0.0.1:46166_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (0)
[junit4] 2> 4347930 INFO (zkCallback-3276-thread-3-processing-n:127.0.0.1:39342_solr) [n:127.0.0.1:39342_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (0)
[junit4] 2> 4348187 INFO (jetty-closer-3245-thread-5) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@36a052a{/solr,null,UNAVAILABLE}
[junit4] 2> 4348222 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x101a868e9a1000e, likely client has closed socket
[junit4] 2> 4348224 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x101a868e9a10009, likely client has closed socket
[junit4] 2> 4348224 INFO (jetty-closer-3245-thread-5) [ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 4348259 INFO (jetty-closer-3245-thread-4) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@3a607178{/solr,null,UNAVAILABLE}
[junit4] 2> 4348261 INFO (jetty-closer-3245-thread-4) [ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 4348288 INFO (zkCallback-3278-thread-2-processing-n:127.0.0.1:40047_solr) [n:127.0.0.1:40047_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:40047_solr
[junit4] 2> 4348399 INFO (jetty-closer-3245-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@d76654{/solr,null,UNAVAILABLE}
[junit4] 2> 4348401 INFO (jetty-closer-3245-thread-2) [ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 4348753 WARN (zkCallback-3307-thread-5-processing-n:127.0.0.1:46166_solr) [n:127.0.0.1:46166_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 4349172 INFO (jetty-closer-3245-thread-3) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@70f937ba{/solr,null,UNAVAILABLE}
[junit4] 2> 4349261 INFO (jetty-closer-3245-thread-3) [ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 4349273 WARN (zkCallback-3304-thread-2-processing-n:127.0.0.1:40047_solr) [n:127.0.0.1:40047_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 4349458 INFO (jetty-closer-3245-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@aa7a730{/solr,null,UNAVAILABLE}
[junit4] 2> 4349460 INFO (jetty-closer-3245-thread-1) [ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 4349473 ERROR (TEST-PingRequestHandlerTest.testPingInClusterWithNoHealthCheck-seed#[B5C5E7D1136C9683]) [ ] 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> 4349475 INFO (TEST-PingRequestHandlerTest.testPingInClusterWithNoHealthCheck-seed#[B5C5E7D1136C9683]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:41596 41596
[junit4] 2> 4349765 INFO (Thread-4203) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:41596 41596
[junit4] 2> 4349865 WARN (Thread-4203) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 13 /solr/aliases.json
[junit4] 2> 5 /solr/security.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 13 /solr/clusterstate.json
[junit4] 2> 13 /solr/clusterprops.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 13 /solr/live_nodes
[junit4] 2> 13 /solr/collections
[junit4] 2>
[junit4] 2> 4349920 INFO (TEST-PingRequestHandlerTest.testPingInClusterWithNoHealthCheck-seed#[B5C5E7D1136C9683]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testPingInClusterWithNoHealthCheck
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=PingRequestHandlerTest -Dtests.method=testPingInClusterWithNoHealthCheck -Dtests.seed=B5C5E7D1136C9683 -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=und -Dtests.timezone=America/Cuiaba -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] ERROR 21.0s J1 | PingRequestHandlerTest.testPingInClusterWithNoHealthCheck <<<
[junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at https://127.0.0.1:40047/solr: KeeperErrorCode = Session expired for /configs/solrCloudCollectionConfig
[junit4] > at __randomizedtesting.SeedInfo.seed([B5C5E7D1136C9683:5B1659019680AC67]:0)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:643)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:255)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:244)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:483)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:413)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1105)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:885)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:818)
[junit4] > at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:194)
[junit4] > at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:211)
[junit4] > at org.apache.solr.handler.PingRequestHandlerTest.testPingInClusterWithNoHealthCheck(PingRequestHandlerTest.java:195)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 4349957 INFO (SUITE-PingRequestHandlerTest-seed#[B5C5E7D1136C9683]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> 4349957 INFO (SUITE-PingRequestHandlerTest-seed#[B5C5E7D1136C9683]-worker) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=243116950
[junit4] 2> 4349957 INFO (SUITE-PingRequestHandlerTest-seed#[B5C5E7D1136C9683]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 4349957 INFO (SUITE-PingRequestHandlerTest-seed#[B5C5E7D1136C9683]-worker) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@69183fbb: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@548289be
[junit4] 2> 4349973 INFO (SUITE-PingRequestHandlerTest-seed#[B5C5E7D1136C9683]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 4349973 INFO (SUITE-PingRequestHandlerTest-seed#[B5C5E7D1136C9683]-worker) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@65e66396: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@54dafa64
[junit4] 2> 4350008 INFO (SUITE-PingRequestHandlerTest-seed#[B5C5E7D1136C9683]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 4350008 INFO (SUITE-PingRequestHandlerTest-seed#[B5C5E7D1136C9683]-worker) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@456f8a28: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@58e530b9
[junit4] 2> 4350064 INFO (coreCloseExecutor-5957-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@16ef6930
[junit4] 2> 4350064 INFO (coreCloseExecutor-5957-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=384788784
[junit4] 2> 4350064 INFO (coreCloseExecutor-5957-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@23e9c75: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1 / com.codahale.metrics.MetricRegistry@5f8b31d6
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.3/solr/build/solr-core/test/J1/temp/solr.handler.PingRequestHandlerTest_B5C5E7D1136C9683-001
[junit4] 2> NOTE: test params are: codec=FastDecompressionCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=FAST_DECOMPRESSION, chunkSize=4373, maxDocsPerChunk=10, blockSize=7), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=FAST_DECOMPRESSION, chunkSize=4373, blockSize=7)), sim=RandomSimilarity(queryNorm=false): {}, locale=und, timezone=America/Cuiaba
[junit4] 2> NOTE: Linux 4.4.0-112-generic amd64/Oracle Corporation 1.8.0_152 (64-bit)/cpus=4,threads=1,free=243572056,total=529530880
[junit4] 2> NOTE: All tests run in this JVM: [TestDynamicLoading, ChaosMonkeySafeLeaderTest, ScriptEngineTest, DeleteInactiveReplicaTest, TestXIncludeConfig, SuggestComponentContextFilterQueryTest, DateRangeFieldTest, LeaderFailoverAfterPartitionTest, TestXmlQParser, PeerSyncReplicationTest, PeerSyncTest, BlockCacheTest, TestReRankQParserPlugin, TestConfigSetsAPI, TestHdfsCloudBackupRestore, AssignTest, BitVectorTest, DocExpirationUpdateProcessorFactoryTest, TestUninvertingReader, TestManagedSchemaThreadSafety, ActionThrottleTest, InfoHandlerTest, RegexBytesRefFilterTest, MetricUtilsTest, BadComponentTest, TestRuleBasedAuthorizationPlugin, SignatureUpdateProcessorFactoryTest, MergeStrategyTest, VMParamsZkACLAndCredentialsProvidersTest, AutoScalingHandlerTest, TestReplicationHandler, TestFastLRUCache, TestSolrIndexConfig, TestTlogReplica, TestJsonFacetRefinement, HdfsAutoAddReplicasIntegrationTest, TestCharFilters, TestStandardQParsers, RequestLoggingTest, TestTrackingShardHandlerFactory, NodeAddedTriggerTest, CSVRequestHandlerTest, RulesTest, DistributedFacetPivotWhiteBoxTest, PreAnalyzedUpdateProcessorTest, UpdateRequestProcessorFactoryTest, AssignBackwardCompatibilityTest, QueryEqualityTest, TestRecovery, HdfsTlogReplayBufferedWhileIndexingTest, TestQueryWrapperFilter, MoveReplicaHDFSFailoverTest, TestApiFramework, TestNestedDocsSort, TestComplexPhraseQParserPlugin, TestMissingGroups, TestLegacyFieldCache, SimplePostToolTest, FastVectorHighlighterTest, TestGeoJSONResponseWriter, DirectSolrConnectionTest, TestSchemaResource, DistributedIntervalFacetingTest, DirectoryFactoryTest, TestBlobHandler, PolyFieldTest, TestMaxTokenLenTokenizer, HdfsDirectoryTest, TestConfigSetImmutable, SolrCloudExampleTest, BaseCdcrDistributedZkTest, ZkStateWriterTest, TestSchemalessBufferedUpdates, QueryResultKeyTest, SoftAutoCommitTest, BJQParserTest, SolrCoreTest, TestIntervalFaceting, BasicZkTest, TestSubQueryTransformer, TestCorePropertiesReload, BasicFunctionalityTest, TestCursorMarkWithoutUniqueKey, TestBulkSchemaAPI, TestSolr4Spatial2, FieldMutatingUpdateProcessorTest, TriggerIntegrationTest, TestEmbeddedSolrServerSchemaAPI, TestImpersonationWithHadoopAuth, V2ApiIntegrationTest, TestElisionMultitermQuery, TestRequestForwarding, ChaosMonkeySafeLeaderWithPullReplicasTest, TestTrie, TestInitParams, JsonLoaderTest, SystemInfoHandlerTest, SolrIndexMetricsTest, TestShardHandlerFactory, TestPerFieldSimilarity, TestSweetSpotSimilarityFactory, SuggesterFSTTest, TestSimpleTrackingShardHandler, MetricsConfigTest, DistributedSuggestComponentTest, SortByFunctionTest, DOMUtilTest, DistribCursorPagingTest, TestCloudManagedSchema, FileUtilsTest, TestPolicyCloud, TestRequestStatusCollectionAPI, IndexSchemaTest, TestClassicSimilarityFactory, TestJsonRequest, CdcrReplicationDistributedZkTest, OverriddenZkACLAndCredentialsProvidersTest, TestSolrXml, TestFileDictionaryLookup, TestDistribStateManager, CachingDirectoryFactoryTest, MultiThreadedOCPTest, SpellCheckCollatorWithCollapseTest, SampleTest, TestSerializedLuceneMatchVersion, SolrMetricReporterTest, PathHierarchyTokenizerFactoryTest, TermsComponentTest, BasicDistributedZk2Test, SyncSliceTest, ShardRoutingTest, RecoveryZkTest, TestRandomFaceting, ZkCLITest, ShardRoutingCustomTest, TestDistributedGrouping, ZkControllerTest, TestRealTimeGet, TestReload, DistributedTermsComponentTest, StatsComponentTest, BadIndexSchemaTest, TestFunctionQuery, DistributedQueryElevationComponentTest, CoreAdminHandlerTest, SolrCoreCheckLockOnStartupTest, TestWordDelimiterFilterFactory, TestRemoteStreaming, DebugComponentTest, LukeRequestHandlerTest, TestIndexingPerformance, IndexSchemaRuntimeFieldTest, SolrPluginUtilsTest, UniqFieldsUpdateProcessorFactoryTest, PingRequestHandlerTest]
[junit4] Completed [474/783 (1!)] on J1 in 26.32s, 6 tests, 1 error <<< FAILURES!
[...truncated 50632 lines...]