Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Linux/1106/
Java: 64bit/jdk-9.0.1 -XX:-UseCompressedOops -XX:+UseG1GC
2 tests failed.
FAILED: org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testEventQueue
Error Message:
action wasn't interrupted
Stack Trace:
java.lang.AssertionError: action wasn't interrupted
at
__randomizedtesting.SeedInfo.seed([5BFC67CD2302993B:924925632A655FCE]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at
org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testEventQueue(TriggerIntegrationTest.java:711)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:564)
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
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.base/java.lang.Thread.run(Thread.java:844)
FAILED: org.apache.solr.metrics.reporters.solr.SolrShardReporterTest.test
Error Message:
Timeout occured while waiting response from server at: http://127.0.0.1:44667
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: Timeout occured while waiting
response from server at: http://127.0.0.1:44667
at
__randomizedtesting.SeedInfo.seed([5BFC67CD2302993B:D3A858178DFEF4C3]:0)
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.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:1104)
at
org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:884)
at
org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:817)
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.cloud.AbstractFullDistribZkTestBase.createServers(AbstractFullDistribZkTestBase.java:320)
at
org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:991)
at
org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:968)
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
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.base/java.lang.Thread.run(Thread.java:844)
Caused by: java.net.SocketTimeoutException: Read timed out
at java.base/java.net.SocketInputStream.socketRead0(Native Method)
at
java.base/java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
at java.base/java.net.SocketInputStream.read(SocketInputStream.java:171)
at java.base/java.net.SocketInputStream.read(SocketInputStream.java:141)
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)
... 42 more
Build Log:
[...truncated 12639 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.TriggerIntegrationTest
[junit4] 2> 1023148 INFO
(SUITE-TriggerIntegrationTest-seed#[5BFC67CD2302993B]-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/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_5BFC67CD2302993B-001/init-core-data-001
[junit4] 2> 1023148 WARN
(SUITE-TriggerIntegrationTest-seed#[5BFC67CD2302993B]-worker) [ ]
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=6 numCloses=6
[junit4] 2> 1023148 INFO
(SUITE-TriggerIntegrationTest-seed#[5BFC67CD2302993B]-worker) [ ]
o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true)
w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 1023149 INFO
(SUITE-TriggerIntegrationTest-seed#[5BFC67CD2302993B]-worker) [ ]
o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via:
@org.apache.solr.util.RandomizeSSL(reason="", ssl=0.0/0.0, value=0.0/0.0,
clientAuth=0.0/0.0)
[junit4] 2> 1023149 INFO
(SUITE-TriggerIntegrationTest-seed#[5BFC67CD2302993B]-worker) [ ]
o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_5BFC67CD2302993B-001/tempDir-001
[junit4] 2> 1023149 INFO
(SUITE-TriggerIntegrationTest-seed#[5BFC67CD2302993B]-worker) [ ]
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 1023158 INFO (Thread-1536) [ ] o.a.s.c.ZkTestServer client
port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1023158 INFO (Thread-1536) [ ] o.a.s.c.ZkTestServer
Starting server
[junit4] 2> 1023159 ERROR (Thread-1536) [ ] 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> 1023249 INFO
(SUITE-TriggerIntegrationTest-seed#[5BFC67CD2302993B]-worker) [ ]
o.a.s.c.ZkTestServer start zk server on port:41913
[junit4] 2> 1023251 INFO (zkConnectionManagerCallback-1526-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1023254 INFO (jetty-launcher-1523-thread-1) [ ]
o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 1023254 INFO (jetty-launcher-1523-thread-2) [ ]
o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 1023255 INFO (jetty-launcher-1523-thread-1) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@53684d6a{/solr,null,AVAILABLE}
[junit4] 2> 1023255 INFO (jetty-launcher-1523-thread-2) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@43fd59d5{/solr,null,AVAILABLE}
[junit4] 2> 1023260 INFO (jetty-launcher-1523-thread-2) [ ]
o.e.j.s.AbstractConnector Started ServerConnector@6c7fa7d9{SSL,[ssl,
http/1.1]}{127.0.0.1:33721}
[junit4] 2> 1023260 INFO (jetty-launcher-1523-thread-1) [ ]
o.e.j.s.AbstractConnector Started ServerConnector@cb2b402{SSL,[ssl,
http/1.1]}{127.0.0.1:41887}
[junit4] 2> 1023260 INFO (jetty-launcher-1523-thread-2) [ ]
o.e.j.s.Server Started @1025274ms
[junit4] 2> 1023260 INFO (jetty-launcher-1523-thread-1) [ ]
o.e.j.s.Server Started @1025274ms
[junit4] 2> 1023260 INFO (jetty-launcher-1523-thread-2) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=33721}
[junit4] 2> 1023260 INFO (jetty-launcher-1523-thread-1) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=41887}
[junit4] 2> 1023261 ERROR (jetty-launcher-1523-thread-1) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 1023261 ERROR (jetty-launcher-1523-thread-2) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 1023261 INFO (jetty-launcher-1523-thread-1) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
7.3.0
[junit4] 2> 1023261 INFO (jetty-launcher-1523-thread-2) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
7.3.0
[junit4] 2> 1023261 INFO (jetty-launcher-1523-thread-1) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1023261 INFO (jetty-launcher-1523-thread-2) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1023261 INFO (jetty-launcher-1523-thread-1) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1023261 INFO (jetty-launcher-1523-thread-2) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1023261 INFO (jetty-launcher-1523-thread-1) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-01-03T01:49:57.063196Z
[junit4] 2> 1023261 INFO (jetty-launcher-1523-thread-2) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-01-03T01:49:57.063233Z
[junit4] 2> 1023262 INFO (zkConnectionManagerCallback-1530-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1023262 INFO (jetty-launcher-1523-thread-2) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1023263 INFO (zkConnectionManagerCallback-1528-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1023264 INFO (jetty-launcher-1523-thread-1) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1023281 INFO (jetty-launcher-1523-thread-2) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41913/solr
[junit4] 2> 1023282 INFO (zkConnectionManagerCallback-1534-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1023283 INFO (jetty-launcher-1523-thread-1) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41913/solr
[junit4] 2> 1023283 INFO (zkConnectionManagerCallback-1538-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1023283 INFO
(zkConnectionManagerCallback-1540-thread-1-processing-n:127.0.0.1:33721_solr)
[n:127.0.0.1:33721_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1023285 INFO
(zkConnectionManagerCallback-1542-thread-1-processing-n:127.0.0.1:41887_solr)
[n:127.0.0.1:41887_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1023314 INFO (jetty-launcher-1523-thread-2)
[n:127.0.0.1:33721_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1023314 INFO (jetty-launcher-1523-thread-2)
[n:127.0.0.1:33721_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:33721_solr
[junit4] 2> 1023314 INFO (jetty-launcher-1523-thread-1)
[n:127.0.0.1:41887_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1023315 INFO (jetty-launcher-1523-thread-2)
[n:127.0.0.1:33721_solr ] o.a.s.c.Overseer Overseer
(id=99283382892036101-127.0.0.1:33721_solr-n_0000000000) starting
[junit4] 2> 1023315 INFO (jetty-launcher-1523-thread-1)
[n:127.0.0.1:41887_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:41887_solr
[junit4] 2> 1023316 INFO
(zkCallback-1541-thread-1-processing-n:127.0.0.1:41887_solr)
[n:127.0.0.1:41887_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 1023326 INFO
(zkCallback-1539-thread-1-processing-n:127.0.0.1:33721_solr)
[n:127.0.0.1:33721_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 1023342 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036101-127.0.0.1:33721_solr-n_0000000000)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.OverseerTriggerThread Adding
.autoAddReplicas trigger
[junit4] 2> 1023342 INFO (jetty-launcher-1523-thread-2)
[n:127.0.0.1:33721_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:33721_solr
[junit4] 2> 1023342 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036101-127.0.0.1:33721_solr-n_0000000000)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 1
[junit4] 2> 1023343 INFO
(zkCallback-1541-thread-1-processing-n:127.0.0.1:41887_solr)
[n:127.0.0.1:41887_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 1023343 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036101-127.0.0.1:33721_solr-n_0000000000)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:41887_solr]
[junit4] 2> 1023343 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036101-127.0.0.1:33721_solr-n_0000000000)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 1, lastZnodeVersion -1
[junit4] 2> 1023343 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036101-127.0.0.1:33721_solr-n_0000000000)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 1
[junit4] 2> 1023343 INFO
(zkCallback-1539-thread-1-processing-n:127.0.0.1:33721_solr)
[n:127.0.0.1:33721_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 1023344 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036101-127.0.0.1:33721_solr-n_0000000000)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 1023344 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036101-127.0.0.1:33721_solr-n_0000000000)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 1023344 DEBUG (ScheduledTrigger-3378-thread-1)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 1023360 INFO (jetty-launcher-1523-thread-1)
[n:127.0.0.1:41887_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_41887.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5d5e8331
[junit4] 2> 1023366 INFO (jetty-launcher-1523-thread-2)
[n:127.0.0.1:33721_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_33721.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5d5e8331
[junit4] 2> 1023368 INFO (jetty-launcher-1523-thread-1)
[n:127.0.0.1:41887_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_41887.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5d5e8331
[junit4] 2> 1023368 INFO (jetty-launcher-1523-thread-1)
[n:127.0.0.1:41887_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_41887.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5d5e8331
[junit4] 2> 1023369 INFO (jetty-launcher-1523-thread-1)
[n:127.0.0.1:41887_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_5BFC67CD2302993B-001/tempDir-001/node1/.
[junit4] 2> 1023371 INFO (jetty-launcher-1523-thread-2)
[n:127.0.0.1:33721_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_33721.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5d5e8331
[junit4] 2> 1023371 INFO (jetty-launcher-1523-thread-2)
[n:127.0.0.1:33721_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_33721.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5d5e8331
[junit4] 2> 1023371 INFO (jetty-launcher-1523-thread-2)
[n:127.0.0.1:33721_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_5BFC67CD2302993B-001/tempDir-001/node2/.
[junit4] 2> 1023406 INFO (zkConnectionManagerCallback-1548-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1023408 INFO (zkConnectionManagerCallback-1552-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1023408 INFO
(SUITE-TriggerIntegrationTest-seed#[5BFC67CD2302993B]-worker) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1023409 INFO
(SUITE-TriggerIntegrationTest-seed#[5BFC67CD2302993B]-worker) [ ]
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:41913/solr ready
[junit4] 2> 1023418 INFO
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5BFC67CD2302993B]) [ ]
o.a.s.SolrTestCaseJ4 ###Starting testSetProperties
[junit4] 2> 1023418 INFO
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5BFC67CD2302993B]) [ ]
o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 2
[junit4] 2> 1023418 DEBUG
(zkCallback-1539-thread-1-processing-n:127.0.0.1:33721_solr)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 2
[junit4] 2> 1023418 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036101-127.0.0.1:33721_solr-n_0000000000)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 2
[junit4] 2> 1023420 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036101-127.0.0.1:33721_solr-n_0000000000)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 1023420 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036101-127.0.0.1:33721_solr-n_0000000000)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 1023420 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036101-127.0.0.1:33721_solr-n_0000000000)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 1024426 DEBUG
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5BFC67CD2302993B]) [ ]
o.a.s.c.a.ScheduledTriggers Changing value of autoscaling property:
triggerScheduleDelaySeconds from: 1 to: 4
[junit4] 2> 1032428 DEBUG
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5BFC67CD2302993B]) [ ]
o.a.s.c.a.ScheduledTriggers Changing value of autoscaling property:
triggerScheduleDelaySeconds from: 4 to: 1
[junit4] 2> 1042431 DEBUG
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5BFC67CD2302993B]) [ ]
o.a.s.c.a.ScheduledTriggers Changing value of autoscaling property:
triggerCorePoolSize from: 4 to: 6
[junit4] 2> 1052435 INFO
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5BFC67CD2302993B]) [ ]
o.a.s.SolrTestCaseJ4 ###Ending testSetProperties
[junit4] 2> 1052440 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B]) [ ]
o.a.s.SolrTestCaseJ4 ###Starting testEventQueue
[junit4] 2> 1052440 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B]) [ ]
o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 3
[junit4] 2> 1052441 DEBUG
(zkCallback-1539-thread-1-processing-n:127.0.0.1:33721_solr)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 3
[junit4] 2> 1052441 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036101-127.0.0.1:33721_solr-n_0000000000)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 3
[junit4] 2> 1052441 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036101-127.0.0.1:33721_solr-n_0000000000)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 1052441 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036101-127.0.0.1:33721_solr-n_0000000000)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 1052441 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036101-127.0.0.1:33721_solr-n_0000000000)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 1052455 INFO (qtp1188638725-7867) [n:127.0.0.1:33721_solr
] o.a.s.h.a.CollectionsHandler Invoked Collection Action :overseerstatus with
params action=OVERSEERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1052459 INFO (qtp1188638725-7867) [n:127.0.0.1:33721_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections
params={action=OVERSEERSTATUS&wt=javabin&version=2} status=0 QTime=4
[junit4] 2> 1052464 INFO (qtp1188638725-7860) [n:127.0.0.1:33721_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0
QTime=0
[junit4] 2> 1052475 INFO (qtp1668135643-7872) [n:127.0.0.1:41887_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0
QTime=0
[junit4] 2> 1052475 DEBUG (qtp1188638725-7869) [n:127.0.0.1:33721_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1052476 DEBUG
(zkCallback-1539-thread-1-processing-n:127.0.0.1:33721_solr)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 4
[junit4] 2> 1052476 INFO (qtp1188638725-7869) [n:127.0.0.1:33721_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=15
[junit4] 2> 1052476 INFO
(zkCallback-1539-thread-1-processing-n:127.0.0.1:33721_solr)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.TriggerIntegrationTest
TestEventQueueAction instantiated
[junit4] 2> 1052476 DEBUG
(zkCallback-1539-thread-1-processing-n:127.0.0.1:33721_solr)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:41887_solr, 127.0.0.1:33721_solr]
[junit4] 2> 1052476 DEBUG
(zkCallback-1539-thread-1-processing-n:127.0.0.1:33721_solr)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=1,
actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestEventQueueAction}],
enabled=true}
[junit4] 2> 1052476 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036101-127.0.0.1:33721_solr-n_0000000000)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 4
[junit4] 2> 1052477 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036101-127.0.0.1:33721_solr-n_0000000000)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 1052477 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036101-127.0.0.1:33721_solr-n_0000000000)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 1052477 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036101-127.0.0.1:33721_solr-n_0000000000)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 1052478 DEBUG (ScheduledTrigger-3378-thread-2)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 1052478 DEBUG (ScheduledTrigger-3378-thread-2)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1052479 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B]) [ ]
o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 1052479 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B]) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@7dd2a06f{/solr,null,AVAILABLE}
[junit4] 2> 1052480 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B]) [ ]
o.e.j.s.AbstractConnector Started ServerConnector@19ab9164{SSL,[ssl,
http/1.1]}{127.0.0.1:33209}
[junit4] 2> 1052480 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B]) [ ]
o.e.j.s.Server Started @1054493ms
[junit4] 2> 1052480 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B]) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=33209}
[junit4] 2> 1052480 ERROR
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B]) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 1052480 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B]) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
7.3.0
[junit4] 2> 1052480 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B]) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1052480 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B]) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1052480 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B]) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-01-03T01:50:26.282750Z
[junit4] 2> 1052482 INFO (zkConnectionManagerCallback-1554-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1052482 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B]) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1052487 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B]) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41913/solr
[junit4] 2> 1052488 INFO (zkConnectionManagerCallback-1558-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1052491 INFO
(zkConnectionManagerCallback-1560-thread-1-processing-n:127.0.0.1:33209_solr)
[n:127.0.0.1:33209_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1052493 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B])
[n:127.0.0.1:33209_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (2)
[junit4] 2> 1052494 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B])
[n:127.0.0.1:33209_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1052495 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B])
[n:127.0.0.1:33209_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:33209_solr
[junit4] 2> 1052496 INFO
(zkCallback-1541-thread-1-processing-n:127.0.0.1:41887_solr)
[n:127.0.0.1:41887_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 1052496 INFO
(zkCallback-1539-thread-1-processing-n:127.0.0.1:33721_solr)
[n:127.0.0.1:33721_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 1052496 INFO (zkCallback-1551-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1052496 INFO
(zkCallback-1559-thread-1-processing-n:127.0.0.1:33209_solr)
[n:127.0.0.1:33209_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 1052565 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B])
[n:127.0.0.1:33209_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_33209.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5d5e8331
[junit4] 2> 1052576 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B])
[n:127.0.0.1:33209_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_33209.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5d5e8331
[junit4] 2> 1052576 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B])
[n:127.0.0.1:33209_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_33209.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5d5e8331
[junit4] 2> 1052578 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B])
[n:127.0.0.1:33209_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_5BFC67CD2302993B-001/tempDir-001/node3/.
[junit4] 2> 1053479 DEBUG (ScheduledTrigger-3378-thread-1)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 1053479 DEBUG (ScheduledTrigger-3378-thread-1)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1053479 DEBUG (ScheduledTrigger-3378-thread-1)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node:
127.0.0.1:33209_solr at time 2645369253298307
[junit4] 2> 1054457 INFO
(OverseerCollectionConfigSetProcessor-99283382892036101-127.0.0.1:33721_solr-n_0000000000)
[n:127.0.0.1:33721_solr ] o.a.s.c.OverseerTaskQueue Response ZK path:
/overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may
have disconnected from ZooKeeper
[junit4] 2> 1054479 DEBUG (ScheduledTrigger-3378-thread-1)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 1054479 DEBUG (ScheduledTrigger-3378-thread-1)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1054479 DEBUG (ScheduledTrigger-3378-thread-1)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger1 firing registered processor for nodes:
[127.0.0.1:33209_solr] added at times [2645369253298307], now=2645370253941001
[junit4] 2> 1054480 DEBUG (ScheduledTrigger-3378-thread-1)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"965f306a48083T3i5888ncesuelojvumj3rluxt",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":2645369253298307,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2645369253298307],
[junit4] 2> "nodeNames":["127.0.0.1:33209_solr"]}}
[junit4] 2> 1054480 INFO (ScheduledTrigger-3378-thread-1)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 1054480 DEBUG
(AutoscalingActionExecutor-3379-thread-1-processing-n:127.0.0.1:33721_solr)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"965f306a48083T3i5888ncesuelojvumj3rluxt",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":2645369253298307,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2645369253298307],
[junit4] 2> "_enqueue_time_":2645370254183180,
[junit4] 2> "nodeNames":["127.0.0.1:33209_solr"]}}
[junit4] 2> 1054480 INFO
(AutoscalingActionExecutor-3379-thread-1-processing-n:127.0.0.1:33721_solr)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.TriggerIntegrationTest -- event: {
[junit4] 2> "id":"965f306a48083T3i5888ncesuelojvumj3rluxt",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":2645369253298307,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2645369253298307],
[junit4] 2> "_enqueue_time_":2645370254183180,
[junit4] 2> "nodeNames":["127.0.0.1:33209_solr"]}}
[junit4] 2> 1054481 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B]) [ ]
o.e.j.s.AbstractConnector Stopped ServerConnector@6c7fa7d9{SSL,[ssl,
http/1.1]}{127.0.0.1:0}
[junit4] 2> 1054481 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B]) [ ]
o.a.s.c.CoreContainer Shutting down CoreContainer instance=1348630078
[junit4] 2> 1054482 DEBUG
(AutoscalingActionExecutor-3379-thread-1-processing-n:127.0.0.1:33721_solr)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 1
ms for event id=965f306a48083T3i5888ncesuelojvumj3rluxt
[junit4] 2> 1054486 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B]) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node,
tag=null
[junit4] 2> 1054486 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B]) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@1d1b4038: rootName =
solr_33721, domain = solr.node, service url = null, agent id = null] for
registry solr.node / com.codahale.metrics.MetricRegistry@54213352
[junit4] 2> 1054493 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B]) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm,
tag=null
[junit4] 2> 1054493 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B]) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@3f6e610e: rootName =
solr_33721, domain = solr.jvm, service url = null, agent id = null] for
registry solr.jvm / com.codahale.metrics.MetricRegistry@422bfbc5
[junit4] 2> 1054498 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B]) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty,
tag=null
[junit4] 2> 1054499 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B]) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@1718b44b: rootName =
solr_33721, domain = solr.jetty, service url = null, agent id = null] for
registry solr.jetty / com.codahale.metrics.MetricRegistry@6d6d17e6
[junit4] 2> 1054499 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B]) [ ]
o.a.s.c.ZkController Remove node as live in
ZooKeeper:/live_nodes/127.0.0.1:33721_solr
[junit4] 2> 1054500 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B]) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster,
tag=null
[junit4] 2> 1054500 INFO
(zkCallback-1559-thread-1-processing-n:127.0.0.1:33209_solr)
[n:127.0.0.1:33209_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 1054500 INFO
(zkCallback-1539-thread-1-processing-n:127.0.0.1:33721_solr)
[n:127.0.0.1:33721_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 1054501 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B]) [ ]
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647
transient cores
[junit4] 2> 1054502 INFO
(zkCallback-1541-thread-1-processing-n:127.0.0.1:41887_solr)
[n:127.0.0.1:41887_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 1054502 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B]) [ ]
o.a.s.c.Overseer Overseer
(id=99283382892036101-127.0.0.1:33721_solr-n_0000000000) closing
[junit4] 2> 1054502 INFO (zkCallback-1551-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 1054502 INFO
(OverseerStateUpdate-99283382892036101-127.0.0.1:33721_solr-n_0000000000)
[n:127.0.0.1:33721_solr ] o.a.s.c.Overseer Overseer Loop exiting :
127.0.0.1:33721_solr
[junit4] 2> 1054502 WARN
(OverseerAutoScalingTriggerThread-99283382892036101-127.0.0.1:33721_solr-n_0000000000)
[n:127.0.0.1:33721_solr ] o.a.s.c.a.OverseerTriggerThread
OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 1054502 DEBUG
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B]) [ ]
o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 1054503 INFO
(zkCallback-1541-thread-1-processing-n:127.0.0.1:41887_solr)
[n:127.0.0.1:41887_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:41887_solr
[junit4] 2> 1054503 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B]) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@43fd59d5{/solr,null,UNAVAILABLE}
[junit4] 2> 1054503 INFO
(zkCallback-1541-thread-1-processing-n:127.0.0.1:41887_solr)
[n:127.0.0.1:41887_solr ] o.a.s.c.Overseer Overseer
(id=99283382892036102-127.0.0.1:41887_solr-n_0000000001) starting
[junit4] 2> 1054505 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036102-127.0.0.1:41887_solr-n_0000000001)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.OverseerTriggerThread Adding
.autoAddReplicas trigger
[junit4] 2> 1054506 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036102-127.0.0.1:41887_solr-n_0000000001)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 5
[junit4] 2> 1054506 INFO
(OverseerAutoScalingTriggerThread-99283382892036102-127.0.0.1:41887_solr-n_0000000001)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.TriggerIntegrationTest
TestEventQueueAction instantiated
[junit4] 2> 1054506 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036102-127.0.0.1:41887_solr-n_0000000001)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:41887_solr, 127.0.0.1:33209_solr]
[junit4] 2> 1054506 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036102-127.0.0.1:41887_solr-n_0000000001)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=1,
actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestEventQueueAction}],
enabled=true}
[junit4] 2> 1054506 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036102-127.0.0.1:41887_solr-n_0000000001)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:41887_solr, 127.0.0.1:33209_solr]
[junit4] 2> 1054506 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036102-127.0.0.1:41887_solr-n_0000000001)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 5, lastZnodeVersion -1
[junit4] 2> 1054506 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036102-127.0.0.1:41887_solr-n_0000000001)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 5
[junit4] 2> 1054507 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036102-127.0.0.1:41887_solr-n_0000000001)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 1054507 DEBUG (ScheduledTrigger-3395-thread-1)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 1054507 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036102-127.0.0.1:41887_solr-n_0000000001)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 5, lastZnodeVersion 5
[junit4] 2> 1054507 DEBUG (ScheduledTrigger-3395-thread-2)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 1054507 DEBUG (ScheduledTrigger-3395-thread-2)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1055507 DEBUG (ScheduledTrigger-3395-thread-1)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 1055508 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 1055508 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1056508 DEBUG (ScheduledTrigger-3395-thread-2)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 1056508 DEBUG (ScheduledTrigger-3395-thread-4)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 1056508 DEBUG (ScheduledTrigger-3395-thread-4)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1057508 DEBUG (ScheduledTrigger-3395-thread-1)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 1057508 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 1057508 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1058508 DEBUG (ScheduledTrigger-3395-thread-2)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 1058508 DEBUG (ScheduledTrigger-3395-thread-4)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 1058508 DEBUG (ScheduledTrigger-3395-thread-4)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1059508 DEBUG (ScheduledTrigger-3395-thread-1)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 1059509 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 1059509 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1060508 DEBUG (ScheduledTrigger-3395-thread-2)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 1060509 DEBUG (ScheduledTrigger-3395-thread-4)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 1060509 DEBUG (ScheduledTrigger-3395-thread-4)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1061509 DEBUG (ScheduledTrigger-3395-thread-1)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 1061509 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 1061509 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1062503 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[5BFC67CD2302993B]) [ ]
o.a.s.SolrTestCaseJ4 ###Ending testEventQueue
[junit4] 2> NOTE: reproduce with: ant test
-Dtestcase=TriggerIntegrationTest -Dtests.method=testEventQueue
-Dtests.seed=5BFC67CD2302993B -Dtests.multiplier=3 -Dtests.slow=true
-Dtests.locale=kea -Dtests.timezone=America/Punta_Arenas -Dtests.asserts=true
-Dtests.file.encoding=US-ASCII
[junit4] FAILURE 10.1s J0 | TriggerIntegrationTest.testEventQueue <<<
[junit4] > Throwable #1: java.lang.AssertionError: action wasn't
interrupted
[junit4] > at
__randomizedtesting.SeedInfo.seed([5BFC67CD2302993B:924925632A655FCE]:0)
[junit4] > at
org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testEventQueue(TriggerIntegrationTest.java:711)
[junit4] > at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] > at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] > at
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] > at
java.base/java.lang.reflect.Method.invoke(Method.java:564)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 1062509 DEBUG (ScheduledTrigger-3395-thread-2)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 1062509 DEBUG (ScheduledTrigger-3395-thread-4)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 1062509 DEBUG (ScheduledTrigger-3395-thread-4)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1062510 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.a.s.SolrTestCaseJ4 ###Starting testEventFromRestoredState
[junit4] 2> 1062510 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode
version 6
[junit4] 2> 1062510 DEBUG
(zkCallback-1541-thread-1-processing-n:127.0.0.1:41887_solr)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 6
[junit4] 2> 1062510 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036102-127.0.0.1:41887_solr-n_0000000001)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 6
[junit4] 2> 1062511 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036102-127.0.0.1:41887_solr-n_0000000001)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 1062511 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036102-127.0.0.1:41887_solr-n_0000000001)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 1062511 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036102-127.0.0.1:41887_solr-n_0000000001)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 6, lastZnodeVersion 6
[junit4] 2> 1062522 INFO (qtp2065325771-7937) [n:127.0.0.1:33209_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0
QTime=0
[junit4] 2> 1062527 INFO (qtp1668135643-7872) [n:127.0.0.1:41887_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0
QTime=0
[junit4] 2> 1062527 DEBUG (qtp2065325771-7930) [n:127.0.0.1:33209_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1062527 INFO (qtp2065325771-7930) [n:127.0.0.1:33209_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=6
[junit4] 2> 1062527 DEBUG
(zkCallback-1541-thread-1-processing-n:127.0.0.1:41887_solr)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 7
[junit4] 2> 1062527 DEBUG
(zkCallback-1541-thread-1-processing-n:127.0.0.1:41887_solr)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:41887_solr, 127.0.0.1:33209_solr]
[junit4] 2> 1062528 DEBUG
(zkCallback-1541-thread-1-processing-n:127.0.0.1:41887_solr)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=10,
actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestTriggerAction}],
enabled=true}
[junit4] 2> 1062528 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036102-127.0.0.1:41887_solr-n_0000000001)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 7
[junit4] 2> 1062528 INFO
(OverseerAutoScalingTriggerThread-99283382892036102-127.0.0.1:41887_solr-n_0000000001)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 1062528 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036102-127.0.0.1:41887_solr-n_0000000001)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 1062528 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036102-127.0.0.1:41887_solr-n_0000000001)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 7, lastZnodeVersion 7
[junit4] 2> 1062528 INFO (qtp2065325771-7935) [n:127.0.0.1:33209_solr
] o.a.s.h.a.CollectionsHandler Invoked Collection Action :overseerstatus with
params action=OVERSEERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1062528 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1062528 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1062531 INFO (qtp2065325771-7935) [n:127.0.0.1:33209_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections
params={action=OVERSEERSTATUS&wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 1062532 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 1062533 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@3e4293b5{/solr,null,AVAILABLE}
[junit4] 2> 1062533 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.e.j.s.AbstractConnector Started ServerConnector@33a943da{SSL,[ssl,
http/1.1]}{127.0.0.1:37659}
[junit4] 2> 1062534 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.e.j.s.Server Started @1064547ms
[junit4] 2> 1062534 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=37659}
[junit4] 2> 1062534 ERROR
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging
may be missing or incomplete.
[junit4] 2> 1062534 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr?
version 7.3.0
[junit4] 2> 1062534 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on
port null
[junit4] 2> 1062534 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1062534 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-01-03T01:50:36.336590Z
[junit4] 2> 1062535 INFO (zkConnectionManagerCallback-1564-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1062535 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1062540 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41913/solr
[junit4] 2> 1062541 INFO (zkConnectionManagerCallback-1568-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1062543 INFO
(zkConnectionManagerCallback-1570-thread-1-processing-n:127.0.0.1:37659_solr)
[n:127.0.0.1:37659_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1062545 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[n:127.0.0.1:37659_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (2)
[junit4] 2> 1062546 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[n:127.0.0.1:37659_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1062547 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[n:127.0.0.1:37659_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:37659_solr
[junit4] 2> 1062550 INFO
(zkCallback-1559-thread-1-processing-n:127.0.0.1:33209_solr)
[n:127.0.0.1:33209_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 1062550 INFO
(zkCallback-1541-thread-1-processing-n:127.0.0.1:41887_solr)
[n:127.0.0.1:41887_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 1062552 INFO (zkCallback-1551-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1062552 INFO
(zkCallback-1569-thread-1-processing-n:127.0.0.1:37659_solr)
[n:127.0.0.1:37659_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 1062598 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[n:127.0.0.1:37659_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_37659.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5d5e8331
[junit4] 2> 1062604 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[n:127.0.0.1:37659_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_37659.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5d5e8331
[junit4] 2> 1062604 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[n:127.0.0.1:37659_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_37659.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5d5e8331
[junit4] 2> 1062605 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[n:127.0.0.1:37659_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_5BFC67CD2302993B-001/tempDir-001/node4/.
[junit4] 2> 1063529 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1063529 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1063529 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node:
127.0.0.1:37659_solr at time 2645379303630387
[junit4] 2> 1064530 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1064530 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1064530 INFO
(OverseerCollectionConfigSetProcessor-99283382892036102-127.0.0.1:41887_solr-n_0000000001)
[n:127.0.0.1:41887_solr ] o.a.s.c.OverseerTaskQueue Response ZK path:
/overseer/collection-queue-work/qnr-0000000002 doesn't exist. Requestor may
have disconnected from ZooKeeper
[junit4] 2> 1065530 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1065530 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1066530 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1066530 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1067530 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1067530 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1068530 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1068530 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1069531 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1069531 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1070531 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1070531 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1071531 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1071531 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1072531 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1072531 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1073531 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1073532 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1073532 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger firing registered processor for nodes:
[127.0.0.1:37659_solr] added at times [2645379303630387], now=2645389306220844
[junit4] 2> 1073532 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"965f55db06633T3i5888ncesuelojvumj3rluxv",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":2645379303630387,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2645379303630387],
[junit4] 2> "nodeNames":["127.0.0.1:37659_solr"]}}
[junit4] 2> 1073532 INFO (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 1073532 DEBUG
(AutoscalingActionExecutor-3396-thread-1-processing-n:127.0.0.1:41887_solr)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"965f55db06633T3i5888ncesuelojvumj3rluxv",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":2645379303630387,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2645379303630387],
[junit4] 2> "_enqueue_time_":2645389306370054,
[junit4] 2> "nodeNames":["127.0.0.1:37659_solr"]}}
[junit4] 2> 1073533 DEBUG
(AutoscalingActionExecutor-3396-thread-1-processing-n:127.0.0.1:41887_solr)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 0
ms for event id=965f55db06633T3i5888ncesuelojvumj3rluxv
[junit4] 2> 1073534 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 1073534 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@6c339366{/solr,null,AVAILABLE}
[junit4] 2> 1073535 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.e.j.s.AbstractConnector Started ServerConnector@11b055bf{SSL,[ssl,
http/1.1]}{127.0.0.1:46833}
[junit4] 2> 1073535 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.e.j.s.Server Started @1075549ms
[junit4] 2> 1073535 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=46833}
[junit4] 2> 1073535 ERROR
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging
may be missing or incomplete.
[junit4] 2> 1073535 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr?
version 7.3.0
[junit4] 2> 1073535 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on
port null
[junit4] 2> 1073535 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1073536 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-01-03T01:50:47.338Z
[junit4] 2> 1073537 INFO (zkConnectionManagerCallback-1574-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1073537 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1073544 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41913/solr
[junit4] 2> 1073545 INFO (zkConnectionManagerCallback-1578-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1073547 INFO
(zkConnectionManagerCallback-1580-thread-1-processing-n:127.0.0.1:46833_solr)
[n:127.0.0.1:46833_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1073550 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[n:127.0.0.1:46833_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (3)
[junit4] 2> 1073551 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[n:127.0.0.1:46833_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1073552 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[n:127.0.0.1:46833_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:46833_solr
[junit4] 2> 1073553 INFO (zkCallback-1551-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 1073553 INFO
(zkCallback-1559-thread-1-processing-n:127.0.0.1:33209_solr)
[n:127.0.0.1:33209_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (4)
[junit4] 2> 1073553 INFO
(zkCallback-1541-thread-1-processing-n:127.0.0.1:41887_solr)
[n:127.0.0.1:41887_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (4)
[junit4] 2> 1073553 INFO
(zkCallback-1569-thread-1-processing-n:127.0.0.1:37659_solr)
[n:127.0.0.1:37659_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (4)
[junit4] 2> 1073554 INFO
(zkCallback-1579-thread-1-processing-n:127.0.0.1:46833_solr)
[n:127.0.0.1:46833_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (4)
[junit4] 2> 1073586 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[n:127.0.0.1:46833_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_46833.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5d5e8331
[junit4] 2> 1073593 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[n:127.0.0.1:46833_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_46833.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5d5e8331
[junit4] 2> 1073593 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[n:127.0.0.1:46833_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_46833.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5d5e8331
[junit4] 2> 1073594 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[n:127.0.0.1:46833_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_5BFC67CD2302993B-001/tempDir-001/node5/.
[junit4] 2> 1074533 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1074533 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 1074533 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node:
127.0.0.1:46833_solr at time 2645390307773086
[junit4] 2> 1075534 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1075534 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 1076534 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1076534 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 1077534 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1077534 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 1078534 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1078534 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 1079534 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1079535 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 1080535 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1080535 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 1081535 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1081535 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 1082535 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1082535 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 1083535 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1083535 DEBUG (ScheduledTrigger-3395-thread-3)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 1083624 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.e.j.s.AbstractConnector Stopped ServerConnector@cb2b402{SSL,[ssl,
http/1.1]}{127.0.0.1:0}
[junit4] 2> 1083624 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=753034772
[junit4] 2> 1083624 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.node, tag=null
[junit4] 2> 1083624 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@77cd0077: rootName =
solr_41887, domain = solr.node, service url = null, agent id = null] for
registry solr.node / com.codahale.metrics.MetricRegistry@b310fe
[junit4] 2> 1083632 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.jvm, tag=null
[junit4] 2> 1083632 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@46487c16: rootName =
solr_41887, domain = solr.jvm, service url = null, agent id = null] for
registry solr.jvm / com.codahale.metrics.MetricRegistry@422bfbc5
[junit4] 2> 1083638 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.jetty, tag=null
[junit4] 2> 1083638 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@7f88c378: rootName =
solr_41887, domain = solr.jetty, service url = null, agent id = null] for
registry solr.jetty / com.codahale.metrics.MetricRegistry@6d6d17e6
[junit4] 2> 1083639 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.a.s.c.ZkController Remove node as live in
ZooKeeper:/live_nodes/127.0.0.1:41887_solr
[junit4] 2> 1083639 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.cluster, tag=null
[junit4] 2> 1083639 INFO (zkCallback-1551-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 1083639 INFO
(zkCallback-1579-thread-1-processing-n:127.0.0.1:46833_solr)
[n:127.0.0.1:46833_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (4) -> (3)
[junit4] 2> 1083639 INFO
(zkCallback-1541-thread-1-processing-n:127.0.0.1:41887_solr)
[n:127.0.0.1:41887_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (4) -> (3)
[junit4] 2> 1083640 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for
2147483647 transient cores
[junit4] 2> 1083639 INFO
(zkCallback-1569-thread-1-processing-n:127.0.0.1:37659_solr)
[n:127.0.0.1:37659_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (4) -> (3)
[junit4] 2> 1083640 INFO
(zkCallback-1559-thread-1-processing-n:127.0.0.1:33209_solr)
[n:127.0.0.1:33209_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (4) -> (3)
[junit4] 2> 1083640 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.a.s.c.Overseer Overseer
(id=99283382892036102-127.0.0.1:41887_solr-n_0000000001) closing
[junit4] 2> 1083640 INFO
(OverseerStateUpdate-99283382892036102-127.0.0.1:41887_solr-n_0000000001)
[n:127.0.0.1:41887_solr ] o.a.s.c.Overseer Overseer Loop exiting :
127.0.0.1:41887_solr
[junit4] 2> 1083640 WARN
(OverseerAutoScalingTriggerThread-99283382892036102-127.0.0.1:41887_solr-n_0000000001)
[n:127.0.0.1:41887_solr ] o.a.s.c.a.OverseerTriggerThread
OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 1083641 DEBUG
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed
explicitly
[junit4] 2> 1083641 INFO
(zkCallback-1559-thread-1-processing-n:127.0.0.1:33209_solr)
[n:127.0.0.1:33209_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:33209_solr
[junit4] 2> 1083641 INFO
(zkCallback-1559-thread-1-processing-n:127.0.0.1:33209_solr)
[n:127.0.0.1:33209_solr ] o.a.s.c.Overseer Overseer
(id=99283382892036107-127.0.0.1:33209_solr-n_0000000002) starting
[junit4] 2> 1083642 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@53684d6a{/solr,null,UNAVAILABLE}
[junit4] 2> 1083644 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036107-127.0.0.1:33209_solr-n_0000000002)
[n:127.0.0.1:33209_solr ] o.a.s.c.a.OverseerTriggerThread Adding
.autoAddReplicas trigger
[junit4] 2> 1083645 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036107-127.0.0.1:33209_solr-n_0000000002)
[n:127.0.0.1:33209_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 8
[junit4] 2> 1083645 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036107-127.0.0.1:33209_solr-n_0000000002)
[n:127.0.0.1:33209_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:46833_solr, 127.0.0.1:37659_solr, 127.0.0.1:33209_solr]
[junit4] 2> 1083645 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036107-127.0.0.1:33209_solr-n_0000000002)
[n:127.0.0.1:33209_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=10,
actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestTriggerAction}],
enabled=true}
[junit4] 2> 1083645 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036107-127.0.0.1:33209_solr-n_0000000002)
[n:127.0.0.1:33209_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:46833_solr, 127.0.0.1:37659_solr, 127.0.0.1:33209_solr]
[junit4] 2> 1083645 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036107-127.0.0.1:33209_solr-n_0000000002)
[n:127.0.0.1:33209_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 8, lastZnodeVersion -1
[junit4] 2> 1083645 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036107-127.0.0.1:33209_solr-n_0000000002)
[n:127.0.0.1:33209_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 8
[junit4] 2> 1083646 INFO
(OverseerAutoScalingTriggerThread-99283382892036107-127.0.0.1:33209_solr-n_0000000002)
[n:127.0.0.1:33209_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 1083646 DEBUG (ScheduledTrigger-3412-thread-1)
[n:127.0.0.1:33209_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 3
[junit4] 2> 1083646 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036107-127.0.0.1:33209_solr-n_0000000002)
[n:127.0.0.1:33209_solr ] o.a.s.c.a.NodeAddedTrigger Adding node from
marker path: 127.0.0.1:46833_solr
[junit4] 2> 1083646 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036107-127.0.0.1:33209_solr-n_0000000002)
[n:127.0.0.1:33209_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 8, lastZnodeVersion 8
[junit4] 2> 1083646 DEBUG (ScheduledTrigger-3412-thread-1)
[n:127.0.0.1:33209_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1083646 DEBUG (ScheduledTrigger-3412-thread-1)
[n:127.0.0.1:33209_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1084646 DEBUG (ScheduledTrigger-3412-thread-2)
[n:127.0.0.1:33209_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 3
[junit4] 2> 1084647 DEBUG (ScheduledTrigger-3412-thread-3)
[n:127.0.0.1:33209_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1084647 DEBUG (ScheduledTrigger-3412-thread-3)
[n:127.0.0.1:33209_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1084647 DEBUG (ScheduledTrigger-3412-thread-3)
[n:127.0.0.1:33209_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger firing registered processor for nodes:
[127.0.0.1:46833_solr] added at times [2645390307773086], now=2645400421494330
[junit4] 2> 1084647 DEBUG (ScheduledTrigger-3412-thread-3)
[n:127.0.0.1:33209_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"965f7ed964a9eT3i5888ncesuelojvumj3rluxx",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":2645390307773086,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2645390307773086],
[junit4] 2> "nodeNames":["127.0.0.1:46833_solr"]}}
[junit4] 2> 1084648 INFO (ScheduledTrigger-3412-thread-3)
[n:127.0.0.1:33209_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 1084648 DEBUG
(AutoscalingActionExecutor-3413-thread-1-processing-n:127.0.0.1:33209_solr)
[n:127.0.0.1:33209_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"965f7ed964a9eT3i5888ncesuelojvumj3rluxx",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":2645390307773086,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2645390307773086],
[junit4] 2> "_enqueue_time_":2645400421656753,
[junit4] 2> "nodeNames":["127.0.0.1:46833_solr"]}}
[junit4] 2> 1084648 INFO
(TEST-TriggerIntegrationTest.testEventFromRestoredState-seed#[5BFC67CD2302993B])
[ ] o.a.s.SolrTestCaseJ4 ###Ending testEventFromRestoredState
[junit4] 2> 1084649 DEBUG
(AutoscalingActionExecutor-3413-thread-1-processing-n:127.0.0.1:33209_solr)
[n:127.0.0.1:33209_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 0
ms for event id=965f7ed964a9eT3i5888ncesuelojvumj3rluxx
[junit4] 2> 1084667 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[5BFC67CD2302993B]) [
] o.a.s.SolrTestCaseJ4 ###Starting testNodeAddedTrigger
[junit4] 2> 1084668 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[5BFC67CD2302993B]) [
] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 9
[junit4] 2> 1084668 DEBUG
(zkCallback-1559-thread-1-processing-n:127.0.0.1:33209_solr)
[n:127.0.0.1:33209_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 9
[junit4] 2> 1084668 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036107-127.0.0.1:33209_solr-n_0000000002)
[n:127.0.0.1:33209_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 9
[junit4] 2> 1084669 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036107-127.0.0.1:33209_solr-n_0000000002)
[n:127.0.0.1:33209_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 1084669 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036107-127.0.0.1:33209_solr-n_0000000002)
[n:127.0.0.1:33209_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 1084669 DEBUG
(OverseerAutoScalingTriggerThread-99283382892036107-127.0.0.1:33209_solr-n_0000000002)
[n:127.0.0.1:33209_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 9, lastZnodeVersion 9
[junit4] 2> 1084682 INFO (qtp1431439142-7999) [n:127.0.0.1:46833_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0
QTime=0
[junit4] 2> 1084686 INFO (qtp2065325771-7931) [n:127.0.0.1:33209_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0
QTime=0
[junit4] 2> 1084696 INFO (qtp2022237916-7973) [n:127.0.0.1:37659_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0
QTime=0
[junit4] 2> 1084696 DEBUG (qtp2065325771-7936) [n:127.0.0.1:33209_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1084696 INFO (qtp2065325771-7936) [n:127.0.0.1:33209_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime
[...truncated too long message...]
t4] 2> at
org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:283)
[junit4] 2> at
org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:108)
[junit4] 2> at
org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93)
[junit4] 2> at
org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303)
[junit4] 2> at
org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148)
[junit4] 2> at
org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136)
[junit4] 2> at
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)
[junit4] 2> at
org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> Caused by: org.apache.solr.common.SolrException: No registered
leader was found after waiting for 1220000ms , collection: control_collection
slice: shard1 saw state=null with live_nodes=[]
[junit4] 2> at
org.apache.solr.common.cloud.ZkStateReader.getLeaderRetry(ZkStateReader.java:771)
[junit4] 2> at
org.apache.solr.common.cloud.ZkStateReader.getLeaderUrl(ZkStateReader.java:736)
[junit4] 2> at
org.apache.solr.cloud.ZkController.getLeader(ZkController.java:1178)
[junit4] 2> ... 41 more
[junit4] 2>
[junit4] 2> 1577006 INFO (qtp657625067-11979) [n:127.0.0.1:44667_
c:control_collection s:shard1 x:control_collection_shard1_replica_n1]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores
params={qt=/admin/cores&collection.configName=conf1&newCollection=true&name=control_collection_shard1_replica_n1&action=CREATE&numShards=1&collection=control_collection&shard=shard1&wt=javabin&version=2&replicaType=NRT}
status=0 QTime=630168
[junit4] 2> 1577006 ERROR
(TEST-SolrShardReporterTest.test-seed#[5BFC67CD2302993B]) [ ]
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> 1577007 INFO
(TEST-SolrShardReporterTest.test-seed#[5BFC67CD2302993B]) [ ]
o.a.s.c.ZkTestServer connecting to 127.0.0.1:32875 32875
[junit4] 2> 1582404 INFO (Thread-3887) [ ] o.a.s.c.ZkTestServer
connecting to 127.0.0.1:32875 32875
[junit4] 2> 1582404 WARN (Thread-3887) [ ] o.a.s.c.ZkTestServer Watch
limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 2 /solr/aliases.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 2 /solr/clusterstate.json
[junit4] 2> 2 /solr/clusterprops.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 2 /solr/live_nodes
[junit4] 2> 2 /solr/collections
[junit4] 2>
[junit4] 2> NOTE: reproduce with: ant test
-Dtestcase=SolrShardReporterTest -Dtests.method=test
-Dtests.seed=5BFC67CD2302993B -Dtests.multiplier=3 -Dtests.slow=true
-Dtests.locale=rw-RW -Dtests.timezone=CTT -Dtests.asserts=true
-Dtests.file.encoding=US-ASCII
[junit4] ERROR 636s J2 | SolrShardReporterTest.test <<<
[junit4] > Throwable #1:
org.apache.solr.client.solrj.SolrServerException: Timeout occured while waiting
response from server at: http://127.0.0.1:44667
[junit4] > at
__randomizedtesting.SeedInfo.seed([5BFC67CD2302993B:D3A858178DFEF4C3]:0)
[junit4] > at
org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:654)
[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:1104)
[junit4] > at
org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:884)
[junit4] > at
org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:817)
[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.cloud.AbstractFullDistribZkTestBase.createServers(AbstractFullDistribZkTestBase.java:320)
[junit4] > at
org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:991)
[junit4] > at
org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:968)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] > Caused by: java.net.SocketTimeoutException: Read timed out
[junit4] > at
java.base/java.net.SocketInputStream.socketRead0(Native Method)
[junit4] > at
java.base/java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
[junit4] > at
java.base/java.net.SocketInputStream.read(SocketInputStream.java:171)
[junit4] > at
java.base/java.net.SocketInputStream.read(SocketInputStream.java:141)
[junit4] > at
org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:137)
[junit4] > at
org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:153)
[junit4] > at
org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:282)
[junit4] > at
org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:138)
[junit4] > at
org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:56)
[junit4] > at
org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:259)
[junit4] > at
org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:163)
[junit4] > at
org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:165)
[junit4] > at
org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:273)
[junit4] > at
org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:125)
[junit4] > at
org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:272)
[junit4] > at
org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:185)
[junit4] > at
org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
[junit4] > at
org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:111)
[junit4] > at
org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
[junit4] > at
org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
[junit4] > at
org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56)
[junit4] > at
org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:542)
[junit4] > ... 42 more
[junit4] 2> NOTE: leaving temporary files on disk at:
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.metrics.reporters.solr.SolrShardReporterTest_5BFC67CD2302993B-001
[junit4] 2> NOTE: test params are: codec=Lucene70,
sim=RandomSimilarity(queryNorm=false): {}, locale=rw-RW, timezone=CTT
[junit4] 2> NOTE: Linux 4.10.0-40-generic amd64/Oracle Corporation 9.0.1
(64-bit)/cpus=8,threads=1,free=325032040,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [TestPullReplica,
SpellPossibilityIteratorTest, BasicDistributedZk2Test, MetricsHandlerTest,
FileBasedSpellCheckerTest, TestMaxTokenLenTokenizer, TestNoOpRegenerator,
TestChildDocTransformer, TestDistributedMissingSort, RecoveryZkTest,
IndexSchemaTest, TestUninvertingReader, TestSolrCLIRunExample,
TestFieldResource, DistributedQueryComponentOptimizationTest, TestCharFilters,
LeaderElectionTest, CopyFieldTest, DeleteNodeTest, TestLegacyFieldCache,
BadCopyFieldTest, TestManagedStopFilterFactory, TestMaxScoreQueryParser,
RuleEngineTest, TestFunctionQuery, TestRestManager, TestHdfsCloudBackupRestore,
TestExportWriter, DirectSolrConnectionTest, TestSolrXml, TestNestedDocsSort,
TestFieldSortValues, SolrJmxReporterTest, RecoveryAfterSoftCommitTest,
DocValuesNotIndexedTest, XsltUpdateRequestHandlerTest, InfixSuggestersTest,
WordBreakSolrSpellCheckerTest, AutoAddReplicasIntegrationTest,
TestCloudSearcherWarming, UpdateLogTest, TestPivotHelperCode,
TestLRUStatsCache, TestCloudPivotFacet, ZkNodePropsTest, HdfsThreadLeakTest,
TestSmileRequest, StatsComponentTest, SuggesterTest, TestDynamicLoading,
TestDistributedStatsComponentCardinality, DistributedFacetPivotSmallTest,
ComputePlanActionTest, TestEmbeddedSolrServerConstructors, TestTrie,
UninvertDocValuesMergePolicyTest, TestMinMaxOnMultiValuedField, EnumFieldTest,
SolrGangliaReporterTest, TestCoreContainer, MoveReplicaHDFSTest,
TestComputePlanAction, CurrencyFieldTypeTest, ZkStateReaderTest,
TestDistribIDF, LeaderElectionContextKeyTest, XmlUpdateRequestHandlerTest,
DirectSolrSpellCheckerTest, SystemInfoHandlerTest,
TestLMJelinekMercerSimilarityFactory, TestMacroExpander,
IndexBasedSpellCheckerTest, TestSQLHandler, TestConfigSets, JvmMetricsTest,
DistributedDebugComponentTest, SolrShardReporterTest]
[junit4] Completed [332/764 (2!)] on J2 in 635.99s, 1 test, 1 error <<<
FAILURES!
[...truncated 42287 lines...]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
