You are viewing a plain text version of this content. The canonical link for it is here.
Posted to builds@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2020/05/17 11:26:29 UTC
[JENKINS] Lucene-Solr-8.x-Windows (64bit/jdk-14) - Build # 1136 -
Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-8.x-Windows/1136/
Java: 64bit/jdk-14 -XX:+UseCompressedOops -XX:+UseParallelGC
1 tests failed.
FAILED: org.apache.solr.cloud.autoscaling.ScheduledTriggerIntegrationTest.testScheduledTrigger
Error Message:
ScheduledTrigger did not fire in time
Stack Trace:
java.lang.AssertionError: ScheduledTrigger did not fire in time
at __randomizedtesting.SeedInfo.seed([64851057649BAC3E:F79E58253A66F70A]:0)
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.assertTrue(Assert.java:41)
at org.apache.solr.cloud.autoscaling.ScheduledTriggerIntegrationTest.testScheduledTrigger(ScheduledTriggerIntegrationTest.java:120)
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:1750)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
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:947)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
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:832)
Build Log:
[...truncated 15483 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.ScheduledTriggerIntegrationTest
[junit4] 2> 1575942 INFO (SUITE-ScheduledTriggerIntegrationTest-seed#[64851057649BAC3E]-worker) [ ] o.a.s.SolrTestCase Setting 'solr.default.confdir' system property to test-framework derived value of 'C:\Users\jenkins\workspace\Lucene-Solr-8.x-Windows\solr\server\solr\configsets\_default\conf'
[junit4] 2> 1575942 INFO (SUITE-ScheduledTriggerIntegrationTest-seed#[64851057649BAC3E]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 1575943 INFO (SUITE-ScheduledTriggerIntegrationTest-seed#[64851057649BAC3E]-worker) [ ] o.a.s.SolrTestCaseJ4 Created dataDir: C:\Users\jenkins\workspace\Lucene-Solr-8.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_64851057649BAC3E-001\data-dir-100-001
[junit4] 2> 1575943 WARN (SUITE-ScheduledTriggerIntegrationTest-seed#[64851057649BAC3E]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=14 numCloses=14
[junit4] 2> 1575943 INFO (SUITE-ScheduledTriggerIntegrationTest-seed#[64851057649BAC3E]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 1575944 INFO (SUITE-ScheduledTriggerIntegrationTest-seed#[64851057649BAC3E]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason="", value=0.0/0.0, ssl=0.0/0.0, clientAuth=0.0/0.0)
[junit4] 2> 1575945 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testScheduledTrigger
[junit4] 2> 1575946 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in C:\Users\jenkins\workspace\Lucene-Solr-8.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_64851057649BAC3E-001\tempDir-001
[junit4] 2> 1575946 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 1575946 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port: 0.0.0.0/0.0.0.0:0
[junit4] 2> 1575946 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 1576042 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.c.ZkTestServer start zk server on port: 62632
[junit4] 2> 1576042 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.c.ZkTestServer waitForServerUp: 127.0.0.1:62632
[junit4] 2> 1576042 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:62632
[junit4] 2> 1576042 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 62632
[junit4] 2> 1576043 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1576047 INFO (zkConnectionManagerCallback-12604-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1576047 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1576049 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1576050 INFO (zkConnectionManagerCallback-12606-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1576050 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1576050 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1576052 INFO (zkConnectionManagerCallback-12608-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1576052 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1576152 WARN (jetty-launcher-12609-thread-2) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 1576152 INFO (jetty-launcher-12609-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 1576152 INFO (jetty-launcher-12609-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
[junit4] 2> 1576152 WARN (jetty-launcher-12609-thread-1) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 1576152 INFO (jetty-launcher-12609-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 1576152 INFO (jetty-launcher-12609-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
[junit4] 2> 1576152 INFO (jetty-launcher-12609-thread-2) [ ] o.e.j.s.Server jetty-9.4.27.v20200227; built: 2020-02-27T18:37:21.340Z; git: a304fd9f351f337e7c0e2a7c28878dd536149c6c; jvm 14+36
[junit4] 2> 1576152 INFO (jetty-launcher-12609-thread-1) [ ] o.e.j.s.Server jetty-9.4.27.v20200227; built: 2020-02-27T18:37:21.340Z; git: a304fd9f351f337e7c0e2a7c28878dd536149c6c; jvm 14+36
[junit4] 2> 1576152 INFO (jetty-launcher-12609-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1576152 INFO (jetty-launcher-12609-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1576152 INFO (jetty-launcher-12609-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1576152 INFO (jetty-launcher-12609-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1576152 INFO (jetty-launcher-12609-thread-2) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 1576152 INFO (jetty-launcher-12609-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 1576152 INFO (jetty-launcher-12609-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@819a91{/solr,null,AVAILABLE}
[junit4] 2> 1576152 INFO (jetty-launcher-12609-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@7e21a52a{/solr,null,AVAILABLE}
[junit4] 2> 1576152 INFO (jetty-launcher-12609-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@4f31cc0{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:?????}
[junit4] 2> 1576152 INFO (jetty-launcher-12609-thread-2) [ ] o.e.j.s.Server Started @???????ms
[junit4] 2> 1576152 INFO (jetty-launcher-12609-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=62646}
[junit4] 2> 1576152 INFO (jetty-launcher-12609-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1a1808cb{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:?????}
[junit4] 2> 1576152 ERROR (jetty-launcher-12609-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1576152 INFO (jetty-launcher-12609-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 1576152 INFO (jetty-launcher-12609-thread-1) [ ] o.e.j.s.Server Started @???????ms
[junit4] 2> 1576152 INFO (jetty-launcher-12609-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.6.0
[junit4] 2> 1576152 INFO (jetty-launcher-12609-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1576152 INFO (jetty-launcher-12609-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: C:\Users\jenkins\workspace\Lucene-Solr-8.x-Windows\solr
[junit4] 2> 1576152 INFO (jetty-launcher-12609-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=62645}
[junit4] 2> 1576152 INFO (jetty-launcher-12609-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-05-17T10:56:04.101717400Z
[junit4] 2> 1576152 ERROR (jetty-launcher-12609-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1576152 INFO (jetty-launcher-12609-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 1576152 INFO (jetty-launcher-12609-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.6.0
[junit4] 2> 1576152 INFO (jetty-launcher-12609-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1576152 INFO (jetty-launcher-12609-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: C:\Users\jenkins\workspace\Lucene-Solr-8.x-Windows\solr
[junit4] 2> 1576152 INFO (jetty-launcher-12609-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-05-17T10:56:04.101717400Z
[junit4] 2> 1576155 INFO (jetty-launcher-12609-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1576155 INFO (jetty-launcher-12609-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1576156 INFO (zkConnectionManagerCallback-12613-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1576156 INFO (jetty-launcher-12609-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1576156 INFO (zkConnectionManagerCallback-12611-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1576156 INFO (jetty-launcher-12609-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1576156 INFO (jetty-launcher-12609-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1576156 INFO (jetty-launcher-12609-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1576310 INFO (jetty-launcher-12609-thread-2) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 1576311 WARN (jetty-launcher-12609-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@122eeedd[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1576311 WARN (jetty-launcher-12609-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@122eeedd[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1576314 WARN (jetty-launcher-12609-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@674f715f[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1576314 WARN (jetty-launcher-12609-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@674f715f[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1576314 INFO (jetty-launcher-12609-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:62632/solr
[junit4] 2> 1576315 INFO (jetty-launcher-12609-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1576316 INFO (zkConnectionManagerCallback-12624-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1576316 INFO (jetty-launcher-12609-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1576431 INFO (jetty-launcher-12609-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 1576432 WARN (jetty-launcher-12609-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@699fde21[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1576432 WARN (jetty-launcher-12609-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@699fde21[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1576434 WARN (jetty-launcher-12609-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@26bcaa1[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1576434 WARN (jetty-launcher-12609-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@26bcaa1[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1576435 INFO (jetty-launcher-12609-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:62632/solr
[junit4] 2> 1576436 INFO (jetty-launcher-12609-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1576438 INFO (zkConnectionManagerCallback-12635-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1576438 INFO (jetty-launcher-12609-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1576451 INFO (jetty-launcher-12609-thread-2) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1576453 INFO (zkConnectionManagerCallback-12637-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1576453 INFO (jetty-launcher-12609-thread-2) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1576524 INFO (jetty-launcher-12609-thread-2) [n:127.0.0.1:62646_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:62646_solr
[junit4] 2> 1576525 INFO (jetty-launcher-12609-thread-2) [n:127.0.0.1:62646_solr ] o.a.s.c.Overseer Overseer (id=72058175064047623-127.0.0.1:62646_solr-n_0000000000) starting
[junit4] 2> 1576528 INFO (jetty-launcher-12609-thread-2) [n:127.0.0.1:62646_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:62646_solr
[junit4] 2> 1576528 INFO (OverseerStateUpdate-72058175064047623-127.0.0.1:62646_solr-n_0000000000) [n:127.0.0.1:62646_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:62646_solr
[junit4] 2> 1576528 DEBUG (OverseerAutoScalingTriggerThread-72058175064047623-127.0.0.1:62646_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 1576528 INFO (OverseerStateUpdate-72058175064047623-127.0.0.1:62646_solr-n_0000000000) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1576528 DEBUG (OverseerAutoScalingTriggerThread-72058175064047623-127.0.0.1:62646_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 1576530 DEBUG (OverseerAutoScalingTriggerThread-72058175064047623-127.0.0.1:62646_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 0
[junit4] 2> 1576530 DEBUG (OverseerAutoScalingTriggerThread-72058175064047623-127.0.0.1:62646_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 1576530 INFO (jetty-launcher-12609-thread-2) [n:127.0.0.1:62646_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 1576530 WARN (jetty-launcher-12609-thread-2) [n:127.0.0.1:62646_solr ] o.a.s.c.CoreContainer Not all security plugins configured! authentication=disabled authorization=disabled. Solr is only as secure as you make it. Consider configuring authentication/authorization before exposing Solr to users internal or external. See https://s.apache.org/solrsecurity for more info
[junit4] 2> 1576531 DEBUG (OverseerAutoScalingTriggerThread-72058175064047623-127.0.0.1:62646_solr-n_0000000000) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:62646_solr]
[junit4] 2> 1576531 DEBUG (OverseerAutoScalingTriggerThread-72058175064047623-127.0.0.1:62646_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 1576531 DEBUG (ScheduledTrigger-12642-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 and last live nodes: 1
[junit4] 2> 1576531 DEBUG (OverseerAutoScalingTriggerThread-72058175064047623-127.0.0.1:62646_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 1576546 INFO (jetty-launcher-12609-thread-2) [n:127.0.0.1:62646_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 1576550 INFO (jetty-launcher-12609-thread-1) [n:127.0.0.1:62645_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1576550 INFO (zkConnectionManagerCallback-12650-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1576550 INFO (jetty-launcher-12609-thread-1) [n:127.0.0.1:62645_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1576553 INFO (jetty-launcher-12609-thread-1) [n:127.0.0.1:62645_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1576557 INFO (jetty-launcher-12609-thread-1) [n:127.0.0.1:62645_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:62645_solr as DOWN
[junit4] 2> 1576557 INFO (jetty-launcher-12609-thread-1) [n:127.0.0.1:62645_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 1576557 INFO (jetty-launcher-12609-thread-1) [n:127.0.0.1:62645_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:62645_solr
[junit4] 2> 1576557 INFO (zkCallback-12636-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1576557 INFO (zkCallback-12649-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1576557 INFO (jetty-launcher-12609-thread-1) [n:127.0.0.1:62645_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 1576561 WARN (jetty-launcher-12609-thread-1) [n:127.0.0.1:62645_solr ] o.a.s.c.CoreContainer Not all security plugins configured! authentication=disabled authorization=disabled. Solr is only as secure as you make it. Consider configuring authentication/authorization before exposing Solr to users internal or external. See https://s.apache.org/solrsecurity for more info
[junit4] 2> 1576564 INFO (jetty-launcher-12609-thread-2) [n:127.0.0.1:62646_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_62646.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@55f245b4
[junit4] 2> 1576569 INFO (jetty-launcher-12609-thread-2) [n:127.0.0.1:62646_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_62646.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@55f245b4
[junit4] 2> 1576569 INFO (jetty-launcher-12609-thread-2) [n:127.0.0.1:62646_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_62646.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@55f245b4
[junit4] 2> 1576572 INFO (jetty-launcher-12609-thread-2) [n:127.0.0.1:62646_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-8.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_64851057649BAC3E-001\tempDir-001\node2\.
[junit4] 2> 1576578 INFO (jetty-launcher-12609-thread-1) [n:127.0.0.1:62645_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 1576593 INFO (jetty-launcher-12609-thread-1) [n:127.0.0.1:62645_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_62645.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@55f245b4
[junit4] 2> 1576598 INFO (jetty-launcher-12609-thread-1) [n:127.0.0.1:62645_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_62645.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@55f245b4
[junit4] 2> 1576598 INFO (jetty-launcher-12609-thread-1) [n:127.0.0.1:62645_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_62645.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@55f245b4
[junit4] 2> 1576599 INFO (jetty-launcher-12609-thread-1) [n:127.0.0.1:62645_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-8.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_64851057649BAC3E-001\tempDir-001\node1\.
[junit4] 2> 1576610 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.c.MiniSolrCloudCluster waitForAllNodes: numServers=2
[junit4] 2> 1576611 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1576613 INFO (zkConnectionManagerCallback-12664-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1576613 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1576613 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1576614 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:62632/solr ready
[junit4] 2> 1576618 INFO (qtp350221344-19641) [n:127.0.0.1:62645_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling params={wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 1576622 INFO (qtp350221344-19639) [n:127.0.0.1:62645_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=2
[junit4] 2> 1576624 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=1
[junit4] 2> 1576625 DEBUG (qtp350221344-19643) [n:127.0.0.1:62645_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1576625 INFO (qtp350221344-19643) [n:127.0.0.1:62645_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling params={wt=javabin&version=2} status=0 QTime=6
[junit4] 2> 1576625 DEBUG (zkCallback-12636-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 1576627 DEBUG (OverseerAutoScalingTriggerThread-72058175064047623-127.0.0.1:62646_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 1576627 INFO (qtp350221344-19645) [n:127.0.0.1:62645_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params pullReplicas=0&maxShardsPerNode=5&name=testScheduledTrigger&nrtReplicas=3&action=CREATE&numShards=1&tlogReplicas=0&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1576627 DEBUG (OverseerAutoScalingTriggerThread-72058175064047623-127.0.0.1:62646_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 1576627 DEBUG (OverseerAutoScalingTriggerThread-72058175064047623-127.0.0.1:62646_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 1576627 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection testScheduledTrigger
[junit4] 2> 1576636 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/managed-schema to /configs/testScheduledTrigger.AUTOCREATED/managed-schema
[junit4] 2> 1576638 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/protwords.txt to /configs/testScheduledTrigger.AUTOCREATED/protwords.txt
[junit4] 2> 1576640 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/contractions_it.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/contractions_it.txt
[junit4] 2> 1576641 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/contractions_ca.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/contractions_ca.txt
[junit4] 2> 1576643 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stemdict_nl.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stemdict_nl.txt
[junit4] 2> 1576644 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_hy.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_hy.txt
[junit4] 2> 1576645 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_no.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_no.txt
[junit4] 2> 1576646 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_id.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_id.txt
[junit4] 2> 1576647 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_et.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_et.txt
[junit4] 2> 1576648 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_da.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_da.txt
[junit4] 2> 1576650 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_ga.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_ga.txt
[junit4] 2> 1576651 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_hi.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_hi.txt
[junit4] 2> 1576652 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_ja.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_ja.txt
[junit4] 2> 1576653 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_pt.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_pt.txt
[junit4] 2> 1576654 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_hu.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_hu.txt
[junit4] 2> 1576655 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_el.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_el.txt
[junit4] 2> 1576657 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_ru.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_ru.txt
[junit4] 2> 1576658 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_tr.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_tr.txt
[junit4] 2> 1576659 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_ar.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_ar.txt
[junit4] 2> 1576660 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/userdict_ja.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/userdict_ja.txt
[junit4] 2> 1576661 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_eu.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_eu.txt
[junit4] 2> 1576662 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_it.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_it.txt
[junit4] 2> 1576664 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_cz.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_cz.txt
[junit4] 2> 1576664 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stoptags_ja.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stoptags_ja.txt
[junit4] 2> 1576664 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/contractions_fr.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/contractions_fr.txt
[junit4] 2> 1576664 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_de.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_de.txt
[junit4] 2> 1576668 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_fa.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_fa.txt
[junit4] 2> 1576669 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/contractions_ga.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/contractions_ga.txt
[junit4] 2> 1576670 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_ca.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_ca.txt
[junit4] 2> 1576671 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_nl.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_nl.txt
[junit4] 2> 1576672 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_bg.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_bg.txt
[junit4] 2> 1576673 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_en.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_en.txt
[junit4] 2> 1576674 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_es.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_es.txt
[junit4] 2> 1576675 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_lv.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_lv.txt
[junit4] 2> 1576676 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_ro.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_ro.txt
[junit4] 2> 1576677 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_th.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_th.txt
[junit4] 2> 1576678 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_fr.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_fr.txt
[junit4] 2> 1576680 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_sv.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_sv.txt
[junit4] 2> 1576681 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_fi.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_fi.txt
[junit4] 2> 1576682 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/hyphenations_ga.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/hyphenations_ga.txt
[junit4] 2> 1576683 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_gl.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_gl.txt
[junit4] 2> 1576684 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/solrconfig.xml to /configs/testScheduledTrigger.AUTOCREATED/solrconfig.xml
[junit4] 2> 1576685 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/synonyms.txt to /configs/testScheduledTrigger.AUTOCREATED/synonyms.txt
[junit4] 2> 1576686 INFO (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/stopwords.txt to /configs/testScheduledTrigger.AUTOCREATED/stopwords.txt
[junit4] 2> 1576785 WARN (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.a.c.CreateCollectionCmd Specified number of replicas of 3 on collection testScheduledTrigger is higher than the number of Solr instances currently live or live and part of your createNodeSet(2). It's unusual to run two replica of the same slice on the same Solr-instance.
[junit4] 2> 1576785 DEBUG (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 1576787 INFO (qtp350221344-19639) [n:127.0.0.1:62645_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=2
[junit4] 2> 1576791 INFO (qtp171238390-19644) [n:127.0.0.1:62646_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=1
[junit4] 2> 1576791 DEBUG (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 1576793 INFO (qtp350221344-19643) [n:127.0.0.1:62645_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=2
[junit4] 2> 1576796 INFO (qtp171238390-19638) [n:127.0.0.1:62646_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=2
[junit4] 2> 1576798 DEBUG (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 8866643 sessionWrapper.createTime 8866636381500, this.sessionWrapper.createTime 8866636381500
[junit4] 2> 1576802 INFO (OverseerStateUpdate-72058175064047623-127.0.0.1:62646_solr-n_0000000000) [n:127.0.0.1:62646_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testScheduledTrigger",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"testScheduledTrigger_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:62646/solr",
[junit4] 2> "node_name":"127.0.0.1:62646_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 1576808 INFO (OverseerStateUpdate-72058175064047623-127.0.0.1:62646_solr-n_0000000000) [n:127.0.0.1:62646_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testScheduledTrigger",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"testScheduledTrigger_shard1_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:62645/solr",
[junit4] 2> "node_name":"127.0.0.1:62645_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 1576815 INFO (OverseerStateUpdate-72058175064047623-127.0.0.1:62646_solr-n_0000000000) [n:127.0.0.1:62646_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testScheduledTrigger",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"testScheduledTrigger_shard1_replica_n4",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:62645/solr",
[junit4] 2> "node_name":"127.0.0.1:62645_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 1577004 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=testScheduledTrigger.AUTOCREATED&newCollection=true&name=testScheduledTrigger_shard1_replica_n1&action=CREATE&numShards=1&collection=testScheduledTrigger&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 1577004 INFO (qtp350221344-19641) [n:127.0.0.1:62645_solr x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node5&collection.configName=testScheduledTrigger.AUTOCREATED&newCollection=true&name=testScheduledTrigger_shard1_replica_n2&action=CREATE&numShards=1&collection=testScheduledTrigger&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 1577004 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 1577004 INFO (qtp350221344-19643) [n:127.0.0.1:62645_solr x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node6&collection.configName=testScheduledTrigger.AUTOCREATED&newCollection=true&name=testScheduledTrigger_shard1_replica_n4&action=CREATE&numShards=1&collection=testScheduledTrigger&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 1577017 INFO (qtp350221344-19643) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.6.0
[junit4] 2> 1577017 INFO (qtp350221344-19641) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.6.0
[junit4] 2> 1577017 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.6.0
[junit4] 2> 1577029 INFO (qtp350221344-19641) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.s.IndexSchema Schema name=default-config
[junit4] 2> 1577029 INFO (qtp350221344-19643) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.s.IndexSchema Schema name=default-config
[junit4] 2> 1577032 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.s.IndexSchema Schema name=default-config
[junit4] 2> 1577131 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.s.IndexSchema Loaded schema default-config/1.6 with uniqueid field id
[junit4] 2> 1577135 INFO (qtp350221344-19641) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.s.IndexSchema Loaded schema default-config/1.6 with uniqueid field id
[junit4] 2> 1577135 INFO (qtp350221344-19643) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.s.IndexSchema Loaded schema default-config/1.6 with uniqueid field id
[junit4] 2> 1577166 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.c.CoreContainer Creating SolrCore 'testScheduledTrigger_shard1_replica_n1' using configuration from configset testScheduledTrigger.AUTOCREATED, trusted=true
[junit4] 2> 1577166 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_62646.solr.core.testScheduledTrigger.shard1.replica_n1' (registry 'solr.core.testScheduledTrigger.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@55f245b4
[junit4] 2> 1577166 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.c.SolrCore [[testScheduledTrigger_shard1_replica_n1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-8.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_64851057649BAC3E-001\tempDir-001\node2\.\testScheduledTrigger_shard1_replica_n1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-8.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_64851057649BAC3E-001\tempDir-001\node2\.\testScheduledTrigger_shard1_replica_n1\data\]
[junit4] 2> 1577173 INFO (qtp350221344-19643) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.c.CoreContainer Creating SolrCore 'testScheduledTrigger_shard1_replica_n4' using configuration from configset testScheduledTrigger.AUTOCREATED, trusted=true
[junit4] 2> 1577174 INFO (qtp350221344-19643) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_62645.solr.core.testScheduledTrigger.shard1.replica_n4' (registry 'solr.core.testScheduledTrigger.shard1.replica_n4') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@55f245b4
[junit4] 2> 1577174 INFO (qtp350221344-19641) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.c.CoreContainer Creating SolrCore 'testScheduledTrigger_shard1_replica_n2' using configuration from configset testScheduledTrigger.AUTOCREATED, trusted=true
[junit4] 2> 1577174 INFO (qtp350221344-19643) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.c.SolrCore [[testScheduledTrigger_shard1_replica_n4] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-8.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_64851057649BAC3E-001\tempDir-001\node1\.\testScheduledTrigger_shard1_replica_n4], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-8.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_64851057649BAC3E-001\tempDir-001\node1\.\testScheduledTrigger_shard1_replica_n4\data\]
[junit4] 2> 1577174 INFO (qtp350221344-19641) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_62645.solr.core.testScheduledTrigger.shard1.replica_n2' (registry 'solr.core.testScheduledTrigger.shard1.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@55f245b4
[junit4] 2> 1577174 INFO (qtp350221344-19641) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.c.SolrCore [[testScheduledTrigger_shard1_replica_n2] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-8.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_64851057649BAC3E-001\tempDir-001\node1\.\testScheduledTrigger_shard1_replica_n2], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-8.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_64851057649BAC3E-001\tempDir-001\node1\.\testScheduledTrigger_shard1_replica_n2\data\]
[junit4] 2> 1577226 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1577226 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1577228 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.u.CommitTracker Hard AutoCommit: if uncommitted for 15000ms;
[junit4] 2> 1577228 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1577230 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/testScheduledTrigger.AUTOCREATED
[junit4] 2> 1577230 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/testScheduledTrigger.AUTOCREATED
[junit4] 2> 1577230 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/testScheduledTrigger.AUTOCREATED/managed-schema
[junit4] 2> 1577230 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 1577230 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
[junit4] 2> 1577230 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.s.DirectSolrSpellChecker init: {name=default,field=_text_,classname=solr.DirectSolrSpellChecker,distanceMeasure=internal,accuracy=0.5,maxEdits=2,minPrefix=1,maxInspections=5,minQueryLength=4,maxQueryFrequency=0.01}
[junit4] 2> 1577230 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 ms
[junit4] 2> 1577230 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1666934862175535104
[junit4] 2> 1577233 INFO (searcherExecutor-12666-thread-1-processing-n:127.0.0.1:62646_solr x:testScheduledTrigger_shard1_replica_n1 c:testScheduledTrigger s:shard1 r:core_node3) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.c.QuerySenderListener QuerySenderListener done.
[junit4] 2> 1577233 INFO (searcherExecutor-12666-thread-1-processing-n:127.0.0.1:62646_solr x:testScheduledTrigger_shard1_replica_n1 c:testScheduledTrigger s:shard1 r:core_node3) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
[junit4] 2> 1577234 INFO (searcherExecutor-12666-thread-1-processing-n:127.0.0.1:62646_solr x:testScheduledTrigger_shard1_replica_n1 c:testScheduledTrigger s:shard1 r:core_node3) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.c.SolrCore [testScheduledTrigger_shard1_replica_n1] Registered new searcher autowarm time: 0 ms: Collection: 'testScheduledTrigger'
[junit4] 2> 1577235 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/testScheduledTrigger/terms/shard1 to Terms{values={core_node3=0}, version=0}
[junit4] 2> 1577235 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/testScheduledTrigger/leaders/shard1
[junit4] 2> 1577237 INFO (qtp350221344-19641) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1577237 INFO (qtp350221344-19641) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1577240 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=3 found=1 timeoute in=9999ms
[junit4] 2> 1577240 INFO (qtp350221344-19641) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.u.CommitTracker Hard AutoCommit: if uncommitted for 15000ms;
[junit4] 2> 1577240 INFO (qtp350221344-19641) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1577240 INFO (qtp350221344-19643) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1577240 INFO (qtp350221344-19643) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1577240 INFO (qtp350221344-19641) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/testScheduledTrigger.AUTOCREATED
[junit4] 2> 1577240 INFO (qtp350221344-19641) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/testScheduledTrigger.AUTOCREATED
[junit4] 2> 1577240 INFO (qtp350221344-19641) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/testScheduledTrigger.AUTOCREATED/managed-schema
[junit4] 2> 1577240 INFO (qtp350221344-19641) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 1577240 INFO (qtp350221344-19641) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
[junit4] 2> 1577240 INFO (qtp350221344-19641) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.s.DirectSolrSpellChecker init: {name=default,field=_text_,classname=solr.DirectSolrSpellChecker,distanceMeasure=internal,accuracy=0.5,maxEdits=2,minPrefix=1,maxInspections=5,minQueryLength=4,maxQueryFrequency=0.01}
[junit4] 2> 1577248 INFO (qtp350221344-19643) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.u.CommitTracker Hard AutoCommit: if uncommitted for 15000ms;
[junit4] 2> 1577248 INFO (qtp350221344-19643) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1577248 INFO (qtp350221344-19641) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 ms
[junit4] 2> 1577248 INFO (qtp350221344-19641) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1666934862194409472
[junit4] 2> 1577250 INFO (qtp350221344-19643) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/testScheduledTrigger.AUTOCREATED
[junit4] 2> 1577250 INFO (searcherExecutor-12670-thread-1-processing-n:127.0.0.1:62645_solr x:testScheduledTrigger_shard1_replica_n2 c:testScheduledTrigger s:shard1 r:core_node5) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.c.QuerySenderListener QuerySenderListener done.
[junit4] 2> 1577250 INFO (searcherExecutor-12670-thread-1-processing-n:127.0.0.1:62645_solr x:testScheduledTrigger_shard1_replica_n2 c:testScheduledTrigger s:shard1 r:core_node5) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
[junit4] 2> 1577250 INFO (qtp350221344-19643) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/testScheduledTrigger.AUTOCREATED
[junit4] 2> 1577250 INFO (qtp350221344-19643) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/testScheduledTrigger.AUTOCREATED/managed-schema
[junit4] 2> 1577251 INFO (searcherExecutor-12670-thread-1-processing-n:127.0.0.1:62645_solr x:testScheduledTrigger_shard1_replica_n2 c:testScheduledTrigger s:shard1 r:core_node5) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.c.SolrCore [testScheduledTrigger_shard1_replica_n2] Registered new searcher autowarm time: 0 ms: Collection: 'testScheduledTrigger'
[junit4] 2> 1577251 INFO (qtp350221344-19643) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 1577251 INFO (qtp350221344-19643) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
[junit4] 2> 1577251 INFO (qtp350221344-19643) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.s.DirectSolrSpellChecker init: {name=default,field=_text_,classname=solr.DirectSolrSpellChecker,distanceMeasure=internal,accuracy=0.5,maxEdits=2,minPrefix=1,maxInspections=5,minQueryLength=4,maxQueryFrequency=0.01}
[junit4] 2> 1577251 INFO (qtp350221344-19643) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 ms
[junit4] 2> 1577252 INFO (qtp350221344-19643) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1666934862198603776
[junit4] 2> 1577254 INFO (qtp350221344-19641) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/testScheduledTrigger/terms/shard1 to Terms{values={core_node3=0, core_node5=0}, version=1}
[junit4] 2> 1577254 INFO (qtp350221344-19641) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/testScheduledTrigger/leaders/shard1
[junit4] 2> 1577254 INFO (searcherExecutor-12668-thread-1-processing-n:127.0.0.1:62645_solr x:testScheduledTrigger_shard1_replica_n4 c:testScheduledTrigger s:shard1 r:core_node6) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.c.QuerySenderListener QuerySenderListener done.
[junit4] 2> 1577254 INFO (searcherExecutor-12668-thread-1-processing-n:127.0.0.1:62645_solr x:testScheduledTrigger_shard1_replica_n4 c:testScheduledTrigger s:shard1 r:core_node6) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
[junit4] 2> 1577255 INFO (searcherExecutor-12668-thread-1-processing-n:127.0.0.1:62645_solr x:testScheduledTrigger_shard1_replica_n4 c:testScheduledTrigger s:shard1 r:core_node6) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.c.SolrCore [testScheduledTrigger_shard1_replica_n4] Registered new searcher autowarm time: 0 ms: Collection: 'testScheduledTrigger'
[junit4] 2> 1577255 INFO (qtp350221344-19643) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/testScheduledTrigger/terms/shard1 to Terms{values={core_node6=0, core_node3=0, core_node5=0}, version=2}
[junit4] 2> 1577255 INFO (qtp350221344-19643) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/testScheduledTrigger/leaders/shard1
[junit4] 2> 1577489 DEBUG (ScheduledTrigger-12642-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 1
[junit4] 2> 1577718 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 1577718 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 1577718 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:62646/solr/testScheduledTrigger_shard1_replica_n1/
[junit4] 2> 1577718 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.u.PeerSync PeerSync: core=testScheduledTrigger_shard1_replica_n1 url=http://127.0.0.1:62646/solr START replicas=[http://127.0.0.1:62645/solr/testScheduledTrigger_shard1_replica_n2/, http://127.0.0.1:62645/solr/testScheduledTrigger_shard1_replica_n4/] nUpdates=100
[junit4] 2> 1577719 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.u.PeerSync PeerSync: core=testScheduledTrigger_shard1_replica_n1 url=http://127.0.0.1:62646/solr DONE. We have no versions. sync failed.
[junit4] 2> 1577719 INFO (qtp350221344-19713) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.c.S.Request [testScheduledTrigger_shard1_replica_n4] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 1577719 INFO (qtp350221344-19639) [n:127.0.0.1:62645_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.c.S.Request [testScheduledTrigger_shard1_replica_n2] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 1577719 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 1577719 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 1577721 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/testScheduledTrigger/leaders/shard1/leader after winning as /collections/testScheduledTrigger/leader_elect/shard1/election/72058175064047623-core_node3-n_0000000000
[junit4] 2> 1577722 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:62646/solr/testScheduledTrigger_shard1_replica_n1/ shard1
[junit4] 2> 1577819 INFO (zkCallback-12636-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testScheduledTrigger/state.json] for collection [testScheduledTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1577820 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 1577824 INFO (qtp171238390-19640) [n:127.0.0.1:62646_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node3&collection.configName=testScheduledTrigger.AUTOCREATED&newCollection=true&name=testScheduledTrigger_shard1_replica_n1&action=CREATE&numShards=1&collection=testScheduledTrigger&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=857
[junit4] 2> 1577918 INFO (zkCallback-12636-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testScheduledTrigger/state.json] for collection [testScheduledTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1577918 INFO (zkCallback-12636-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testScheduledTrigger/state.json] for collection [testScheduledTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1578216 INFO (qtp350221344-19641) [n:127.0.0.1:62645_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node5&collection.configName=testScheduledTrigger.AUTOCREATED&newCollection=true&name=testScheduledTrigger_shard1_replica_n2&action=CREATE&numShards=1&collection=testScheduledTrigger&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1268
[junit4] 2> 1578216 INFO (qtp350221344-19643) [n:127.0.0.1:62645_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node6&collection.configName=testScheduledTrigger.AUTOCREATED&newCollection=true&name=testScheduledTrigger_shard1_replica_n4&action=CREATE&numShards=1&collection=testScheduledTrigger&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1267
[junit4] 2> 1578216 DEBUG (OverseerThreadFactory-12644-thread-1-processing-n:127.0.0.1:62646_solr) [n:127.0.0.1:62646_solr ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 1578217 INFO (qtp350221344-19645) [n:127.0.0.1:62645_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 45 seconds. Check all shard replicas
[junit4] 2> 1578310 INFO (zkCallback-12649-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testScheduledTrigger/state.json] for collection [testScheduledTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1578310 INFO (zkCallback-12636-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testScheduledTrigger/state.json] for collection [testScheduledTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1578310 INFO (zkCallback-12636-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testScheduledTrigger/state.json] for collection [testScheduledTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1578310 INFO (zkCallback-12649-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testScheduledTrigger/state.json] for collection [testScheduledTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1578311 INFO (zkCallback-12649-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testScheduledTrigger/state.json] for collection [testScheduledTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1578311 INFO (qtp350221344-19645) [n:127.0.0.1:62645_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={pullReplicas=0&maxShardsPerNode=5&name=testScheduledTrigger&nrtReplicas=3&action=CREATE&numShards=1&tlogReplicas=0&wt=javabin&version=2} status=0 QTime=1763
[junit4] 2> 1578311 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.c.MiniSolrCloudCluster waitForActiveCollection: testScheduledTrigger
[junit4] 2> 1578313 INFO (qtp350221344-19639) [n:127.0.0.1:62645_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={wt=javabin&version=2&key=solr.core.testScheduledTrigger.shard1.replica_n2:INDEX.sizeInBytes&key=solr.core.testScheduledTrigger.shard1.replica_n4:INDEX.sizeInBytes} status=0 QTime=0
[junit4] 2> 1578313 INFO (qtp350221344-19643) [n:127.0.0.1:62645_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=1
[junit4] 2> 1578315 INFO (qtp171238390-19642) [n:127.0.0.1:62646_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={wt=javabin&version=2&key=solr.core.testScheduledTrigger.shard1.replica_n1:INDEX.sizeInBytes} status=0 QTime=0
[junit4] 2> 1578316 INFO (qtp171238390-19644) [n:127.0.0.1:62646_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=1
[junit4] 2> 1578316 DEBUG (qtp350221344-19713) [n:127.0.0.1:62645_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1578317 INFO (qtp350221344-19713) [n:127.0.0.1:62645_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling params={wt=javabin&version=2} status=0 QTime=4
[junit4] 2> 1578317 DEBUG (zkCallback-12636-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 1578317 DEBUG (OverseerAutoScalingTriggerThread-72058175064047623-127.0.0.1:62646_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 1578317 WARN (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 1578317 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 1578317 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
[junit4] 2> 1578317 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.e.j.s.Server jetty-9.4.27.v20200227; built: 2020-02-27T18:37:21.340Z; git: a304fd9f351f337e7c0e2a7c28878dd536149c6c; jvm 14+36
[junit4] 2> 1578317 DEBUG (OverseerAutoScalingTriggerThread-72058175064047623-127.0.0.1:62646_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 1578317 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1578317 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1578317 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 1578318 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@26049676{/solr,null,AVAILABLE}
[junit4] 2> 1578318 DEBUG (OverseerAutoScalingTriggerThread-72058175064047623-127.0.0.1:62646_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 1578319 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@20179710{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:?????}
[junit4] 2> 1578319 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.e.j.s.Server Started @???????ms
[junit4] 2> 1578319 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=62735}
[junit4] 2> 1578319 ERROR (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1578319 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 1578319 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.6.0
[junit4] 2> 1578319 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1578319 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: C:\Users\jenkins\workspace\Lucene-Solr-8.x-Windows\solr
[junit4] 2> 1578319 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-05-17T10:56:06.268945900Z
[junit4] 2> 1578320 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1578321 INFO (zkConnectionManagerCallback-12684-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1578321 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1578322 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1578445 DEBUG (ScheduledTrigger-12642-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 1578474 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 1578475 WARN (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@461a5012[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1578475 WARN (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@461a5012[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1578477 WARN (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@4b9e3519[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1578477 WARN (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@4b9e3519[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1578478 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:62632/solr
[junit4] 2> 1578479 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1578479 INFO (zkConnectionManagerCallback-12695-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1578479 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1578541 INFO (OverseerCollectionConfigSetProcessor-72058175064047623-127.0.0.1:62646_solr-n_0000000000) [n:127.0.0.1:62646_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> 1578578 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [n:127.0.0.1:62735_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1578580 INFO (zkConnectionManagerCallback-12697-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1578580 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [n:127.0.0.1:62735_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1578583 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [n:127.0.0.1:62735_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1578586 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [n:127.0.0.1:62735_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:62735_solr as DOWN
[junit4] 2> 1578591 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [n:127.0.0.1:62735_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 1578591 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [n:127.0.0.1:62735_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:62735_solr
[junit4] 2> 1578592 INFO (zkCallback-12663-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1578592 INFO (zkCallback-12636-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1578592 INFO (zkCallback-12649-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1578592 INFO (zkCallback-12696-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1578593 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [n:127.0.0.1:62735_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 1578594 WARN (TEST-ScheduledTriggerIntegrationTest.testScheduledTr
[...truncated too long message...]
4
[junit4] 2> 1633276 INFO (jetty-closer-12706-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty tag=null
[junit4] 2> 1633276 INFO (jetty-closer-12706-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@da0940a: rootName = solr_62645, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty/com.codahale.metrics.MetricRegistry@7ce1c3dd
[junit4] 2> 1633276 INFO (jetty-closer-12706-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster tag=null
[junit4] 2> 1633376 INFO (jetty-closer-12706-thread-3) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@20179710{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:?}
[junit4] 2> 1633376 INFO (jetty-closer-12706-thread-3) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@26049676{/solr,null,UNAVAILABLE}
[junit4] 2> 1633376 INFO (jetty-closer-12706-thread-3) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 1633395 INFO (jetty-closer-12706-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72058175064047623-127.0.0.1:62646_solr-n_0000000000) closing
[junit4] 2> 1633395 INFO (zkCallback-12649-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 1633397 INFO (jetty-closer-12706-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@4f31cc0{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:?}
[junit4] 2> 1633397 INFO (jetty-closer-12706-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@7e21a52a{/solr,null,UNAVAILABLE}
[junit4] 2> 1633397 INFO (jetty-closer-12706-thread-1) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 1633525 INFO (jetty-closer-12706-thread-2) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@1a1808cb{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:?}
[junit4] 2> 1633525 INFO (jetty-closer-12706-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@819a91{/solr,null,UNAVAILABLE}
[junit4] 2> 1633525 INFO (jetty-closer-12706-thread-2) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 1633526 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.c.ZkTestServer Shutting down ZkTestServer.
[junit4] 2> 1633782 WARN (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 7 /solr/collections/testScheduledTrigger/terms/shard1
[junit4] 2> 4 /solr/aliases.json
[junit4] 2> 4 /solr/clusterprops.json
[junit4] 2> 3 /solr/configs/testScheduledTrigger.AUTOCREATED/managed-schema
[junit4] 2> 3 /solr/packages.json
[junit4] 2> 3 /solr/security.json
[junit4] 2> 2 /solr/configs/testScheduledTrigger.AUTOCREATED
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 24 /solr/collections/testScheduledTrigger/state.json
[junit4] 2> 4 /solr/clusterstate.json
[junit4] 2> 4 /solr/autoscaling.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 24 /solr/overseer/queue
[junit4] 2> 14 /solr/live_nodes
[junit4] 2> 7 /solr/collections
[junit4] 2> 5 /solr/overseer/collection-queue-work
[junit4] 2>
[junit4] 2> 1633786 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.c.ZkTestServer waitForServerDown: 127.0.0.1:62632
[junit4] 2> 1633786 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:62632
[junit4] 2> 1633786 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 62632
[junit4] 2> 1636312 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[64851057649BAC3E]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testScheduledTrigger
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ScheduledTriggerIntegrationTest -Dtests.method=testScheduledTrigger -Dtests.seed=64851057649BAC3E -Dtests.slow=true -Dtests.locale=ckb -Dtests.timezone=America/North_Dakota/Center -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] FAILURE 60.4s J1 | ScheduledTriggerIntegrationTest.testScheduledTrigger <<<
[junit4] > Throwable #1: java.lang.AssertionError: ScheduledTrigger did not fire in time
[junit4] > at __randomizedtesting.SeedInfo.seed([64851057649BAC3E:F79E58253A66F70A]:0)
[junit4] > at org.apache.solr.cloud.autoscaling.ScheduledTriggerIntegrationTest.testScheduledTrigger(ScheduledTriggerIntegrationTest.java:120)
[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:832)
[junit4] 2> NOTE: leaving temporary files on disk at: C:\Users\jenkins\workspace\Lucene-Solr-8.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_64851057649BAC3E-001
[junit4] 2> NOTE: test params are: codec=Lucene84, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@68dce11d), locale=ckb, timezone=America/North_Dakota/Center
[junit4] 2> NOTE: Windows 10 10.0 amd64/AdoptOpenJDK 14 (64-bit)/cpus=6,threads=1,free=190641008,total=488112128
[junit4] 2> NOTE: All tests run in this JVM: [TestZkChroot, TestMacroExpander, SolrTestCaseJ4Test, ZkSolrClientTest, AuditLoggerIntegrationTest, TestStressCloudBlindAtomicUpdates, TestSimComputePlanAction, ConnectionReuseTest, SolrLogPostToolTest, TestRandomDVFaceting, TestDistributedTracing, SSLMigrationTest, TestSurroundQueryParser, DocumentBuilderTest, CdcrVersionReplicationTest, TestXmlQParserPlugin, MissingSegmentRecoveryTest, TestCloudRecovery2, SyncSliceTest, TestFuzzyAnalyzedSuggestions, TestManagedSynonymFilterFactory, BlockJoinFacetRandomTest, TestCollectionsAPIViaSolrCloudCluster, OverseerCollectionConfigSetProcessorTest, TermsComponentTest, WordBreakSolrSpellCheckerTest, TestNonDefinedSimilarityFactory, TestBlobHandler, TestTolerantUpdateProcessorCloud, TestDistributedSearch, RequiredFieldsTest, TestInfoStreamLogging, RankQueryTest, BigEndianAscendingWordDeserializerTest, BasicDistributedZk2Test, ChaosMonkeySafeLeaderTest, DistributedQueryComponentOptimizationTest, TestSubQueryTransformerCrossCore, ConfigureRecoveryStrategyTest, CheckHdfsIndexTest, TestSimGenericDistributedQueue, TestAddFieldRealTimeGet, TestScoreJoinQPNoScore, HLLSerializationTest, TestCSVResponseWriter, TestLogWatcher, HdfsRestartWhileUpdatingTest, TestComponentsName, FieldMutatingUpdateProcessorTest, AutoAddReplicasIntegrationTest, TriggerCooldownIntegrationTest, TestFastLRUCache, BufferStoreTest, OverseerStatusTest, DeleteShardTest, TestDirectoryFactory, MultiThreadedOCPTest, TestAnalyzeInfixSuggestions, PluginInfoTest, TestIndexingPerformance, TestPHPSerializedResponseWriter, TestTrackingShardHandlerFactory, MetricsHistoryHandlerTest, TestLuceneIndexBackCompat, TestCollationField, SpellCheckCollatorTest, TestDefaultStatsCache, SOLR749Test, TestReload, JWTAuthPluginIntegrationTest, MetricTriggerIntegrationTest, TestGraphTermsQParserPlugin, TestPullReplica, TestNRTOpen, ChangedSchemaMergeTest, TestIntervalFaceting, ReplaceNodeTest, NodeLostTriggerTest, AlternateDirectoryTest, UUIDUpdateProcessorFallbackTest, ParsingFieldUpdateProcessorsTest, IndexSchemaRuntimeFieldTest, ZkStateWriterTest, BadComponentTest, TestFieldCacheWithThreads, FullSolrCloudDistribCmdsTest, SignatureUpdateProcessorFactoryTest, SolrSlf4jReporterTest, TestPseudoReturnFields, UpdateParamsTest, DeleteNodeTest, DistributedVersionInfoTest, LeaderFailureAfterFreshStartTest, RecoveryZkTest, TestCloudDeleteByQuery, TestCloudPhrasesIdentificationComponent, TestConfigSetsAPIZkFailure, TestCryptoKeys, TestDistributedMap, TestDownShardTolerantSearch, TestLeaderElectionWithEmptyReplica, TestSkipOverseerOperations, ZkControllerTest, CollectionReloadTest, CollectionsAPIAsyncDistributedZkTest, ExecutePlanActionTest, ScheduledTriggerIntegrationTest]
[junit4] Completed [593/908 (1!)] on J1 in 60.69s, 1 test, 1 failure <<< FAILURES!
[...truncated 45921 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-8.x-Windows/1136/consoleText
[repro] Revision: 62847cced885fd8b2402b9adc588247340d16f41
[repro] Ant options: "-Dargs=-XX:+UseCompressedOops -XX:+UseParallelGC"
[repro] JUnit rest result XML files will be moved to: ./repro-reports
[repro] ant clean
[...truncated 6 lines...]
[repro] Test suites by module:
[repro] solr\core
[repro] ScheduledTriggerIntegrationTest
[repro] ant compile-test
[...truncated 3484 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.ScheduledTriggerIntegrationTest" -Dtests.showOutput=onerror "-Dargs=-XX:+UseCompressedOops -XX:+UseParallelGC" -Dtests.seed=64851057649BAC3E -Dtests.slow=true -Dtests.locale=ckb -Dtests.timezone=America/North_Dakota/Center -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[...truncated 86 lines...]
[repro] Failures w/original seeds:
[repro] 0/5 failed: org.apache.solr.cloud.autoscaling.ScheduledTriggerIntegrationTest
[repro] Exiting with code 0
[...truncated 78 lines...]
[JENKINS] Lucene-Solr-8.x-Windows (64bit/jdk-11.0.6) - Build # 1137
- Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-8.x-Windows/1137/
Java: 64bit/jdk-11.0.6 -XX:-UseCompressedOops -XX:+UseParallelGC
1 tests failed.
FAILED: org.apache.solr.cloud.autoscaling.ScheduledTriggerIntegrationTest.testScheduledTrigger
Error Message:
ScheduledTrigger did not fire in time
Stack Trace:
java.lang.AssertionError: ScheduledTrigger did not fire in time
at __randomizedtesting.SeedInfo.seed([8A3880AAE4D9942:9BB8C078F0B0C276]:0)
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.assertTrue(Assert.java:41)
at org.apache.solr.cloud.autoscaling.ScheduledTriggerIntegrationTest.testScheduledTrigger(ScheduledTriggerIntegrationTest.java:120)
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:566)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1750)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
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:947)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
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:834)
Build Log:
[...truncated 15527 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.ScheduledTriggerIntegrationTest
[junit4] 2> 1577431 INFO (SUITE-ScheduledTriggerIntegrationTest-seed#[8A3880AAE4D9942]-worker) [ ] o.a.s.SolrTestCase Setting 'solr.default.confdir' system property to test-framework derived value of 'C:\Users\jenkins\workspace\Lucene-Solr-8.x-Windows\solr\server\solr\configsets\_default\conf'
[junit4] 2> 1577431 INFO (SUITE-ScheduledTriggerIntegrationTest-seed#[8A3880AAE4D9942]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 1577433 INFO (SUITE-ScheduledTriggerIntegrationTest-seed#[8A3880AAE4D9942]-worker) [ ] o.a.s.SolrTestCaseJ4 Created dataDir: C:\Users\jenkins\workspace\Lucene-Solr-8.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_8A3880AAE4D9942-001\data-dir-104-001
[junit4] 2> 1577433 INFO (SUITE-ScheduledTriggerIntegrationTest-seed#[8A3880AAE4D9942]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 1577433 INFO (SUITE-ScheduledTriggerIntegrationTest-seed#[8A3880AAE4D9942]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason="", value=0.0/0.0, ssl=0.0/0.0, clientAuth=0.0/0.0)
[junit4] 2> 1577435 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testScheduledTrigger
[junit4] 2> 1577435 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in C:\Users\jenkins\workspace\Lucene-Solr-8.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_8A3880AAE4D9942-001\tempDir-001
[junit4] 2> 1577435 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 1577436 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port: 0.0.0.0/0.0.0.0:0
[junit4] 2> 1577436 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 1577527 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.c.ZkTestServer start zk server on port: 59546
[junit4] 2> 1577527 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.c.ZkTestServer waitForServerUp: 127.0.0.1:59546
[junit4] 2> 1577527 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:59546
[junit4] 2> 1577527 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 59546
[junit4] 2> 1577528 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1577531 INFO (zkConnectionManagerCallback-15063-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1577531 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1577533 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1577534 INFO (zkConnectionManagerCallback-15065-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1577534 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1577535 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1577536 INFO (zkConnectionManagerCallback-15067-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1577536 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1577630 WARN (jetty-launcher-15068-thread-1) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 1577630 WARN (jetty-launcher-15068-thread-2) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 1577630 INFO (jetty-launcher-15068-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 1577630 INFO (jetty-launcher-15068-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
[junit4] 2> 1577630 INFO (jetty-launcher-15068-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 1577630 INFO (jetty-launcher-15068-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
[junit4] 2> 1577630 INFO (jetty-launcher-15068-thread-2) [ ] o.e.j.s.Server jetty-9.4.27.v20200227; built: 2020-02-27T18:37:21.340Z; git: a304fd9f351f337e7c0e2a7c28878dd536149c6c; jvm 11.0.6+10
[junit4] 2> 1577630 INFO (jetty-launcher-15068-thread-1) [ ] o.e.j.s.Server jetty-9.4.27.v20200227; built: 2020-02-27T18:37:21.340Z; git: a304fd9f351f337e7c0e2a7c28878dd536149c6c; jvm 11.0.6+10
[junit4] 2> 1577631 INFO (jetty-launcher-15068-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1577631 INFO (jetty-launcher-15068-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1577631 INFO (jetty-launcher-15068-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1577631 INFO (jetty-launcher-15068-thread-2) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 1577631 INFO (jetty-launcher-15068-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1577631 INFO (jetty-launcher-15068-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 1577632 INFO (jetty-launcher-15068-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@72fc4719{/solr,null,AVAILABLE}
[junit4] 2> 1577632 INFO (jetty-launcher-15068-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@4ebaab32{/solr,null,AVAILABLE}
[junit4] 2> 1577633 INFO (jetty-launcher-15068-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@6c86d510{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:59560}
[junit4] 2> 1577633 INFO (jetty-launcher-15068-thread-2) [ ] o.e.j.s.Server Started @1525229ms
[junit4] 2> 1577633 INFO (jetty-launcher-15068-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@58ca4d92{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:59561}
[junit4] 2> 1577633 INFO (jetty-launcher-15068-thread-1) [ ] o.e.j.s.Server Started @1525229ms
[junit4] 2> 1577633 INFO (jetty-launcher-15068-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=59560}
[junit4] 2> 1577633 INFO (jetty-launcher-15068-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=59561}
[junit4] 2> 1577633 ERROR (jetty-launcher-15068-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1577633 ERROR (jetty-launcher-15068-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1577633 INFO (jetty-launcher-15068-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 1577633 INFO (jetty-launcher-15068-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 1577633 INFO (jetty-launcher-15068-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.6.0
[junit4] 2> 1577633 INFO (jetty-launcher-15068-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.6.0
[junit4] 2> 1577633 INFO (jetty-launcher-15068-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1577633 INFO (jetty-launcher-15068-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1577633 INFO (jetty-launcher-15068-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: C:\Users\jenkins\workspace\Lucene-Solr-8.x-Windows\solr
[junit4] 2> 1577633 INFO (jetty-launcher-15068-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: C:\Users\jenkins\workspace\Lucene-Solr-8.x-Windows\solr
[junit4] 2> 1577633 INFO (jetty-launcher-15068-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-05-17T16:03:47.239258300Z
[junit4] 2> 1577633 INFO (jetty-launcher-15068-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-05-17T16:03:47.239258300Z
[junit4] 2> 1577634 INFO (jetty-launcher-15068-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1577634 INFO (jetty-launcher-15068-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1577635 INFO (zkConnectionManagerCallback-15072-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1577635 INFO (jetty-launcher-15068-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1577635 INFO (zkConnectionManagerCallback-15071-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1577635 INFO (jetty-launcher-15068-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1577635 INFO (jetty-launcher-15068-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1577635 INFO (jetty-launcher-15068-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1577813 INFO (jetty-launcher-15068-thread-2) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 1577814 WARN (jetty-launcher-15068-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@7647307[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1577814 WARN (jetty-launcher-15068-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@7647307[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1577816 WARN (jetty-launcher-15068-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@4c6ea6cd[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1577816 WARN (jetty-launcher-15068-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@4c6ea6cd[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1577816 INFO (jetty-launcher-15068-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:59546/solr
[junit4] 2> 1577817 INFO (jetty-launcher-15068-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1577818 INFO (zkConnectionManagerCallback-15083-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1577818 INFO (jetty-launcher-15068-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1577862 INFO (jetty-launcher-15068-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 1577863 WARN (jetty-launcher-15068-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@7c9543a4[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1577863 WARN (jetty-launcher-15068-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@7c9543a4[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1577865 WARN (jetty-launcher-15068-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@92a0cd7[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1577865 WARN (jetty-launcher-15068-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@92a0cd7[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1577866 INFO (jetty-launcher-15068-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:59546/solr
[junit4] 2> 1577866 INFO (jetty-launcher-15068-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1577867 INFO (zkConnectionManagerCallback-15094-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1577867 INFO (jetty-launcher-15068-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1577913 INFO (jetty-launcher-15068-thread-2) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1577914 INFO (zkConnectionManagerCallback-15096-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1577914 INFO (jetty-launcher-15068-thread-2) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1577976 INFO (jetty-launcher-15068-thread-2) [n:127.0.0.1:59560_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:59560_solr
[junit4] 2> 1577979 INFO (jetty-launcher-15068-thread-2) [n:127.0.0.1:59560_solr ] o.a.s.c.Overseer Overseer (id=72059343834316807-127.0.0.1:59560_solr-n_0000000000) starting
[junit4] 2> 1577983 INFO (OverseerStateUpdate-72059343834316807-127.0.0.1:59560_solr-n_0000000000) [n:127.0.0.1:59560_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:59560_solr
[junit4] 2> 1577983 INFO (jetty-launcher-15068-thread-2) [n:127.0.0.1:59560_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:59560_solr
[junit4] 2> 1577984 DEBUG (OverseerAutoScalingTriggerThread-72059343834316807-127.0.0.1:59560_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 1577984 INFO (OverseerStateUpdate-72059343834316807-127.0.0.1:59560_solr-n_0000000000) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1577985 DEBUG (OverseerAutoScalingTriggerThread-72059343834316807-127.0.0.1:59560_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 1577985 DEBUG (OverseerAutoScalingTriggerThread-72059343834316807-127.0.0.1:59560_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 0
[junit4] 2> 1577985 DEBUG (OverseerAutoScalingTriggerThread-72059343834316807-127.0.0.1:59560_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 1577986 INFO (jetty-launcher-15068-thread-2) [n:127.0.0.1:59560_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 1577986 WARN (jetty-launcher-15068-thread-2) [n:127.0.0.1:59560_solr ] o.a.s.c.CoreContainer Not all security plugins configured! authentication=disabled authorization=disabled. Solr is only as secure as you make it. Consider configuring authentication/authorization before exposing Solr to users internal or external. See https://s.apache.org/solrsecurity for more info
[junit4] 2> 1577987 DEBUG (OverseerAutoScalingTriggerThread-72059343834316807-127.0.0.1:59560_solr-n_0000000000) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:59560_solr]
[junit4] 2> 1577988 DEBUG (OverseerAutoScalingTriggerThread-72059343834316807-127.0.0.1:59560_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 1577988 DEBUG (ScheduledTrigger-15101-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 and last live nodes: 1
[junit4] 2> 1577988 DEBUG (OverseerAutoScalingTriggerThread-72059343834316807-127.0.0.1:59560_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 1578002 INFO (jetty-launcher-15068-thread-2) [n:127.0.0.1:59560_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 1578004 INFO (jetty-launcher-15068-thread-1) [n:127.0.0.1:59561_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1578006 INFO (zkConnectionManagerCallback-15109-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1578006 INFO (jetty-launcher-15068-thread-1) [n:127.0.0.1:59561_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1578009 INFO (jetty-launcher-15068-thread-1) [n:127.0.0.1:59561_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1578012 INFO (jetty-launcher-15068-thread-1) [n:127.0.0.1:59561_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:59561_solr as DOWN
[junit4] 2> 1578013 INFO (jetty-launcher-15068-thread-1) [n:127.0.0.1:59561_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 1578013 INFO (jetty-launcher-15068-thread-1) [n:127.0.0.1:59561_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:59561_solr
[junit4] 2> 1578013 INFO (zkCallback-15095-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1578014 INFO (zkCallback-15108-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1578015 INFO (jetty-launcher-15068-thread-1) [n:127.0.0.1:59561_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 1578015 WARN (jetty-launcher-15068-thread-1) [n:127.0.0.1:59561_solr ] o.a.s.c.CoreContainer Not all security plugins configured! authentication=disabled authorization=disabled. Solr is only as secure as you make it. Consider configuring authentication/authorization before exposing Solr to users internal or external. See https://s.apache.org/solrsecurity for more info
[junit4] 2> 1578019 INFO (jetty-launcher-15068-thread-2) [n:127.0.0.1:59560_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_59560.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5255f12e
[junit4] 2> 1578023 INFO (jetty-launcher-15068-thread-2) [n:127.0.0.1:59560_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_59560.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5255f12e
[junit4] 2> 1578023 INFO (jetty-launcher-15068-thread-2) [n:127.0.0.1:59560_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_59560.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5255f12e
[junit4] 2> 1578023 INFO (jetty-launcher-15068-thread-2) [n:127.0.0.1:59560_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-8.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_8A3880AAE4D9942-001\tempDir-001\node2\.
[junit4] 2> 1578032 INFO (jetty-launcher-15068-thread-1) [n:127.0.0.1:59561_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 1578045 INFO (jetty-launcher-15068-thread-1) [n:127.0.0.1:59561_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_59561.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5255f12e
[junit4] 2> 1578046 INFO (jetty-launcher-15068-thread-1) [n:127.0.0.1:59561_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_59561.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5255f12e
[junit4] 2> 1578046 INFO (jetty-launcher-15068-thread-1) [n:127.0.0.1:59561_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_59561.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5255f12e
[junit4] 2> 1578046 INFO (jetty-launcher-15068-thread-1) [n:127.0.0.1:59561_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-8.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_8A3880AAE4D9942-001\tempDir-001\node1\.
[junit4] 2> 1578058 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.c.MiniSolrCloudCluster waitForAllNodes: numServers=2
[junit4] 2> 1578059 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1578061 INFO (zkConnectionManagerCallback-15123-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1578061 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1578061 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1578062 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:59546/solr ready
[junit4] 2> 1578066 INFO (qtp1443735843-23728) [n:127.0.0.1:59561_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling params={wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 1578069 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=2
[junit4] 2> 1578072 INFO (qtp1443735843-23730) [n:127.0.0.1:59561_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=1
[junit4] 2> 1578072 DEBUG (qtp1648441128-23727) [n:127.0.0.1:59560_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1578072 INFO (qtp1648441128-23727) [n:127.0.0.1:59560_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling params={wt=javabin&version=2} status=0 QTime=5
[junit4] 2> 1578072 DEBUG (zkCallback-15095-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 1578073 DEBUG (OverseerAutoScalingTriggerThread-72059343834316807-127.0.0.1:59560_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 1578073 INFO (qtp1648441128-23729) [n:127.0.0.1:59560_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params pullReplicas=0&maxShardsPerNode=5&name=testScheduledTrigger&nrtReplicas=3&action=CREATE&numShards=1&tlogReplicas=0&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1578074 DEBUG (OverseerAutoScalingTriggerThread-72059343834316807-127.0.0.1:59560_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 1578075 DEBUG (OverseerAutoScalingTriggerThread-72059343834316807-127.0.0.1:59560_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 1578076 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection testScheduledTrigger
[junit4] 2> 1578076 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/managed-schema to /configs/testScheduledTrigger.AUTOCREATED/managed-schema
[junit4] 2> 1578077 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/protwords.txt to /configs/testScheduledTrigger.AUTOCREATED/protwords.txt
[junit4] 2> 1578078 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/contractions_it.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/contractions_it.txt
[junit4] 2> 1578080 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/contractions_ca.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/contractions_ca.txt
[junit4] 2> 1578081 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stemdict_nl.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stemdict_nl.txt
[junit4] 2> 1578082 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_hy.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_hy.txt
[junit4] 2> 1578083 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_no.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_no.txt
[junit4] 2> 1578084 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_id.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_id.txt
[junit4] 2> 1578085 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_et.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_et.txt
[junit4] 2> 1578086 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_da.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_da.txt
[junit4] 2> 1578087 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_ga.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_ga.txt
[junit4] 2> 1578088 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_hi.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_hi.txt
[junit4] 2> 1578089 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_ja.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_ja.txt
[junit4] 2> 1578090 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_pt.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_pt.txt
[junit4] 2> 1578092 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_hu.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_hu.txt
[junit4] 2> 1578093 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_el.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_el.txt
[junit4] 2> 1578093 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_ru.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_ru.txt
[junit4] 2> 1578095 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_tr.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_tr.txt
[junit4] 2> 1578096 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_ar.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_ar.txt
[junit4] 2> 1578097 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/userdict_ja.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/userdict_ja.txt
[junit4] 2> 1578098 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_eu.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_eu.txt
[junit4] 2> 1578099 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_it.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_it.txt
[junit4] 2> 1578100 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_cz.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_cz.txt
[junit4] 2> 1578101 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stoptags_ja.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stoptags_ja.txt
[junit4] 2> 1578103 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/contractions_fr.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/contractions_fr.txt
[junit4] 2> 1578104 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_de.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_de.txt
[junit4] 2> 1578105 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_fa.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_fa.txt
[junit4] 2> 1578106 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/contractions_ga.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/contractions_ga.txt
[junit4] 2> 1578107 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_ca.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_ca.txt
[junit4] 2> 1578109 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_nl.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_nl.txt
[junit4] 2> 1578109 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_bg.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_bg.txt
[junit4] 2> 1578111 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_en.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_en.txt
[junit4] 2> 1578112 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_es.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_es.txt
[junit4] 2> 1578113 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_lv.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_lv.txt
[junit4] 2> 1578114 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_ro.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_ro.txt
[junit4] 2> 1578115 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_th.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_th.txt
[junit4] 2> 1578116 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_fr.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_fr.txt
[junit4] 2> 1578118 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_sv.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_sv.txt
[junit4] 2> 1578118 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_fi.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_fi.txt
[junit4] 2> 1578120 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/hyphenations_ga.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/hyphenations_ga.txt
[junit4] 2> 1578121 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_gl.txt to /configs/testScheduledTrigger.AUTOCREATED/lang/stopwords_gl.txt
[junit4] 2> 1578122 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/solrconfig.xml to /configs/testScheduledTrigger.AUTOCREATED/solrconfig.xml
[junit4] 2> 1578123 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/synonyms.txt to /configs/testScheduledTrigger.AUTOCREATED/synonyms.txt
[junit4] 2> 1578124 INFO (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/stopwords.txt to /configs/testScheduledTrigger.AUTOCREATED/stopwords.txt
[junit4] 2> 1578218 WARN (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.a.c.CreateCollectionCmd Specified number of replicas of 3 on collection testScheduledTrigger is higher than the number of Solr instances currently live or live and part of your createNodeSet(2). It's unusual to run two replica of the same slice on the same Solr-instance.
[junit4] 2> 1578219 DEBUG (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 1578221 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=2
[junit4] 2> 1578223 INFO (qtp1443735843-23732) [n:127.0.0.1:59561_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=2
[junit4] 2> 1578224 DEBUG (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 1578225 INFO (qtp1648441128-23727) [n:127.0.0.1:59560_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=1
[junit4] 2> 1578227 INFO (qtp1443735843-23726) [n:127.0.0.1:59561_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=1
[junit4] 2> 1578229 DEBUG (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 26700637 sessionWrapper.createTime 26700632202500, this.sessionWrapper.createTime 26700632202500
[junit4] 2> 1578230 INFO (OverseerStateUpdate-72059343834316807-127.0.0.1:59560_solr-n_0000000000) [n:127.0.0.1:59560_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testScheduledTrigger",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"testScheduledTrigger_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:59561/solr",
[junit4] 2> "node_name":"127.0.0.1:59561_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 1578233 INFO (OverseerStateUpdate-72059343834316807-127.0.0.1:59560_solr-n_0000000000) [n:127.0.0.1:59560_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testScheduledTrigger",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"testScheduledTrigger_shard1_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:59560/solr",
[junit4] 2> "node_name":"127.0.0.1:59560_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 1578235 INFO (OverseerStateUpdate-72059343834316807-127.0.0.1:59560_solr-n_0000000000) [n:127.0.0.1:59560_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testScheduledTrigger",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"testScheduledTrigger_shard1_replica_n4",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:59560/solr",
[junit4] 2> "node_name":"127.0.0.1:59560_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 1578419 INFO (qtp1443735843-23728) [n:127.0.0.1:59561_solr x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=testScheduledTrigger.AUTOCREATED&newCollection=true&name=testScheduledTrigger_shard1_replica_n1&action=CREATE&numShards=1&collection=testScheduledTrigger&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 1578419 INFO (qtp1648441128-23725) [n:127.0.0.1:59560_solr x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node5&collection.configName=testScheduledTrigger.AUTOCREATED&newCollection=true&name=testScheduledTrigger_shard1_replica_n2&action=CREATE&numShards=1&collection=testScheduledTrigger&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 1578419 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node6&collection.configName=testScheduledTrigger.AUTOCREATED&newCollection=true&name=testScheduledTrigger_shard1_replica_n4&action=CREATE&numShards=1&collection=testScheduledTrigger&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 1578419 INFO (qtp1648441128-23725) [n:127.0.0.1:59560_solr x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 1578433 INFO (qtp1443735843-23728) [n:127.0.0.1:59561_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.6.0
[junit4] 2> 1578433 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.6.0
[junit4] 2> 1578433 INFO (qtp1648441128-23725) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.6.0
[junit4] 2> 1578449 INFO (qtp1443735843-23728) [n:127.0.0.1:59561_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.s.IndexSchema Schema name=default-config
[junit4] 2> 1578449 INFO (qtp1648441128-23725) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.s.IndexSchema Schema name=default-config
[junit4] 2> 1578449 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.s.IndexSchema Schema name=default-config
[junit4] 2> 1578562 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.s.IndexSchema Loaded schema default-config/1.6 with uniqueid field id
[junit4] 2> 1578568 INFO (qtp1443735843-23728) [n:127.0.0.1:59561_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.s.IndexSchema Loaded schema default-config/1.6 with uniqueid field id
[junit4] 2> 1578570 INFO (qtp1648441128-23725) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.s.IndexSchema Loaded schema default-config/1.6 with uniqueid field id
[junit4] 2> 1578595 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.c.CoreContainer Creating SolrCore 'testScheduledTrigger_shard1_replica_n4' using configuration from configset testScheduledTrigger.AUTOCREATED, trusted=true
[junit4] 2> 1578596 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_59560.solr.core.testScheduledTrigger.shard1.replica_n4' (registry 'solr.core.testScheduledTrigger.shard1.replica_n4') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5255f12e
[junit4] 2> 1578596 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.c.SolrCore [[testScheduledTrigger_shard1_replica_n4] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-8.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_8A3880AAE4D9942-001\tempDir-001\node2\.\testScheduledTrigger_shard1_replica_n4], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-8.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_8A3880AAE4D9942-001\tempDir-001\node2\.\testScheduledTrigger_shard1_replica_n4\data\]
[junit4] 2> 1578598 INFO (qtp1443735843-23728) [n:127.0.0.1:59561_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.c.CoreContainer Creating SolrCore 'testScheduledTrigger_shard1_replica_n1' using configuration from configset testScheduledTrigger.AUTOCREATED, trusted=true
[junit4] 2> 1578598 INFO (qtp1443735843-23728) [n:127.0.0.1:59561_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_59561.solr.core.testScheduledTrigger.shard1.replica_n1' (registry 'solr.core.testScheduledTrigger.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5255f12e
[junit4] 2> 1578598 INFO (qtp1443735843-23728) [n:127.0.0.1:59561_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.c.SolrCore [[testScheduledTrigger_shard1_replica_n1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-8.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_8A3880AAE4D9942-001\tempDir-001\node1\.\testScheduledTrigger_shard1_replica_n1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-8.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_8A3880AAE4D9942-001\tempDir-001\node1\.\testScheduledTrigger_shard1_replica_n1\data\]
[junit4] 2> 1578602 INFO (qtp1648441128-23725) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.c.CoreContainer Creating SolrCore 'testScheduledTrigger_shard1_replica_n2' using configuration from configset testScheduledTrigger.AUTOCREATED, trusted=true
[junit4] 2> 1578602 INFO (qtp1648441128-23725) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_59560.solr.core.testScheduledTrigger.shard1.replica_n2' (registry 'solr.core.testScheduledTrigger.shard1.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5255f12e
[junit4] 2> 1578602 INFO (qtp1648441128-23725) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.c.SolrCore [[testScheduledTrigger_shard1_replica_n2] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-8.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_8A3880AAE4D9942-001\tempDir-001\node2\.\testScheduledTrigger_shard1_replica_n2], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-8.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_8A3880AAE4D9942-001\tempDir-001\node2\.\testScheduledTrigger_shard1_replica_n2\data\]
[junit4] 2> 1578658 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1578658 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1578660 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.u.CommitTracker Hard AutoCommit: if uncommitted for 15000ms;
[junit4] 2> 1578660 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1578662 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/testScheduledTrigger.AUTOCREATED
[junit4] 2> 1578667 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/testScheduledTrigger.AUTOCREATED
[junit4] 2> 1578667 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/testScheduledTrigger.AUTOCREATED/managed-schema
[junit4] 2> 1578668 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 1578668 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
[junit4] 2> 1578668 INFO (qtp1443735843-23728) [n:127.0.0.1:59561_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1578668 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.s.DirectSolrSpellChecker init: {name=default,field=_text_,classname=solr.DirectSolrSpellChecker,distanceMeasure=internal,accuracy=0.5,maxEdits=2,minPrefix=1,maxInspections=5,minQueryLength=4,maxQueryFrequency=0.01}
[junit4] 2> 1578668 INFO (qtp1443735843-23728) [n:127.0.0.1:59561_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1578669 INFO (qtp1648441128-23725) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1578669 INFO (qtp1648441128-23725) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1578669 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 ms
[junit4] 2> 1578669 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1666954222134886400
[junit4] 2> 1578670 INFO (searcherExecutor-15125-thread-1-processing-n:127.0.0.1:59560_solr x:testScheduledTrigger_shard1_replica_n4 c:testScheduledTrigger s:shard1 r:core_node6) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.c.QuerySenderListener QuerySenderListener done.
[junit4] 2> 1578670 INFO (searcherExecutor-15125-thread-1-processing-n:127.0.0.1:59560_solr x:testScheduledTrigger_shard1_replica_n4 c:testScheduledTrigger s:shard1 r:core_node6) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
[junit4] 2> 1578670 INFO (qtp1443735843-23728) [n:127.0.0.1:59561_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.u.CommitTracker Hard AutoCommit: if uncommitted for 15000ms;
[junit4] 2> 1578671 INFO (qtp1443735843-23728) [n:127.0.0.1:59561_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1578671 INFO (searcherExecutor-15125-thread-1-processing-n:127.0.0.1:59560_solr x:testScheduledTrigger_shard1_replica_n4 c:testScheduledTrigger s:shard1 r:core_node6) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.c.SolrCore [testScheduledTrigger_shard1_replica_n4] Registered new searcher autowarm time: 0 ms: Collection: 'testScheduledTrigger'
[junit4] 2> 1578671 INFO (qtp1648441128-23725) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.u.CommitTracker Hard AutoCommit: if uncommitted for 15000ms;
[junit4] 2> 1578671 INFO (qtp1648441128-23725) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1578672 INFO (qtp1443735843-23728) [n:127.0.0.1:59561_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/testScheduledTrigger.AUTOCREATED
[junit4] 2> 1578672 INFO (qtp1443735843-23728) [n:127.0.0.1:59561_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/testScheduledTrigger.AUTOCREATED
[junit4] 2> 1578672 INFO (qtp1443735843-23728) [n:127.0.0.1:59561_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/testScheduledTrigger.AUTOCREATED/managed-schema
[junit4] 2> 1578672 INFO (qtp1648441128-23725) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/testScheduledTrigger.AUTOCREATED
[junit4] 2> 1578672 INFO (qtp1648441128-23725) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/testScheduledTrigger.AUTOCREATED
[junit4] 2> 1578672 INFO (qtp1648441128-23725) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/testScheduledTrigger.AUTOCREATED/managed-schema
[junit4] 2> 1578672 INFO (qtp1443735843-23728) [n:127.0.0.1:59561_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 1578672 INFO (qtp1443735843-23728) [n:127.0.0.1:59561_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
[junit4] 2> 1578673 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/testScheduledTrigger/terms/shard1 to Terms{values={core_node6=0}, version=0}
[junit4] 2> 1578673 INFO (qtp1443735843-23728) [n:127.0.0.1:59561_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.s.DirectSolrSpellChecker init: {name=default,field=_text_,classname=solr.DirectSolrSpellChecker,distanceMeasure=internal,accuracy=0.5,maxEdits=2,minPrefix=1,maxInspections=5,minQueryLength=4,maxQueryFrequency=0.01}
[junit4] 2> 1578673 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/testScheduledTrigger/leaders/shard1
[junit4] 2> 1578673 INFO (qtp1648441128-23725) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 1578673 INFO (qtp1648441128-23725) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
[junit4] 2> 1578673 INFO (qtp1648441128-23725) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.s.DirectSolrSpellChecker init: {name=default,field=_text_,classname=solr.DirectSolrSpellChecker,distanceMeasure=internal,accuracy=0.5,maxEdits=2,minPrefix=1,maxInspections=5,minQueryLength=4,maxQueryFrequency=0.01}
[junit4] 2> 1578673 INFO (qtp1443735843-23728) [n:127.0.0.1:59561_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 ms
[junit4] 2> 1578673 INFO (qtp1648441128-23725) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 ms
[junit4] 2> 1578674 INFO (qtp1443735843-23728) [n:127.0.0.1:59561_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1666954222140129280
[junit4] 2> 1578674 INFO (qtp1648441128-23725) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1666954222140129280
[junit4] 2> 1578674 INFO (searcherExecutor-15129-thread-1-processing-n:127.0.0.1:59560_solr x:testScheduledTrigger_shard1_replica_n2 c:testScheduledTrigger s:shard1 r:core_node5) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.c.QuerySenderListener QuerySenderListener done.
[junit4] 2> 1578674 INFO (searcherExecutor-15129-thread-1-processing-n:127.0.0.1:59560_solr x:testScheduledTrigger_shard1_replica_n2 c:testScheduledTrigger s:shard1 r:core_node5) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
[junit4] 2> 1578674 INFO (searcherExecutor-15127-thread-1-processing-n:127.0.0.1:59561_solr x:testScheduledTrigger_shard1_replica_n1 c:testScheduledTrigger s:shard1 r:core_node3) [n:127.0.0.1:59561_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.c.QuerySenderListener QuerySenderListener done.
[junit4] 2> 1578674 INFO (searcherExecutor-15127-thread-1-processing-n:127.0.0.1:59561_solr x:testScheduledTrigger_shard1_replica_n1 c:testScheduledTrigger s:shard1 r:core_node3) [n:127.0.0.1:59561_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
[junit4] 2> 1578674 INFO (searcherExecutor-15129-thread-1-processing-n:127.0.0.1:59560_solr x:testScheduledTrigger_shard1_replica_n2 c:testScheduledTrigger s:shard1 r:core_node5) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.c.SolrCore [testScheduledTrigger_shard1_replica_n2] Registered new searcher autowarm time: 0 ms: Collection: 'testScheduledTrigger'
[junit4] 2> 1578674 INFO (searcherExecutor-15127-thread-1-processing-n:127.0.0.1:59561_solr x:testScheduledTrigger_shard1_replica_n1 c:testScheduledTrigger s:shard1 r:core_node3) [n:127.0.0.1:59561_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.c.SolrCore [testScheduledTrigger_shard1_replica_n1] Registered new searcher autowarm time: 0 ms: Collection: 'testScheduledTrigger'
[junit4] 2> 1578676 INFO (qtp1648441128-23725) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/testScheduledTrigger/terms/shard1 to Terms{values={core_node6=0, core_node5=0}, version=1}
[junit4] 2> 1578676 INFO (qtp1648441128-23725) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/testScheduledTrigger/leaders/shard1
[junit4] 2> 1578677 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=3 found=2 timeoute in=9999ms
[junit4] 2> 1578677 INFO (qtp1443735843-23728) [n:127.0.0.1:59561_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/testScheduledTrigger/terms/shard1 to Terms{values={core_node6=0, core_node3=0, core_node5=0}, version=2}
[junit4] 2> 1578677 INFO (qtp1443735843-23728) [n:127.0.0.1:59561_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/testScheduledTrigger/leaders/shard1
[junit4] 2> 1578904 DEBUG (ScheduledTrigger-15101-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 1
[junit4] 2> 1579134 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 1579134 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 1579134 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:59560/solr/testScheduledTrigger_shard1_replica_n4/
[junit4] 2> 1579135 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.u.PeerSync PeerSync: core=testScheduledTrigger_shard1_replica_n4 url=http://127.0.0.1:59560/solr START replicas=[http://127.0.0.1:59561/solr/testScheduledTrigger_shard1_replica_n1/, http://127.0.0.1:59560/solr/testScheduledTrigger_shard1_replica_n2/] nUpdates=100
[junit4] 2> 1579135 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.u.PeerSync PeerSync: core=testScheduledTrigger_shard1_replica_n4 url=http://127.0.0.1:59560/solr DONE. We have no versions. sync failed.
[junit4] 2> 1579136 INFO (qtp1443735843-23732) [n:127.0.0.1:59561_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.c.S.Request [testScheduledTrigger_shard1_replica_n1] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 1579136 INFO (qtp1648441128-23727) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.c.S.Request [testScheduledTrigger_shard1_replica_n2] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 1579136 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 1579136 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 1579136 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/testScheduledTrigger/leaders/shard1/leader after winning as /collections/testScheduledTrigger/leader_elect/shard1/election/72059343834316807-core_node6-n_0000000000
[junit4] 2> 1579138 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:59560/solr/testScheduledTrigger_shard1_replica_n4/ shard1
[junit4] 2> 1579231 INFO (zkCallback-15095-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testScheduledTrigger/state.json] for collection [testScheduledTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1579231 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 1579233 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node6&collection.configName=testScheduledTrigger.AUTOCREATED&newCollection=true&name=testScheduledTrigger_shard1_replica_n4&action=CREATE&numShards=1&collection=testScheduledTrigger&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=892
[junit4] 2> 1579326 INFO (zkCallback-15095-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testScheduledTrigger/state.json] for collection [testScheduledTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1579326 INFO (zkCallback-15095-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testScheduledTrigger/state.json] for collection [testScheduledTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1579594 INFO (qtp1648441128-23725) [n:127.0.0.1:59560_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node5&collection.configName=testScheduledTrigger.AUTOCREATED&newCollection=true&name=testScheduledTrigger_shard1_replica_n2&action=CREATE&numShards=1&collection=testScheduledTrigger&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1287
[junit4] 2> 1579597 INFO (qtp1443735843-23728) [n:127.0.0.1:59561_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node3&collection.configName=testScheduledTrigger.AUTOCREATED&newCollection=true&name=testScheduledTrigger_shard1_replica_n1&action=CREATE&numShards=1&collection=testScheduledTrigger&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1289
[junit4] 2> 1579597 DEBUG (OverseerThreadFactory-15103-thread-1-processing-n:127.0.0.1:59560_solr) [n:127.0.0.1:59560_solr ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 1579598 INFO (qtp1648441128-23729) [n:127.0.0.1:59560_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 45 seconds. Check all shard replicas
[junit4] 2> 1579687 INFO (zkCallback-15095-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testScheduledTrigger/state.json] for collection [testScheduledTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1579687 INFO (zkCallback-15108-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testScheduledTrigger/state.json] for collection [testScheduledTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1579687 INFO (zkCallback-15095-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testScheduledTrigger/state.json] for collection [testScheduledTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1579687 INFO (zkCallback-15108-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testScheduledTrigger/state.json] for collection [testScheduledTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1579687 INFO (qtp1648441128-23729) [n:127.0.0.1:59560_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={pullReplicas=0&maxShardsPerNode=5&name=testScheduledTrigger&nrtReplicas=3&action=CREATE&numShards=1&tlogReplicas=0&wt=javabin&version=2} status=0 QTime=1767
[junit4] 2> 1579687 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.c.MiniSolrCloudCluster waitForActiveCollection: testScheduledTrigger
[junit4] 2> 1579689 INFO (qtp1648441128-23731) [n:127.0.0.1:59560_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={wt=javabin&version=2&key=solr.core.testScheduledTrigger.shard1.replica_n2:INDEX.sizeInBytes&key=solr.core.testScheduledTrigger.shard1.replica_n4:INDEX.sizeInBytes} status=0 QTime=0
[junit4] 2> 1579691 INFO (qtp1648441128-23725) [n:127.0.0.1:59560_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=1
[junit4] 2> 1579691 INFO (qtp1443735843-23726) [n:127.0.0.1:59561_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={wt=javabin&version=2&key=solr.core.testScheduledTrigger.shard1.replica_n1:INDEX.sizeInBytes} status=0 QTime=0
[junit4] 2> 1579693 INFO (qtp1443735843-23730) [n:127.0.0.1:59561_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=1
[junit4] 2> 1579693 DEBUG (qtp1648441128-23727) [n:127.0.0.1:59560_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1579693 INFO (qtp1648441128-23727) [n:127.0.0.1:59560_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling params={wt=javabin&version=2} status=0 QTime=5
[junit4] 2> 1579693 DEBUG (zkCallback-15095-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 1579693 DEBUG (OverseerAutoScalingTriggerThread-72059343834316807-127.0.0.1:59560_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 1579694 DEBUG (OverseerAutoScalingTriggerThread-72059343834316807-127.0.0.1:59560_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 1579694 WARN (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 1579694 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 1579694 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
[junit4] 2> 1579694 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.e.j.s.Server jetty-9.4.27.v20200227; built: 2020-02-27T18:37:21.340Z; git: a304fd9f351f337e7c0e2a7c28878dd536149c6c; jvm 11.0.6+10
[junit4] 2> 1579694 DEBUG (OverseerAutoScalingTriggerThread-72059343834316807-127.0.0.1:59560_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 1579694 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1579694 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1579694 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 1579694 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@778f872a{/solr,null,AVAILABLE}
[junit4] 2> 1579695 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@451a4278{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:59610}
[junit4] 2> 1579695 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.e.j.s.Server Started @1527488ms
[junit4] 2> 1579695 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=59610}
[junit4] 2> 1579696 ERROR (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1579696 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 1579696 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.6.0
[junit4] 2> 1579696 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1579696 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: C:\Users\jenkins\workspace\Lucene-Solr-8.x-Windows\solr
[junit4] 2> 1579696 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-05-17T16:03:49.302246600Z
[junit4] 2> 1579697 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1579698 INFO (zkConnectionManagerCallback-15143-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1579698 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1579698 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1579819 DEBUG (ScheduledTrigger-15101-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 1579903 INFO (OverseerCollectionConfigSetProcessor-72059343834316807-127.0.0.1:59560_solr-n_0000000000) [n:127.0.0.1:59560_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> 1579940 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 1579941 WARN (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@65a0154b[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1579941 WARN (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@65a0154b[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1579943 WARN (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@1b3547a2[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1579943 WARN (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@1b3547a2[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1579944 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:59546/solr
[junit4] 2> 1579945 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1579946 INFO (zkConnectionManagerCallback-15154-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1579946 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1580039 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [n:127.0.0.1:59610_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1580041 INFO (zkConnectionManagerCallback-15156-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1580041 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [n:127.0.0.1:59610_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1580044 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [n:127.0.0.1:59610_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1580047 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [n:127.0.0.1:59610_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:59610_solr as DOWN
[junit4] 2> 1580048 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [n:127.0.0.1:59610_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 1580048 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [n:127.0.0.1:59610_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:59610_solr
[junit4] 2> 1580049 INFO (zkCallback-15108-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1580049 INFO (zkCallback-15095-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1580049 INFO (zkCallback-15122-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1580049 INFO (zkCallback-15155-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1580050 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [n:127.0.0.1:59610_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 1580051 WARN (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [n:127.0.0.1:59610_solr ] o.a.s.c.CoreContainer Not all security plugins configured! authentication=disabled authorization=disabled. Solr is only as secure as you make it. Consider configuring authentication/authorization before exposing Solr to users internal or external. See https://s.apache.org/solrsecurity for more info
[junit4] 2> 1580069 INFO (TEST-ScheduledTriggerIntegrationTest.testSched
[...truncated too long message...]
.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 1631099 DEBUG (closeThreadPool-15182-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 1631099 INFO (closeThreadPool-15182-thread-2) [ ] o.a.s.c.Overseer Overseer (id=72059343834316807-127.0.0.1:59560_solr-n_0000000000) closing
[junit4] 2> 1631202 INFO (jetty-closer-15165-thread-3) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@451a4278{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:0}
[junit4] 2> 1631203 INFO (jetty-closer-15165-thread-3) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@778f872a{/solr,null,UNAVAILABLE}
[junit4] 2> 1631203 INFO (jetty-closer-15165-thread-3) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 1631336 INFO (jetty-closer-15165-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72059343834316807-127.0.0.1:59560_solr-n_0000000000) closing
[junit4] 2> 1631337 INFO (jetty-closer-15165-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@6c86d510{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:0}
[junit4] 2> 1631337 INFO (jetty-closer-15165-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@72fc4719{/solr,null,UNAVAILABLE}
[junit4] 2> 1631337 INFO (jetty-closer-15165-thread-1) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 1631472 INFO (jetty-closer-15165-thread-2) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@58ca4d92{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:0}
[junit4] 2> 1631472 INFO (jetty-closer-15165-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@4ebaab32{/solr,null,UNAVAILABLE}
[junit4] 2> 1631472 INFO (jetty-closer-15165-thread-2) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 1631473 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.c.ZkTestServer Shutting down ZkTestServer.
[junit4] 2> 1631744 WARN (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 6 /solr/collections/testScheduledTrigger/terms/shard1
[junit4] 2> 4 /solr/aliases.json
[junit4] 2> 4 /solr/clusterprops.json
[junit4] 2> 3 /solr/configs/testScheduledTrigger.AUTOCREATED/managed-schema
[junit4] 2> 3 /solr/packages.json
[junit4] 2> 3 /solr/security.json
[junit4] 2> 2 /solr/configs/testScheduledTrigger.AUTOCREATED
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 21 /solr/collections/testScheduledTrigger/state.json
[junit4] 2> 4 /solr/clusterstate.json
[junit4] 2> 4 /solr/autoscaling.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 24 /solr/overseer/queue
[junit4] 2> 14 /solr/live_nodes
[junit4] 2> 7 /solr/collections
[junit4] 2> 4 /solr/overseer/collection-queue-work
[junit4] 2>
[junit4] 2> 1631748 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.c.ZkTestServer waitForServerDown: 127.0.0.1:59546
[junit4] 2> 1631748 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:59546
[junit4] 2> 1631748 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 59546
[junit4] 2> 1634656 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[8A3880AAE4D9942]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testScheduledTrigger
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ScheduledTriggerIntegrationTest -Dtests.method=testScheduledTrigger -Dtests.seed=8A3880AAE4D9942 -Dtests.slow=true -Dtests.locale=en-MU -Dtests.timezone=US/Michigan -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[junit4] FAILURE 57.2s J1 | ScheduledTriggerIntegrationTest.testScheduledTrigger <<<
[junit4] > Throwable #1: java.lang.AssertionError: ScheduledTrigger did not fire in time
[junit4] > at __randomizedtesting.SeedInfo.seed([8A3880AAE4D9942:9BB8C078F0B0C276]:0)
[junit4] > at org.apache.solr.cloud.autoscaling.ScheduledTriggerIntegrationTest.testScheduledTrigger(ScheduledTriggerIntegrationTest.java:120)
[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:566)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] 2> NOTE: leaving temporary files on disk at: C:\Users\jenkins\workspace\Lucene-Solr-8.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_8A3880AAE4D9942-001
[junit4] 2> NOTE: test params are: codec=DummyCompressingStoredFieldsData(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=DUMMY, chunkSize=9893, maxDocsPerChunk=9, blockShift=7), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=DUMMY, chunkSize=9893, blockSize=7)), sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@4efe60f), locale=en-MU, timezone=US/Michigan
[junit4] 2> NOTE: Windows 10 10.0 amd64/AdoptOpenJDK 11.0.6 (64-bit)/cpus=6,threads=1,free=245097344,total=522190848
[junit4] 2> NOTE: All tests run in this JVM: [AuditLoggerIntegrationTest, SpellCheckCollatorTest, AlternateDirectoryTest, DistributedQueryComponentOptimizationTest, TestCloudRecovery2, RecoveryAfterSoftCommitTest, SynonymTokenizerTest, RegexBytesRefFilterTest, SSLMigrationTest, OpenExchangeRatesOrgProviderTest, PKIAuthenticationIntegrationTest, OverseerStatusTest, HLLSerializationTest, CloudMLTQParserTest, MetricsHistoryHandlerTest, TestCloudJSONFacetSKG, SolrRequestParserTest, ReplaceNodeTest, FullSolrCloudDistribCmdsTest, TestSimpleTextCodec, FuzzySearchTest, TestSmileRequest, TestUnifiedSolrHighlighter, MissingSegmentRecoveryTest, TriggerCooldownIntegrationTest, TestLeaderElectionZkExpiry, TestConfigSetsAPIZkFailure, LeaderElectionIntegrationTest, TestOrdValues, TestSimComputePlanAction, BadComponentTest, TestAddFieldRealTimeGet, ConfigureRecoveryStrategyTest, TestDistributedSearch, StatsComponentTest, JsonLoaderTest, TestFieldCacheWithThreads, TestDownShardTolerantSearch, CdcrBidirectionalTest, ConnectionReuseTest, TestDirectoryFactory, CoreAdminRequestStatusTest, Tagger2Test, CloneFieldUpdateProcessorFactoryTest, FieldMutatingUpdateProcessorTest, TestLRUCache, TestPseudoReturnFields, TestLuceneIndexBackCompat, TestSimGenericDistributedQueue, TestSystemIdResolver, TestLegacyTerms, UpdateParamsTest, TestIntervalFaceting, TestLogWatcher, CollectionsAPIAsyncDistributedZkTest, HdfsCollectionsAPIDistributedZkTest, CdcrVersionReplicationTest, TestFuzzyAnalyzedSuggestions, CreateRoutedAliasTest, ParsingFieldUpdateProcessorsTest, TermsComponentTest, DistributedDebugComponentTest, TestComponentsName, TestReload, TestSha256AuthenticationProvider, TestSQLHandler, TestObjectReleaseTracker, SignatureUpdateProcessorFactoryTest, TestZkChroot, TestIndexingPerformance, TestManagedSchemaThreadSafety, TestNRTOpen, TestTrackingShardHandlerFactory, SolrLogPostToolTest, AtomicUpdatesTest, RequiredFieldsTest, TestSchemalessBufferedUpdates, InfoHandlerTest, TestRangeQuery, TestGraphTermsQParserPlugin, TestDistribPackageStore, TestRandomDVFaceting, HighlighterConfigTest, UUIDUpdateProcessorFallbackTest, TestCollectionAPIs, CollectionsAPISolrJTest, TestStressLucene, FacetPivotSmallTest, ChaosMonkeyNothingIsSafeWithPullReplicasTest, ClusterStateMockUtilTest, ClusterStateTest, ConfigSetsAPITest, HttpPartitionTest, MultiSolrCloudTestCaseTest, NodeMutatorTest, OutOfBoxZkACLAndCredentialsProvidersTest, OverriddenZkACLAndCredentialsProvidersTest, RemoteQueryErrorTest, RestartWhileUpdatingTest, RollingRestartTest, SystemCollectionCompatTest, TestAuthenticationFramework, TestCloudInspectUtil, TestCloudPhrasesIdentificationComponent, TestConfigSetsAPI, TestRandomFlRTGCloud, TestRebalanceLeaders, TestUtilizeNode, TriLevelCompositeIdRoutingTest, UnloadDistributedZkTest, TestCollectionAPI, AutoScalingHandlerTest, ExecutePlanActionTest, NodeLostTriggerIntegrationTest, ScheduledTriggerIntegrationTest]
[junit4] Completed [608/908 (1!)] on J1 in 57.31s, 1 test, 1 failure <<< FAILURES!
[...truncated 48887 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-8.x-Windows/1137/consoleText
[repro] Revision: 62847cced885fd8b2402b9adc588247340d16f41
[repro] Ant options: "-Dargs=-XX:-UseCompressedOops -XX:+UseParallelGC"
[repro] JUnit rest result XML files will be moved to: ./repro-reports
[repro] ant clean
[...truncated 6 lines...]
[repro] Test suites by module:
[repro] solr\core
[repro] ScheduledTriggerIntegrationTest
[repro] ant compile-test
[...truncated 3484 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.ScheduledTriggerIntegrationTest" -Dtests.showOutput=onerror "-Dargs=-XX:-UseCompressedOops -XX:+UseParallelGC" -Dtests.seed=8A3880AAE4D9942 -Dtests.slow=true -Dtests.locale=en-MU -Dtests.timezone=US/Michigan -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[...truncated 82 lines...]
[repro] Failures w/original seeds:
[repro] 0/5 failed: org.apache.solr.cloud.autoscaling.ScheduledTriggerIntegrationTest
[repro] Exiting with code 0
[...truncated 78 lines...]