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/24 14:17:12 UTC
[JENKINS-Experimental-GC] Lucene-Solr-master-Windows
(64bit/jdk-15-ea+16) - Build # 8874 - Still Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Windows/8874/
Java: 64bit/jdk-15-ea+16 -XX:+UseCompressedOops -XX:+UnlockExperimentalVMOptions -XX:+UseZGC
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([4D5D13C3904581C7:DE465BB1CEB8DAF3]: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:1754)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:942)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:978)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:992)
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:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:819)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:470)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:951)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:887)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:898)
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:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.lambda$forkTimeoutingTask$0(ThreadLeakControl.java:826)
at java.base/java.lang.Thread.run(Thread.java:832)
Build Log:
[...truncated 14887 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.ScheduledTriggerIntegrationTest
[junit4] 2> 1666509 INFO (SUITE-ScheduledTriggerIntegrationTest-seed#[4D5D13C3904581C7]-worker) [ ] o.a.s.SolrTestCase Setting 'solr.default.confdir' system property to test-framework derived value of 'C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\server\solr\configsets\_default\conf'
[junit4] 2> 1666509 INFO (SUITE-ScheduledTriggerIntegrationTest-seed#[4D5D13C3904581C7]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 1666509 INFO (SUITE-ScheduledTriggerIntegrationTest-seed#[4D5D13C3904581C7]-worker) [ ] o.a.s.SolrTestCaseJ4 Created dataDir: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J4\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_4D5D13C3904581C7-001\data-dir-114-001
[junit4] 2> 1666509 INFO (SUITE-ScheduledTriggerIntegrationTest-seed#[4D5D13C3904581C7]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 1666509 INFO (SUITE-ScheduledTriggerIntegrationTest-seed#[4D5D13C3904581C7]-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> 1666509 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testScheduledTrigger
[junit4] 2> 1666513 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J4\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_4D5D13C3904581C7-001\tempDir-001
[junit4] 2> 1666514 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 1666514 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port: 0.0.0.0/0.0.0.0:0
[junit4] 2> 1666514 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 1666614 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.c.ZkTestServer start zk server on port: 51811
[junit4] 2> 1666614 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.c.ZkTestServer waitForServerUp: 127.0.0.1:51811
[junit4] 2> 1666614 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:51811
[junit4] 2> 1666614 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 51811
[junit4] 2> 1666616 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1666619 INFO (zkConnectionManagerCallback-16846-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1666619 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1666621 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1666622 INFO (zkConnectionManagerCallback-16848-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1666622 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1666623 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1666625 INFO (zkConnectionManagerCallback-16850-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1666625 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1666728 INFO (jetty-launcher-16851-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 1666728 INFO (jetty-launcher-16851-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
[junit4] 2> 1666728 INFO (jetty-launcher-16851-thread-2) [ ] o.e.j.s.Server jetty-9.4.27.v20200227; built: 2020-02-27T18:37:21.340Z; git: a304fd9f351f337e7c0e2a7c28878dd536149c6c; jvm 15-ea+16-681
[junit4] 2> 1666728 INFO (jetty-launcher-16851-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 1666728 INFO (jetty-launcher-16851-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
[junit4] 2> 1666728 INFO (jetty-launcher-16851-thread-1) [ ] o.e.j.s.Server jetty-9.4.27.v20200227; built: 2020-02-27T18:37:21.340Z; git: a304fd9f351f337e7c0e2a7c28878dd536149c6c; jvm 15-ea+16-681
[junit4] 2> 1666728 INFO (jetty-launcher-16851-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1666728 INFO (jetty-launcher-16851-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1666728 INFO (jetty-launcher-16851-thread-2) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 1666728 INFO (jetty-launcher-16851-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1666728 INFO (jetty-launcher-16851-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1666728 INFO (jetty-launcher-16851-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@370cd97d{/solr,null,AVAILABLE}
[junit4] 2> 1666728 INFO (jetty-launcher-16851-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 1666728 INFO (jetty-launcher-16851-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@2f54ff5e{/solr,null,AVAILABLE}
[junit4] 2> 1666730 INFO (jetty-launcher-16851-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@54152ddf{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:?????}
[junit4] 2> 1666730 INFO (jetty-launcher-16851-thread-2) [ ] o.e.j.s.Server Started @???????ms
[junit4] 2> 1666730 INFO (jetty-launcher-16851-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=51824}
[junit4] 2> 1666730 INFO (jetty-launcher-16851-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@79877082{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:?????}
[junit4] 2> 1666730 INFO (jetty-launcher-16851-thread-1) [ ] o.e.j.s.Server Started @???????ms
[junit4] 2> 1666730 INFO (jetty-launcher-16851-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=51825}
[junit4] 2> 1666730 ERROR (jetty-launcher-16851-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1666730 INFO (jetty-launcher-16851-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 1666730 INFO (jetty-launcher-16851-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 9.0.0
[junit4] 2> 1666731 INFO (jetty-launcher-16851-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1666731 INFO (jetty-launcher-16851-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr
[junit4] 2> 1666731 INFO (jetty-launcher-16851-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-05-24T13:52:49.076335400Z
[junit4] 2> 1666731 ERROR (jetty-launcher-16851-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1666731 INFO (jetty-launcher-16851-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 1666731 INFO (jetty-launcher-16851-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 9.0.0
[junit4] 2> 1666731 INFO (jetty-launcher-16851-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1666731 INFO (jetty-launcher-16851-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr
[junit4] 2> 1666731 INFO (jetty-launcher-16851-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-05-24T13:52:49.076335400Z
[junit4] 2> 1666731 INFO (jetty-launcher-16851-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1666731 INFO (jetty-launcher-16851-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1666733 INFO (zkConnectionManagerCallback-16855-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1666733 INFO (jetty-launcher-16851-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1666733 INFO (zkConnectionManagerCallback-16853-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1666733 INFO (jetty-launcher-16851-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1666733 INFO (jetty-launcher-16851-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1666733 INFO (jetty-launcher-16851-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1666839 INFO (jetty-launcher-16851-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 1666841 WARN (jetty-launcher-16851-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@834beec[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1666841 WARN (jetty-launcher-16851-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@834beec[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1666843 WARN (jetty-launcher-16851-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@c80aeca[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1666843 WARN (jetty-launcher-16851-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@c80aeca[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1666844 INFO (jetty-launcher-16851-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:51811/solr
[junit4] 2> 1666845 INFO (jetty-launcher-16851-thread-1) [n:127.0.0.1:51825_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1666847 INFO (zkConnectionManagerCallback-16866-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1666847 INFO (jetty-launcher-16851-thread-1) [n:127.0.0.1:51825_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1666914 INFO (jetty-launcher-16851-thread-1) [n:127.0.0.1:51825_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:51825_solr
[junit4] 2> 1666914 INFO (jetty-launcher-16851-thread-1) [n:127.0.0.1:51825_solr ] o.a.s.c.Overseer Overseer (id=72097129901654021-127.0.0.1:51825_solr-n_0000000000) starting
[junit4] 2> 1666919 INFO (OverseerStateUpdate-72097129901654021-127.0.0.1:51825_solr-n_0000000000) [n:127.0.0.1:51825_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:51825_solr
[junit4] 2> 1666919 INFO (jetty-launcher-16851-thread-1) [n:127.0.0.1:51825_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51825_solr
[junit4] 2> 1666919 DEBUG (OverseerAutoScalingTriggerThread-72097129901654021-127.0.0.1:51825_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 1666920 INFO (OverseerStateUpdate-72097129901654021-127.0.0.1:51825_solr-n_0000000000) [n:127.0.0.1:51825_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1666920 DEBUG (OverseerAutoScalingTriggerThread-72097129901654021-127.0.0.1:51825_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 1666921 DEBUG (OverseerAutoScalingTriggerThread-72097129901654021-127.0.0.1:51825_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 0
[junit4] 2> 1666921 DEBUG (OverseerAutoScalingTriggerThread-72097129901654021-127.0.0.1:51825_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 1666921 INFO (jetty-launcher-16851-thread-1) [n:127.0.0.1:51825_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 1666921 WARN (jetty-launcher-16851-thread-1) [n:127.0.0.1:51825_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> 1666921 DEBUG (OverseerAutoScalingTriggerThread-72097129901654021-127.0.0.1:51825_solr-n_0000000000) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:51825_solr]
[junit4] 2> 1666924 DEBUG (OverseerAutoScalingTriggerThread-72097129901654021-127.0.0.1:51825_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 1666924 DEBUG (OverseerAutoScalingTriggerThread-72097129901654021-127.0.0.1:51825_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 1666924 DEBUG (ScheduledTrigger-16871-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> 1666938 INFO (jetty-launcher-16851-thread-2) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 1666939 WARN (jetty-launcher-16851-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@10e3c505[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1666939 WARN (jetty-launcher-16851-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@10e3c505[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1666940 INFO (jetty-launcher-16851-thread-1) [n:127.0.0.1:51825_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 1666941 WARN (jetty-launcher-16851-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@6a85226d[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1666941 WARN (jetty-launcher-16851-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@6a85226d[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1666941 INFO (jetty-launcher-16851-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:51811/solr
[junit4] 2> 1666943 INFO (jetty-launcher-16851-thread-2) [n:127.0.0.1:51824_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1666945 INFO (zkConnectionManagerCallback-16888-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1666945 INFO (jetty-launcher-16851-thread-2) [n:127.0.0.1:51824_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1666949 INFO (jetty-launcher-16851-thread-2) [n:127.0.0.1:51824_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1666952 INFO (jetty-launcher-16851-thread-2) [n:127.0.0.1:51824_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:51824_solr as DOWN
[junit4] 2> 1666952 INFO (jetty-launcher-16851-thread-2) [n:127.0.0.1:51824_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 1000 transient cores
[junit4] 2> 1666952 INFO (jetty-launcher-16851-thread-2) [n:127.0.0.1:51824_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51824_solr
[junit4] 2> 1666953 INFO (zkCallback-16865-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1666954 INFO (zkCallback-16887-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1666954 INFO (jetty-launcher-16851-thread-2) [n:127.0.0.1:51824_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 1666954 WARN (jetty-launcher-16851-thread-2) [n:127.0.0.1:51824_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> 1666962 INFO (jetty-launcher-16851-thread-1) [n:127.0.0.1:51825_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_51825.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7b6b46a9
[junit4] 2> 1666966 INFO (jetty-launcher-16851-thread-1) [n:127.0.0.1:51825_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_51825.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7b6b46a9
[junit4] 2> 1666966 INFO (jetty-launcher-16851-thread-1) [n:127.0.0.1:51825_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_51825.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7b6b46a9
[junit4] 2> 1666966 INFO (jetty-launcher-16851-thread-1) [n:127.0.0.1:51825_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J4\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_4D5D13C3904581C7-001\tempDir-001\node2\.
[junit4] 2> 1666972 INFO (jetty-launcher-16851-thread-2) [n:127.0.0.1:51824_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 1666988 INFO (jetty-launcher-16851-thread-2) [n:127.0.0.1:51824_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_51824.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7b6b46a9
[junit4] 2> 1666992 INFO (jetty-launcher-16851-thread-2) [n:127.0.0.1:51824_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_51824.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7b6b46a9
[junit4] 2> 1666992 INFO (jetty-launcher-16851-thread-2) [n:127.0.0.1:51824_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_51824.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7b6b46a9
[junit4] 2> 1666994 INFO (jetty-launcher-16851-thread-2) [n:127.0.0.1:51824_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J4\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_4D5D13C3904581C7-001\tempDir-001\node1\.
[junit4] 2> 1667005 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.c.MiniSolrCloudCluster waitForAllNodes: numServers=2
[junit4] 2> 1667006 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1667008 INFO (zkConnectionManagerCallback-16902-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1667008 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1667009 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1667011 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:51811/solr ready
[junit4] 2> 1667018 INFO (qtp2000719898-27752) [n:127.0.0.1:51825_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling params={wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 1667023 INFO (qtp1523763445-27745) [n:127.0.0.1:51824_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=2
[junit4] 2> 1667023 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 1000 transient cores
[junit4] 2> 1667026 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=2
[junit4] 2> 1667026 DEBUG (qtp1523763445-27740) [n:127.0.0.1:51824_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1667027 INFO (qtp1523763445-27740) [n:127.0.0.1:51824_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling params={wt=javabin&version=2} status=0 QTime=8
[junit4] 2> 1667028 DEBUG (zkCallback-16865-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 1667029 DEBUG (OverseerAutoScalingTriggerThread-72097129901654021-127.0.0.1:51825_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 1667029 INFO (qtp2000719898-27752) [n:127.0.0.1:51825_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> 1667032 DEBUG (OverseerAutoScalingTriggerThread-72097129901654021-127.0.0.1:51825_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 1667033 DEBUG (OverseerAutoScalingTriggerThread-72097129901654021-127.0.0.1:51825_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 1667033 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection testScheduledTrigger
[junit4] 2> 1667034 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/managed-schema to /configs/testScheduledTrigger.AUTOCREATED/managed-schema
[junit4] 2> 1667035 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/protwords.txt to /configs/testScheduledTrigger.AUTOCREATED/protwords.txt
[junit4] 2> 1667037 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667038 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667040 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667041 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667042 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667044 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667045 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667046 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667047 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667049 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667050 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667051 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667052 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667054 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667055 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667056 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667058 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667059 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667060 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667061 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667063 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667064 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667065 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667066 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667067 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667068 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667070 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667071 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667072 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667074 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667075 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667076 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667077 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667079 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667080 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667081 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667083 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667084 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667085 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667087 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/solrconfig.xml to /configs/testScheduledTrigger.AUTOCREATED/solrconfig.xml
[junit4] 2> 1667088 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/synonyms.txt to /configs/testScheduledTrigger.AUTOCREATED/synonyms.txt
[junit4] 2> 1667089 INFO (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/stopwords.txt to /configs/testScheduledTrigger.AUTOCREATED/stopwords.txt
[junit4] 2> 1667192 WARN (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_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> 1667193 DEBUG (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_solr ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 1667193 INFO (qtp2000719898-27753) [n:127.0.0.1:51825_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=2
[junit4] 2> 1667197 INFO (qtp1523763445-27742) [n:127.0.0.1:51824_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=2
[junit4] 2> 1667199 DEBUG (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_solr ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 1667201 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=1
[junit4] 2> 1667203 INFO (qtp1523763445-27744) [n:127.0.0.1:51824_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=1
[junit4] 2> 1667204 DEBUG (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_solr ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 603270101 sessionWrapper.createTime 603270095830300, this.sessionWrapper.createTime 603270095830300
[junit4] 2> 1667207 INFO (OverseerStateUpdate-72097129901654021-127.0.0.1:51825_solr-n_0000000000) [n:127.0.0.1:51825_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:51824/solr",
[junit4] 2> "node_name":"127.0.0.1:51824_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 1667208 INFO (OverseerStateUpdate-72097129901654021-127.0.0.1:51825_solr-n_0000000000) [n:127.0.0.1:51825_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:51825/solr",
[junit4] 2> "node_name":"127.0.0.1:51825_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 1667210 INFO (OverseerStateUpdate-72097129901654021-127.0.0.1:51825_solr-n_0000000000) [n:127.0.0.1:51825_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:51825/solr",
[junit4] 2> "node_name":"127.0.0.1:51825_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 1667411 INFO (qtp2000719898-27751) [n:127.0.0.1:51825_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> 1667411 INFO (qtp1523763445-27745) [n:127.0.0.1:51824_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> 1667411 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_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> 1667422 INFO (qtp1523763445-27745) [n:127.0.0.1:51824_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 1667422 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 1667422 INFO (qtp2000719898-27751) [n:127.0.0.1:51825_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 1667445 INFO (qtp2000719898-27751) [n:127.0.0.1:51825_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.s.IndexSchema Schema name=default-config
[junit4] 2> 1667445 INFO (qtp1523763445-27745) [n:127.0.0.1:51824_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.s.IndexSchema Schema name=default-config
[junit4] 2> 1667446 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.s.IndexSchema Schema name=default-config
[junit4] 2> 1667879 INFO (qtp1523763445-27745) [n:127.0.0.1:51824_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> 1667879 INFO (qtp1523763445-27745) [n:127.0.0.1:51824_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> 1667880 INFO (qtp1523763445-27745) [n:127.0.0.1:51824_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_51824.solr.core.testScheduledTrigger.shard1.replica_n1' (registry 'solr.core.testScheduledTrigger.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7b6b46a9
[junit4] 2> 1667880 INFO (qtp1523763445-27745) [n:127.0.0.1:51824_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-master-Windows\solr\build\solr-core\test\J4\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_4D5D13C3904581C7-001\tempDir-001\node1\.\testScheduledTrigger_shard1_replica_n1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J4\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_4D5D13C3904581C7-001\tempDir-001\node1\.\testScheduledTrigger_shard1_replica_n1\data\]
[junit4] 2> 1667885 INFO (qtp2000719898-27751) [n:127.0.0.1:51825_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> 1667885 INFO (qtp2000719898-27751) [n:127.0.0.1:51825_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> 1667885 INFO (qtp2000719898-27751) [n:127.0.0.1:51825_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_51825.solr.core.testScheduledTrigger.shard1.replica_n2' (registry 'solr.core.testScheduledTrigger.shard1.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7b6b46a9
[junit4] 2> 1667885 INFO (qtp2000719898-27751) [n:127.0.0.1:51825_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-master-Windows\solr\build\solr-core\test\J4\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_4D5D13C3904581C7-001\tempDir-001\node2\.\testScheduledTrigger_shard1_replica_n2], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J4\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_4D5D13C3904581C7-001\tempDir-001\node2\.\testScheduledTrigger_shard1_replica_n2\data\]
[junit4] 2> 1667887 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_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> 1667887 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_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> 1667887 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_51825.solr.core.testScheduledTrigger.shard1.replica_n4' (registry 'solr.core.testScheduledTrigger.shard1.replica_n4') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7b6b46a9
[junit4] 2> 1667887 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_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-master-Windows\solr\build\solr-core\test\J4\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_4D5D13C3904581C7-001\tempDir-001\node2\.\testScheduledTrigger_shard1_replica_n4], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J4\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_4D5D13C3904581C7-001\tempDir-001\node2\.\testScheduledTrigger_shard1_replica_n4\data\]
[junit4] 2> 1667909 DEBUG (ScheduledTrigger-16871-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> 1667958 INFO (qtp2000719898-27751) [n:127.0.0.1:51825_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> 1667958 INFO (qtp2000719898-27751) [n:127.0.0.1:51825_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> 1667958 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_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> 1667958 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_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> 1667962 INFO (qtp2000719898-27751) [n:127.0.0.1:51825_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> 1667962 INFO (qtp2000719898-27751) [n:127.0.0.1:51825_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1667962 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_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> 1667962 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1667962 INFO (qtp1523763445-27745) [n:127.0.0.1:51824_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> 1667962 INFO (qtp1523763445-27745) [n:127.0.0.1:51824_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> 1667967 INFO (qtp2000719898-27751) [n:127.0.0.1:51825_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> 1667967 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_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> 1667967 INFO (qtp2000719898-27751) [n:127.0.0.1:51825_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> 1667967 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_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> 1667967 INFO (qtp2000719898-27751) [n:127.0.0.1:51825_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> 1667967 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_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> 1667967 INFO (qtp1523763445-27745) [n:127.0.0.1:51824_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> 1667967 INFO (qtp1523763445-27745) [n:127.0.0.1:51824_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1667967 INFO (qtp2000719898-27751) [n:127.0.0.1:51825_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> 1667967 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_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> 1667967 INFO (qtp2000719898-27751) [n:127.0.0.1:51825_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
[junit4] 2> 1667967 INFO (qtp2000719898-27751) [n:127.0.0.1:51825_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> 1667967 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
[junit4] 2> 1667967 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_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> 1667969 INFO (qtp2000719898-27751) [n:127.0.0.1:51825_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> 1667969 INFO (qtp2000719898-27751) [n:127.0.0.1:51825_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 1667580161230372864
[junit4] 2> 1667969 INFO (qtp1523763445-27745) [n:127.0.0.1:51824_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> 1667969 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_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> 1667969 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_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 1667580161230372864
[junit4] 2> 1667969 INFO (qtp1523763445-27745) [n:127.0.0.1:51824_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> 1667969 INFO (qtp1523763445-27745) [n:127.0.0.1:51824_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> 1667969 INFO (qtp1523763445-27745) [n:127.0.0.1:51824_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> 1667969 INFO (qtp1523763445-27745) [n:127.0.0.1:51824_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
[junit4] 2> 1667969 INFO (qtp1523763445-27745) [n:127.0.0.1:51824_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> 1667969 INFO (searcherExecutor-16906-thread-1-processing-n:127.0.0.1:51825_solr x:testScheduledTrigger_shard1_replica_n2 c:testScheduledTrigger s:shard1 r:core_node5) [n:127.0.0.1:51825_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.c.QuerySenderListener QuerySenderListener done.
[junit4] 2> 1667969 INFO (searcherExecutor-16906-thread-1-processing-n:127.0.0.1:51825_solr x:testScheduledTrigger_shard1_replica_n2 c:testScheduledTrigger s:shard1 r:core_node5) [n:127.0.0.1:51825_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> 1667969 INFO (searcherExecutor-16908-thread-1-processing-n:127.0.0.1:51825_solr x:testScheduledTrigger_shard1_replica_n4 c:testScheduledTrigger s:shard1 r:core_node6) [n:127.0.0.1:51825_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.c.QuerySenderListener QuerySenderListener done.
[junit4] 2> 1667969 INFO (searcherExecutor-16908-thread-1-processing-n:127.0.0.1:51825_solr x:testScheduledTrigger_shard1_replica_n4 c:testScheduledTrigger s:shard1 r:core_node6) [n:127.0.0.1:51825_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> 1667969 INFO (qtp1523763445-27745) [n:127.0.0.1:51824_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> 1667969 INFO (qtp1523763445-27745) [n:127.0.0.1:51824_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 1667580161230372864
[junit4] 2> 1667972 INFO (searcherExecutor-16906-thread-1-processing-n:127.0.0.1:51825_solr x:testScheduledTrigger_shard1_replica_n2 c:testScheduledTrigger s:shard1 r:core_node5) [n:127.0.0.1:51825_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> 1667972 INFO (searcherExecutor-16908-thread-1-processing-n:127.0.0.1:51825_solr x:testScheduledTrigger_shard1_replica_n4 c:testScheduledTrigger s:shard1 r:core_node6) [n:127.0.0.1:51825_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> 1667972 INFO (searcherExecutor-16904-thread-1-processing-n:127.0.0.1:51824_solr x:testScheduledTrigger_shard1_replica_n1 c:testScheduledTrigger s:shard1 r:core_node3) [n:127.0.0.1:51824_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.c.QuerySenderListener QuerySenderListener done.
[junit4] 2> 1667972 INFO (searcherExecutor-16904-thread-1-processing-n:127.0.0.1:51824_solr x:testScheduledTrigger_shard1_replica_n1 c:testScheduledTrigger s:shard1 r:core_node3) [n:127.0.0.1:51824_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> 1667973 INFO (searcherExecutor-16904-thread-1-processing-n:127.0.0.1:51824_solr x:testScheduledTrigger_shard1_replica_n1 c:testScheduledTrigger s:shard1 r:core_node3) [n:127.0.0.1:51824_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> 1667973 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_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> 1667973 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_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> 1667973 INFO (qtp2000719898-27751) [n:127.0.0.1:51825_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> 1667973 INFO (qtp2000719898-27751) [n:127.0.0.1:51825_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> 1667973 INFO (qtp1523763445-27745) [n:127.0.0.1:51824_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> 1667973 INFO (qtp1523763445-27745) [n:127.0.0.1:51824_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> 1667977 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_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> 1667977 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_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> 1667977 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_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:51825/solr/testScheduledTrigger_shard1_replica_n4/
[junit4] 2> 1667977 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_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:51825/solr START replicas=[http://127.0.0.1:51824/solr/testScheduledTrigger_shard1_replica_n1/, http://127.0.0.1:51825/solr/testScheduledTrigger_shard1_replica_n2/] nUpdates=100
[junit4] 2> 1667981 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_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:51825/solr DONE. We have no versions. sync failed.
[junit4] 2> 1667982 INFO (qtp1523763445-27742) [n:127.0.0.1:51824_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> 1667982 INFO (qtp2000719898-27753) [n:127.0.0.1:51825_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> 1667982 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_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> 1667982 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_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> 1667982 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_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/72097129901654021-core_node6-n_0000000000
[junit4] 2> 1667985 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_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:51825/solr/testScheduledTrigger_shard1_replica_n4/ shard1
[junit4] 2> 1668085 INFO (zkCallback-16865-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> 1668085 INFO (zkCallback-16865-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> 1668087 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_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> 1668089 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_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=690
[junit4] 2> 1668187 INFO (zkCallback-16865-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> 1668187 INFO (zkCallback-16865-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> 1668187 INFO (zkCallback-16865-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> 1668897 DEBUG (ScheduledTrigger-16871-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> 1669004 INFO (qtp1523763445-27745) [n:127.0.0.1:51824_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=1619
[junit4] 2> 1669004 INFO (qtp2000719898-27751) [n:127.0.0.1:51825_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=1619
[junit4] 2> 1669004 DEBUG (OverseerThreadFactory-16873-thread-1-processing-n:127.0.0.1:51825_solr) [n:127.0.0.1:51825_solr ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 1669006 INFO (qtp2000719898-27752) [n:127.0.0.1:51825_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> 1669069 INFO (zkCallback-16865-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> 1669069 INFO (zkCallback-16887-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> 1669069 INFO (zkCallback-16865-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> 1669069 INFO (zkCallback-16865-thread-4) [ ] 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> 1669069 INFO (zkCallback-16887-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> 1669070 INFO (qtp2000719898-27752) [n:127.0.0.1:51825_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=2073
[junit4] 2> 1669070 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.c.MiniSolrCloudCluster waitForActiveCollection: testScheduledTrigger
[junit4] 2> 1669073 INFO (qtp2000719898-27754) [n:127.0.0.1:51825_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> 1669075 INFO (qtp2000719898-27751) [n:127.0.0.1:51825_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=1
[junit4] 2> 1669076 INFO (qtp1523763445-27744) [n:127.0.0.1:51824_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> 1669077 INFO (qtp1523763445-27740) [n:127.0.0.1:51824_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=1
[junit4] 2> 1669077 DEBUG (qtp2000719898-27753) [n:127.0.0.1:51825_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1669078 INFO (qtp2000719898-27753) [n:127.0.0.1:51825_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling params={wt=javabin&version=2} status=0 QTime=6
[junit4] 2> 1669078 DEBUG (zkCallback-16865-thread-4) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 1669079 DEBUG (OverseerAutoScalingTriggerThread-72097129901654021-127.0.0.1:51825_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 1669080 DEBUG (OverseerAutoScalingTriggerThread-72097129901654021-127.0.0.1:51825_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 1669080 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 1669080 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
[junit4] 2> 1669080 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.e.j.s.Server jetty-9.4.27.v20200227; built: 2020-02-27T18:37:21.340Z; git: a304fd9f351f337e7c0e2a7c28878dd536149c6c; jvm 15-ea+16-681
[junit4] 2> 1669080 DEBUG (OverseerAutoScalingTriggerThread-72097129901654021-127.0.0.1:51825_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 1669081 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1669081 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1669081 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 1669081 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@5c2c02f6{/solr,null,AVAILABLE}
[junit4] 2> 1669082 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@731f8a3{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:?????}
[junit4] 2> 1669082 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.e.j.s.Server Started @???????ms
[junit4] 2> 1669082 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=51889}
[junit4] 2> 1669082 ERROR (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1669082 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 1669082 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 9.0.0
[junit4] 2> 1669083 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1669083 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr
[junit4] 2> 1669083 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-05-24T13:52:51.428466900Z
[junit4] 2> 1669084 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1669086 INFO (zkConnectionManagerCallback-16922-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1669086 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1669086 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1669193 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 1669195 WARN (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@755fa28f[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1669195 WARN (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@755fa28f[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1669199 WARN (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@537a3a23[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1669199 WARN (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@537a3a23[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1669200 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:51811/solr
[junit4] 2> 1669202 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [n:127.0.0.1:51889_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1669205 INFO (zkConnectionManagerCallback-16933-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1669205 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [n:127.0.0.1:51889_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1669209 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [n:127.0.0.1:51889_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1669213 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [n:127.0.0.1:51889_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:51889_solr as DOWN
[junit4] 2> 1669213 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [n:127.0.0.1:51889_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 1000 transient cores
[junit4] 2> 1669213 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [n:127.0.0.1:51889_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51889_solr
[junit4] 2> 1669213 INFO (zkCallback-16901-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1669213 INFO (zkCallback-16865-thread-4) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1669213 INFO (zkCallback-16887-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1669213 INFO (zkCallback-16932-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1669216 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [n:127.0.0.1:51889_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 1669216 WARN (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [n:127.0.0.1:51889_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> 1669236 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [n:127.0.0.1:51889_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 1669255 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [n:127.0.0.1:51889_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_51889.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7b6b46a9
[junit4] 2> 1669261 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [n:127.0.0.1:51889_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_51889.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7b6b46a9
[junit4] 2> 1669261 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [n:127.0.0.1:51889_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_51889.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7b6b46a9
[junit4] 2> 1669262 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [n:127.0.0.1:51889_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J4\temp\solr.cloud.autoscaling.Sche
[...truncated too long message...]
ThreadPool-16959-thread-2) [ ] o.a.s.c.Overseer Overseer (id=72097129901654021-127.0.0.1:51825_solr-n_0000000000) closing
[junit4] 2> 1706227 INFO (jetty-closer-16942-thread-3) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@731f8a3{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:?}
[junit4] 2> 1706227 INFO (jetty-closer-16942-thread-3) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@5c2c02f6{/solr,null,UNAVAILABLE}
[junit4] 2> 1706227 INFO (jetty-closer-16942-thread-3) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 1706313 INFO (jetty-closer-16942-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72097129901654021-127.0.0.1:51825_solr-n_0000000000) closing
[junit4] 2> 1706314 INFO (jetty-closer-16942-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@79877082{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:?}
[junit4] 2> 1706314 INFO (jetty-closer-16942-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@2f54ff5e{/solr,null,UNAVAILABLE}
[junit4] 2> 1706314 INFO (jetty-closer-16942-thread-1) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 1706401 INFO (jetty-closer-16942-thread-2) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@54152ddf{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:?}
[junit4] 2> 1706401 INFO (jetty-closer-16942-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@370cd97d{/solr,null,UNAVAILABLE}
[junit4] 2> 1706401 INFO (jetty-closer-16942-thread-2) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 1706402 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.c.ZkTestServer Shutting down ZkTestServer.
[junit4] 2> 1706580 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> 24 /solr/collections/testScheduledTrigger/state.json
[junit4] 2> 4 /solr/clusterstate.json
[junit4] 2> 4 /solr/autoscaling.json
[junit4] 2> 2 /solr/collections/testScheduledTrigger/leader_elect/shard1/election/72097129901654021-core_node6-n_0000000000
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 23 /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> 1706583 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.c.ZkTestServer waitForServerDown: 127.0.0.1:51811
[junit4] 2> 1706583 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:51811
[junit4] 2> 1706583 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 51811
[junit4] 2> 1708323 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[4D5D13C3904581C7]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testScheduledTrigger
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ScheduledTriggerIntegrationTest -Dtests.method=testScheduledTrigger -Dtests.seed=4D5D13C3904581C7 -Dtests.slow=true -Dtests.locale=bn-IN -Dtests.timezone=Asia/Hong_Kong -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[junit4] FAILURE 41.8s J4 | ScheduledTriggerIntegrationTest.testScheduledTrigger <<<
[junit4] > Throwable #1: java.lang.AssertionError: ScheduledTrigger did not fire in time
[junit4] > at __randomizedtesting.SeedInfo.seed([4D5D13C3904581C7:DE465BB1CEB8DAF3]: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-master-Windows\solr\build\solr-core\test\J4\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_4D5D13C3904581C7-001
[junit4] 2> NOTE: test params are: codec=HighCompressionCompressingStoredFieldsData(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=HIGH_COMPRESSION, chunkSize=9, maxDocsPerChunk=865, blockShift=8), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=HIGH_COMPRESSION, chunkSize=9, blockSize=8)), sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@5a70c931), locale=bn-IN, timezone=Asia/Hong_Kong
[junit4] 2> NOTE: Windows 10 10.0 amd64/Oracle Corporation 15-ea (64-bit)/cpus=6,threads=1,free=387973120,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [ConcurrentCreateCollectionTest, LeaderFailureAfterFreshStartTest, ProtectedTermFilterFactoryTest, TestFieldSortValues, IndexBasedSpellCheckerTest, StatsReloadRaceTest, ManagedSchemaRoundRobinCloudTest, TestNumericRangeQuery32, ResponseHeaderTest, TestCoreAdminApis, SubstringBytesRefFilterTest, ForceLeaderTest, TestPayloadCheckQParserPlugin, TestDynamicLoadingUrl, CoreAdminCreateDiscoverTest, ExplicitHLLTest, AsyncCallRequestStatusResponseTest, V2StandaloneTest, TestSolrConfigHandlerCloud, SolrShardReporterTest, AuditLoggerIntegrationTest, TestStreamBody, DistributedFacetExistsSmallTest, DeleteNodeTest, TestSolrCLIRunExample, DocExpirationUpdateProcessorFactoryTest, HttpPartitionWithTlogReplicasTest, ConnectionManagerTest, TestDFRSimilarityFactory, SortByFunctionTest, TestUtilizeNode, MetricsHistoryWithAuthIntegrationTest, AuthToolTest, TestFastOutputStream, TestMinHashQParser, TestSolrDeletionPolicy1, HDFSCollectionsAPITest, TestExactSharedStatsCacheCloud, TestLegacyField, TestRSAKeyPair, HdfsNNFailoverTest, TestEmbeddedSolrServerSchemaAPI, SearchHandlerTest, TestExceedMaxTermLength, DaemonStreamApiTest, DistanceFunctionTest, PingRequestHandlerTest, OverseerSolrResponseTest, SchemaApiFailureTest, CdcrOpsAndBoundariesTest, PreAnalyzedFieldManagedSchemaCloudTest, CertAuthPluginTest, DocValuesTest, AnalyticsMergeStrategyTest, TestGeoJSONResponseWriter, NodeAddedTriggerIntegrationTest, TestOmitPositions, TestSolrCachePerf, IndexSizeTriggerMixedBoundsTest, SuggesterWFSTTest, TestDocBasedVersionConstraints, MultiDestinationAuditLoggerTest, SpatialHeatmapFacetsTest, BadCopyFieldTest, DistributedFacetPivotWhiteBoxTest, SolrGraphiteReporterTest, ZkFailoverTest, CollectionPropsTest, SearchRateTriggerTest, TestLeaderElectionWithEmptyReplica, TestValueSourceCache, DirectUpdateHandlerTest, TestWordDelimiterFilterFactory, TestDynamicFieldCollectionResource, MetricsConfigTest, TestRawResponseWriter, TestNonDefinedSimilarityFactory, SuggestComponentTest, TestQuerySenderNoQuery, TestZkAclsWithHadoopAuth, TestHighlightDedupGrouping, ReturnFieldsTest, DirectoryFactoryTest, TestUninvertingReader, TestDeleteCollectionOnDownNodes, TestSort, RAMDirectoryFactoryTest, SolrCoreTest, CleanupOldIndexTest, TestSimpleTrackingShardHandler, BasicDistributedZk2Test, CollectionsAPISolrJTest, ReindexCollectionTest, TestCloudInspectUtil, TestCloudPhrasesIdentificationComponent, TestCloudRecovery, TestClusterProperties, TestConfigSetsAPIExclusivity, TestConfigSetsAPIZkFailure, TestDistribDocBasedVersion, TestHashPartitioner, TestRandomRequestDistribution, TestSkipOverseerOperations, TestTolerantUpdateProcessorCloud, ConcurrentDeleteAndCreateCollectionTest, CustomCollectionTest, SimpleCollectionCreateDeleteTest, SplitByPrefixTest, TestReplicaProperties, AutoScalingHandlerTest, MetricTriggerIntegrationTest, ScheduledMaintenanceTriggerTest, ScheduledTriggerIntegrationTest]
[junit4] Completed [587/913 (1!)] on J4 in 41.83s, 1 test, 1 failure <<< FAILURES!
[...truncated 46027 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Windows/8874/consoleText
[repro] Revision: 675956c0041b18d48a7c059ea458c49f5310d74a
[repro] Ant options: "-Dargs=-XX:+UseCompressedOops -XX:+UnlockExperimentalVMOptions -XX:+UseZGC"
[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 3158 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.ScheduledTriggerIntegrationTest" -Dtests.showOutput=onerror "-Dargs=-XX:+UseCompressedOops -XX:+UnlockExperimentalVMOptions -XX:+UseZGC" -Dtests.seed=4D5D13C3904581C7 -Dtests.slow=true -Dtests.locale=bn-IN -Dtests.timezone=Asia/Hong_Kong -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...]
[JENKINS-Experimental-GC] Lucene-Solr-master-Windows (64bit/jdk-14)
- Build # 8876 - Failure!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Windows/8876/
Java: 64bit/jdk-14 -XX:+UseCompressedOops -XX:+UnlockExperimentalVMOptions -XX:+UseShenandoahGC
All tests passed
Build Log:
[...truncated 522 lines...]
[junit4] JVM J3: stdout was not empty, see: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\lucene\build\core\test\temp\junit4-J3-20200524_231032_1787638324882651934113.sysout
[junit4] >>> JVM J3 emitted unexpected output (verbatim) ----
[junit4] #
[junit4] # A fatal error has been detected by the Java Runtime Environment:
[junit4] #
[junit4] # EXCEPTION_ACCESS_VIOLATION (0xc0000005) at pc=0x00000098ec8148a1, pid=8232, tid=13512
[junit4] #
[junit4] # JRE version: OpenJDK Runtime Environment AdoptOpenJDK (14.0+36) (build 14+36)
[junit4] # Java VM: OpenJDK 64-Bit Server VM AdoptOpenJDK (14+36, mixed mode, sharing, tiered, compressed oops, shenandoah gc, windows-amd64)
[junit4] # Problematic frame:
[junit4] # C 0x00000098ec8148a1
[junit4] #
[junit4] # No core dump will be written. Minidumps are not enabled by default on client versions of Windows
[junit4] #
[junit4] # An error report file with more information is saved as:
[junit4] # C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\lucene\build\core\test\J3\hs_err_pid8232.log
[junit4] #
[junit4] # Compiler replay data is saved as:
[junit4] # C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\lucene\build\core\test\J3\replay_pid8232.log
[junit4] #
[junit4] # If you would like to submit a bug report, please visit:
[junit4] # https://github.com/AdoptOpenJDK/openjdk-support/issues
[junit4] #
[junit4] <<< JVM J3: EOF ----
[...truncated 1677 lines...]
[junit4] ERROR: JVM J3 ended with an exception, command line: C:\Users\jenkins\tools\java\64bit\jdk-14\bin\java.exe -XX:+UseCompressedOops -XX:+UnlockExperimentalVMOptions -XX:+UseShenandoahGC -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\heapdumps -ea -esa --illegal-access=deny -Dtests.prefix=tests -Dtests.seed=2810618764C96855 -Xmx512M -Dtests.iters= -Dtests.verbose=false -Dtests.infostream=false -Dtests.codec=random -Dtests.postingsformat=random -Dtests.docvaluesformat=random -Dtests.locale=random -Dtests.timezone=random -Dtests.directory=random -Dtests.linedocsfile=europarl.lines.txt.gz -Dtests.luceneMatchVersion=9.0.0 -Dtests.cleanthreads=perMethod -Djava.util.logging.config.file=C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\lucene\tools\junit4\logging.properties -Dtests.nightly=false -Dtests.weekly=false -Dtests.monster=false -Dtests.slow=true -Dtests.asserts=true -Dtests.multiplier=1 -DtempDir=./temp -Djava.io.tmpdir=./temp -Dcommon.dir=C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\lucene -Dclover.db.dir=C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\lucene\build\clover\db -Djava.security.policy=C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\lucene\tools\junit4\tests.policy -Dtests.LUCENE_VERSION=9.0.0 -Djetty.testMode=1 -Djetty.insecurerandom=1 -Dsolr.directoryFactory=org.apache.solr.core.MockDirectoryFactory -Djava.awt.headless=true -Djdk.map.althashing.threshold=0 -Dtests.src.home=C:\Users\jenkins\workspace\Lucene-Solr-master-Windows -Djava.security.egd=file:/dev/./urandom -Djunit4.childvm.cwd=C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\lucene\build\core\test\J3 -Djunit4.tempDir=C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\lucene\build\core\test\temp -Djunit4.childvm.id=3 -Djunit4.childvm.count=5 -Dfile.encoding=UTF-8 -Djava.security.manager=org.apache.lucene.util.TestSecurityManager -Dtests.filterstacks=true -Dtests.leaveTemporary=false -Dtests.badapples=false -classpath C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\lucene\build\codecs\classes\java;C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\lucene\build\test-framework\classes\java;C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\lucene\test-framework\lib\hamcrest-core-1.3.jar;C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\lucene\test-framework\lib\junit-4.12.jar;C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\lucene\test-framework\lib\randomizedtesting-runner-2.7.6.jar;C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\lucene\build\core\classes\java;C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\lucene\build\core\classes\test;C:\Users\jenkins\.ivy2\cache\com.carrotsearch.randomizedtesting\junit4-ant\jars\junit4-ant-2.7.6.jar com.carrotsearch.ant.tasks.junit4.slave.SlaveMainSafe -eventsfile C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\lucene\build\core\test\temp\junit4-J3-20200524_231032_17817756552491432918212.events @C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\lucene\build\core\test\temp\junit4-J3-20200524_231032_1782397091019042907402.suites -stdin
[junit4] ERROR: JVM J3 ended with an exception: Forked process returned with error code: 1. Very likely a JVM crash. See process stdout at: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\lucene\build\core\test\temp\junit4-J3-20200524_231032_1787638324882651934113.sysout
[junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4.executeSlave(JUnit4.java:1542)
[junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4.access$000(JUnit4.java:123)
[junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4$2.call(JUnit4.java:997)
[junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4$2.call(JUnit4.java:994)
[junit4] at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
[junit4] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
[junit4] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630)
[junit4] at java.base/java.lang.Thread.run(Thread.java:832)
BUILD FAILED
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\build.xml:635: The following error occurred while executing this line:
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\build.xml:579: The following error occurred while executing this line:
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\build.xml:59: The following error occurred while executing this line:
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\lucene\build.xml:50: The following error occurred while executing this line:
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\lucene\common-build.xml:1521: The following error occurred while executing this line:
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\lucene\common-build.xml:1048: At least one slave process threw an exception, first: Forked process returned with error code: 1. Very likely a JVM crash. See process stdout at: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\lucene\build\core\test\temp\junit4-J3-20200524_231032_1787638324882651934113.sysout
Total time: 6 minutes 4 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Setting ANT_1_8_2_HOME=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2
[WARNINGS] Skipping publisher since build result is FAILURE
Recording test results
Setting ANT_1_8_2_HOME=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any
Setting ANT_1_8_2_HOME=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2
Setting ANT_1_8_2_HOME=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2
Setting ANT_1_8_2_HOME=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2
Setting ANT_1_8_2_HOME=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2
Setting ANT_1_8_2_HOME=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2
Setting ANT_1_8_2_HOME=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2
[JENKINS] Lucene-Solr-master-Windows (64bit/jdk-14) - Build # 8875
- Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Windows/8875/
Java: 64bit/jdk-14 -XX:+UseCompressedOops -XX:+UseSerialGC
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([BF94C777ECD921B4:2C8F8F05B2247A80]: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:1754)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:942)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:978)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:992)
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:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:819)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:470)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:951)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:887)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:898)
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:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.lambda$forkTimeoutingTask$0(ThreadLeakControl.java:826)
at java.base/java.lang.Thread.run(Thread.java:832)
Build Log:
[...truncated 14912 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.ScheduledTriggerIntegrationTest
[junit4] 2> 1577964 INFO (SUITE-ScheduledTriggerIntegrationTest-seed#[BF94C777ECD921B4]-worker) [ ] o.a.s.SolrTestCase Setting 'solr.default.confdir' system property to test-framework derived value of 'C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\server\solr\configsets\_default\conf'
[junit4] 2> 1577964 INFO (SUITE-ScheduledTriggerIntegrationTest-seed#[BF94C777ECD921B4]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 1577965 INFO (SUITE-ScheduledTriggerIntegrationTest-seed#[BF94C777ECD921B4]-worker) [ ] o.a.s.SolrTestCaseJ4 Created dataDir: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J3\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_BF94C777ECD921B4-001\data-dir-116-001
[junit4] 2> 1577966 INFO (SUITE-ScheduledTriggerIntegrationTest-seed#[BF94C777ECD921B4]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 1577967 INFO (SUITE-ScheduledTriggerIntegrationTest-seed#[BF94C777ECD921B4]-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> 1577969 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testScheduledTrigger
[junit4] 2> 1577971 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J3\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_BF94C777ECD921B4-001\tempDir-001
[junit4] 2> 1577971 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 1577972 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port: 0.0.0.0/0.0.0.0:0
[junit4] 2> 1577972 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 1578080 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.c.ZkTestServer start zk server on port: 62196
[junit4] 2> 1578080 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.c.ZkTestServer waitForServerUp: 127.0.0.1:62196
[junit4] 2> 1578080 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:62196
[junit4] 2> 1578080 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 62196
[junit4] 2> 1578083 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1578086 INFO (zkConnectionManagerCallback-16491-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1578086 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1578093 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1578097 INFO (zkConnectionManagerCallback-16493-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1578097 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1578098 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1578101 INFO (zkConnectionManagerCallback-16495-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1578101 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1578214 INFO (jetty-launcher-16496-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 1578214 INFO (jetty-launcher-16496-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
[junit4] 2> 1578214 INFO (jetty-launcher-16496-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 1578214 INFO (jetty-launcher-16496-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
[junit4] 2> 1578214 INFO (jetty-launcher-16496-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> 1578214 INFO (jetty-launcher-16496-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> 1578216 INFO (jetty-launcher-16496-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1578216 INFO (jetty-launcher-16496-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1578216 INFO (jetty-launcher-16496-thread-2) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 1578216 INFO (jetty-launcher-16496-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1578216 INFO (jetty-launcher-16496-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1578216 INFO (jetty-launcher-16496-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 1578216 INFO (jetty-launcher-16496-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@56bcce4c{/solr,null,AVAILABLE}
[junit4] 2> 1578216 INFO (jetty-launcher-16496-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@83b7cc7{/solr,null,AVAILABLE}
[junit4] 2> 1578219 INFO (jetty-launcher-16496-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@62407f4a{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:62209}
[junit4] 2> 1578219 INFO (jetty-launcher-16496-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@275f911e{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:62210}
[junit4] 2> 1578219 INFO (jetty-launcher-16496-thread-2) [ ] o.e.j.s.Server Started @1524986ms
[junit4] 2> 1578219 INFO (jetty-launcher-16496-thread-1) [ ] o.e.j.s.Server Started @1524986ms
[junit4] 2> 1578219 INFO (jetty-launcher-16496-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=62209}
[junit4] 2> 1578219 INFO (jetty-launcher-16496-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=62210}
[junit4] 2> 1578219 ERROR (jetty-launcher-16496-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1578219 INFO (jetty-launcher-16496-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 1578219 ERROR (jetty-launcher-16496-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1578219 INFO (jetty-launcher-16496-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 1578219 INFO (jetty-launcher-16496-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 9.0.0
[junit4] 2> 1578219 INFO (jetty-launcher-16496-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1578219 INFO (jetty-launcher-16496-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 9.0.0
[junit4] 2> 1578219 INFO (jetty-launcher-16496-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr
[junit4] 2> 1578219 INFO (jetty-launcher-16496-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-05-24T18:47:13.990416400Z
[junit4] 2> 1578219 INFO (jetty-launcher-16496-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1578219 INFO (jetty-launcher-16496-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr
[junit4] 2> 1578219 INFO (jetty-launcher-16496-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-05-24T18:47:13.990416400Z
[junit4] 2> 1578220 INFO (jetty-launcher-16496-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1578220 INFO (jetty-launcher-16496-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1578222 INFO (zkConnectionManagerCallback-16500-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1578222 INFO (zkConnectionManagerCallback-16498-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1578222 INFO (jetty-launcher-16496-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1578222 INFO (jetty-launcher-16496-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1578223 INFO (jetty-launcher-16496-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1578223 INFO (jetty-launcher-16496-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1578340 INFO (jetty-launcher-16496-thread-2) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 1578342 WARN (jetty-launcher-16496-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@48dbadd1[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1578342 WARN (jetty-launcher-16496-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@48dbadd1[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1578347 WARN (jetty-launcher-16496-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@3527ca0b[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1578347 WARN (jetty-launcher-16496-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@3527ca0b[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1578348 INFO (jetty-launcher-16496-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:62196/solr
[junit4] 2> 1578350 INFO (jetty-launcher-16496-thread-2) [n:127.0.0.1:62209_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1578353 INFO (zkConnectionManagerCallback-16511-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1578353 INFO (jetty-launcher-16496-thread-2) [n:127.0.0.1:62209_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1578447 INFO (jetty-launcher-16496-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 1578449 WARN (jetty-launcher-16496-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@731ddac3[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1578450 WARN (jetty-launcher-16496-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@731ddac3[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1578453 WARN (jetty-launcher-16496-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@2a036f62[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1578453 WARN (jetty-launcher-16496-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@2a036f62[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1578455 INFO (jetty-launcher-16496-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:62196/solr
[junit4] 2> 1578457 INFO (jetty-launcher-16496-thread-1) [n:127.0.0.1:62210_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1578460 INFO (zkConnectionManagerCallback-16524-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1578460 INFO (jetty-launcher-16496-thread-1) [n:127.0.0.1:62210_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1578474 INFO (jetty-launcher-16496-thread-1) [n:127.0.0.1:62210_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:62210_solr
[junit4] 2> 1578477 INFO (jetty-launcher-16496-thread-1) [n:127.0.0.1:62210_solr ] o.a.s.c.Overseer Overseer (id=72098248557330438-127.0.0.1:62210_solr-n_0000000000) starting
[junit4] 2> 1578479 INFO (jetty-launcher-16496-thread-2) [n:127.0.0.1:62209_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:62209_solr
[junit4] 2> 1578482 INFO (zkCallback-16510-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1578482 INFO (zkCallback-16523-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1578485 INFO (jetty-launcher-16496-thread-2) [n:127.0.0.1:62209_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 1578485 WARN (jetty-launcher-16496-thread-2) [n:127.0.0.1:62209_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> 1578486 INFO (jetty-launcher-16496-thread-1) [n:127.0.0.1:62210_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:62210_solr as DOWN
[junit4] 2> 1578488 INFO (OverseerStateUpdate-72098248557330438-127.0.0.1:62210_solr-n_0000000000) [n:127.0.0.1:62210_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:62210_solr
[junit4] 2> 1578489 INFO (jetty-launcher-16496-thread-1) [n:127.0.0.1:62210_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 1000 transient cores
[junit4] 2> 1578489 INFO (jetty-launcher-16496-thread-1) [n:127.0.0.1:62210_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:62210_solr
[junit4] 2> 1578489 DEBUG (OverseerAutoScalingTriggerThread-72098248557330438-127.0.0.1:62210_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 1578490 INFO (OverseerStateUpdate-72098248557330438-127.0.0.1:62210_solr-n_0000000000) [n:127.0.0.1:62210_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1578490 DEBUG (OverseerAutoScalingTriggerThread-72098248557330438-127.0.0.1:62210_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 1578493 DEBUG (OverseerAutoScalingTriggerThread-72098248557330438-127.0.0.1:62210_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 0
[junit4] 2> 1578493 DEBUG (OverseerAutoScalingTriggerThread-72098248557330438-127.0.0.1:62210_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 1578493 INFO (zkCallback-16510-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1578497 INFO (jetty-launcher-16496-thread-1) [n:127.0.0.1:62210_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 1578497 WARN (jetty-launcher-16496-thread-1) [n:127.0.0.1:62210_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> 1578502 DEBUG (OverseerAutoScalingTriggerThread-72098248557330438-127.0.0.1:62210_solr-n_0000000000) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:62210_solr, 127.0.0.1:62209_solr]
[junit4] 2> 1578502 DEBUG (OverseerAutoScalingTriggerThread-72098248557330438-127.0.0.1:62210_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 1578504 DEBUG (OverseerAutoScalingTriggerThread-72098248557330438-127.0.0.1:62210_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 1578504 DEBUG (ScheduledTrigger-16530-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 1578515 INFO (jetty-launcher-16496-thread-2) [n:127.0.0.1:62209_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 1578527 INFO (jetty-launcher-16496-thread-1) [n:127.0.0.1:62210_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 1578544 INFO (jetty-launcher-16496-thread-2) [n:127.0.0.1:62209_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_62209.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1be71286
[junit4] 2> 1578553 INFO (jetty-launcher-16496-thread-1) [n:127.0.0.1:62210_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_62210.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1be71286
[junit4] 2> 1578553 INFO (jetty-launcher-16496-thread-2) [n:127.0.0.1:62209_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_62209.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1be71286
[junit4] 2> 1578553 INFO (jetty-launcher-16496-thread-2) [n:127.0.0.1:62209_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_62209.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1be71286
[junit4] 2> 1578555 INFO (jetty-launcher-16496-thread-2) [n:127.0.0.1:62209_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J3\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_BF94C777ECD921B4-001\tempDir-001\node2\.
[junit4] 2> 1578565 INFO (jetty-launcher-16496-thread-1) [n:127.0.0.1:62210_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_62210.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1be71286
[junit4] 2> 1578565 INFO (jetty-launcher-16496-thread-1) [n:127.0.0.1:62210_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_62210.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1be71286
[junit4] 2> 1578567 INFO (jetty-launcher-16496-thread-1) [n:127.0.0.1:62210_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J3\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_BF94C777ECD921B4-001\tempDir-001\node1\.
[junit4] 2> 1578581 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.c.MiniSolrCloudCluster waitForAllNodes: numServers=2
[junit4] 2> 1578586 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1578588 INFO (zkConnectionManagerCallback-16547-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1578588 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1578589 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1578590 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:62196/solr ready
[junit4] 2> 1578597 INFO (qtp697858653-26160) [n:127.0.0.1:62210_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling params={wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 1578600 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 1000 transient cores
[junit4] 2> 1578602 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=2
[junit4] 2> 1578606 INFO (qtp697858653-26164) [n:127.0.0.1:62210_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=2
[junit4] 2> 1578606 DEBUG (qtp1820822698-26159) [n:127.0.0.1:62209_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1578607 INFO (qtp1820822698-26159) [n:127.0.0.1:62209_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling params={wt=javabin&version=2} status=0 QTime=7
[junit4] 2> 1578607 DEBUG (zkCallback-16523-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 1578608 DEBUG (OverseerAutoScalingTriggerThread-72098248557330438-127.0.0.1:62210_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 1578608 INFO (qtp697858653-26160) [n:127.0.0.1:62210_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> 1578609 DEBUG (OverseerAutoScalingTriggerThread-72098248557330438-127.0.0.1:62210_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 1578610 DEBUG (OverseerAutoScalingTriggerThread-72098248557330438-127.0.0.1:62210_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 1578610 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection testScheduledTrigger
[junit4] 2> 1578611 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/managed-schema to /configs/testScheduledTrigger.AUTOCREATED/managed-schema
[junit4] 2> 1578613 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/protwords.txt to /configs/testScheduledTrigger.AUTOCREATED/protwords.txt
[junit4] 2> 1578615 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578616 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578617 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578619 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578620 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578622 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578624 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578627 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578629 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578629 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578632 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578632 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578635 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578636 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578636 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578640 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578640 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578643 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578644 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578644 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578648 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578648 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578651 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578651 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578655 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578655 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578655 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578660 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578660 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578660 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578664 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578664 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578668 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578668 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578668 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578672 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578672 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578675 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578675 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578675 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/solrconfig.xml to /configs/testScheduledTrigger.AUTOCREATED/solrconfig.xml
[junit4] 2> 1578695 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/synonyms.txt to /configs/testScheduledTrigger.AUTOCREATED/synonyms.txt
[junit4] 2> 1578697 INFO (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/stopwords.txt to /configs/testScheduledTrigger.AUTOCREATED/stopwords.txt
[junit4] 2> 1578812 WARN (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_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> 1578813 DEBUG (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_solr ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 1578817 INFO (qtp697858653-26162) [n:127.0.0.1:62210_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=3
[junit4] 2> 1578821 INFO (qtp1820822698-26157) [n:127.0.0.1:62209_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=2
[junit4] 2> 1578821 DEBUG (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_solr ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 1578824 INFO (qtp697858653-26164) [n:127.0.0.1:62210_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=2
[junit4] 2> 1578824 INFO (qtp1820822698-26161) [n:127.0.0.1:62209_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=1
[junit4] 2> 1578829 DEBUG (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_solr ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 620339533 sessionWrapper.createTime 620339525177300, this.sessionWrapper.createTime 620339525177300
[junit4] 2> 1578833 INFO (OverseerStateUpdate-72098248557330438-127.0.0.1:62210_solr-n_0000000000) [n:127.0.0.1:62210_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:62209/solr",
[junit4] 2> "node_name":"127.0.0.1:62209_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 1578835 INFO (OverseerStateUpdate-72098248557330438-127.0.0.1:62210_solr-n_0000000000) [n:127.0.0.1:62210_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:62210/solr",
[junit4] 2> "node_name":"127.0.0.1:62210_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 1578837 INFO (OverseerStateUpdate-72098248557330438-127.0.0.1:62210_solr-n_0000000000) [n:127.0.0.1:62210_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:62210/solr",
[junit4] 2> "node_name":"127.0.0.1:62210_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 1579054 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_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> 1579054 INFO (qtp697858653-26158) [n:127.0.0.1:62210_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> 1579055 INFO (qtp697858653-26164) [n:127.0.0.1:62210_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> 1579071 INFO (qtp697858653-26164) [n:127.0.0.1:62210_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 1579073 INFO (qtp697858653-26158) [n:127.0.0.1:62210_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 1579073 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 1579093 INFO (qtp697858653-26164) [n:127.0.0.1:62210_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.s.IndexSchema Schema name=default-config
[junit4] 2> 1579113 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.s.IndexSchema Schema name=default-config
[junit4] 2> 1579113 INFO (qtp697858653-26158) [n:127.0.0.1:62210_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.s.IndexSchema Schema name=default-config
[junit4] 2> 1579279 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_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> 1579279 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_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> 1579279 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_62209.solr.core.testScheduledTrigger.shard1.replica_n1' (registry 'solr.core.testScheduledTrigger.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1be71286
[junit4] 2> 1579280 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_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-master-Windows\solr\build\solr-core\test\J3\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_BF94C777ECD921B4-001\tempDir-001\node2\.\testScheduledTrigger_shard1_replica_n1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J3\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_BF94C777ECD921B4-001\tempDir-001\node2\.\testScheduledTrigger_shard1_replica_n1\data\]
[junit4] 2> 1579283 INFO (qtp697858653-26164) [n:127.0.0.1:62210_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> 1579283 INFO (qtp697858653-26164) [n:127.0.0.1:62210_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> 1579283 INFO (qtp697858653-26164) [n:127.0.0.1:62210_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_62210.solr.core.testScheduledTrigger.shard1.replica_n2' (registry 'solr.core.testScheduledTrigger.shard1.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1be71286
[junit4] 2> 1579284 INFO (qtp697858653-26164) [n:127.0.0.1:62210_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-master-Windows\solr\build\solr-core\test\J3\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_BF94C777ECD921B4-001\tempDir-001\node1\.\testScheduledTrigger_shard1_replica_n2], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J3\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_BF94C777ECD921B4-001\tempDir-001\node1\.\testScheduledTrigger_shard1_replica_n2\data\]
[junit4] 2> 1579284 INFO (qtp697858653-26158) [n:127.0.0.1:62210_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> 1579284 INFO (qtp697858653-26158) [n:127.0.0.1:62210_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> 1579284 INFO (qtp697858653-26158) [n:127.0.0.1:62210_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_62210.solr.core.testScheduledTrigger.shard1.replica_n4' (registry 'solr.core.testScheduledTrigger.shard1.replica_n4') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1be71286
[junit4] 2> 1579284 INFO (qtp697858653-26158) [n:127.0.0.1:62210_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-master-Windows\solr\build\solr-core\test\J3\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_BF94C777ECD921B4-001\tempDir-001\node1\.\testScheduledTrigger_shard1_replica_n4], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J3\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_BF94C777ECD921B4-001\tempDir-001\node1\.\testScheduledTrigger_shard1_replica_n4\data\]
[junit4] 2> 1579355 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_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> 1579355 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_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> 1579356 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_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> 1579356 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1579359 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_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> 1579359 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_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> 1579359 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_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> 1579361 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_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> 1579361 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
[junit4] 2> 1579361 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_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> 1579363 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_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> 1579363 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_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 1667598684136669184
[junit4] 2> 1579384 INFO (searcherExecutor-16549-thread-1-processing-n:127.0.0.1:62209_solr x:testScheduledTrigger_shard1_replica_n1 c:testScheduledTrigger s:shard1 r:core_node3) [n:127.0.0.1:62209_solr c:testScheduledTrigger s:shard1 r:core_node3 x:testScheduledTrigger_shard1_replica_n1 ] o.a.s.c.QuerySenderListener QuerySenderListener done.
[junit4] 2> 1579384 INFO (searcherExecutor-16549-thread-1-processing-n:127.0.0.1:62209_solr x:testScheduledTrigger_shard1_replica_n1 c:testScheduledTrigger s:shard1 r:core_node3) [n:127.0.0.1:62209_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> 1579385 INFO (searcherExecutor-16549-thread-1-processing-n:127.0.0.1:62209_solr x:testScheduledTrigger_shard1_replica_n1 c:testScheduledTrigger s:shard1 r:core_node3) [n:127.0.0.1:62209_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> 1579388 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_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> 1579388 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_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> 1579394 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_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> 1579397 INFO (qtp697858653-26164) [n:127.0.0.1:62210_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> 1579397 INFO (qtp697858653-26164) [n:127.0.0.1:62210_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> 1579399 INFO (qtp697858653-26158) [n:127.0.0.1:62210_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> 1579399 INFO (qtp697858653-26158) [n:127.0.0.1:62210_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> 1579399 INFO (qtp697858653-26164) [n:127.0.0.1:62210_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> 1579399 INFO (qtp697858653-26164) [n:127.0.0.1:62210_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1579403 INFO (qtp697858653-26158) [n:127.0.0.1:62210_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> 1579403 INFO (qtp697858653-26158) [n:127.0.0.1:62210_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1579403 INFO (qtp697858653-26164) [n:127.0.0.1:62210_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> 1579404 INFO (qtp697858653-26164) [n:127.0.0.1:62210_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> 1579404 INFO (qtp697858653-26164) [n:127.0.0.1:62210_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> 1579404 INFO (qtp697858653-26164) [n:127.0.0.1:62210_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> 1579405 INFO (qtp697858653-26158) [n:127.0.0.1:62210_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> 1579405 INFO (qtp697858653-26164) [n:127.0.0.1:62210_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
[junit4] 2> 1579405 INFO (qtp697858653-26164) [n:127.0.0.1:62210_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> 1579405 INFO (qtp697858653-26158) [n:127.0.0.1:62210_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> 1579405 INFO (qtp697858653-26158) [n:127.0.0.1:62210_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> 1579406 INFO (qtp697858653-26158) [n:127.0.0.1:62210_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> 1579406 INFO (qtp697858653-26164) [n:127.0.0.1:62210_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> 1579406 INFO (qtp697858653-26164) [n:127.0.0.1:62210_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 1667598684181757952
[junit4] 2> 1579406 INFO (qtp697858653-26158) [n:127.0.0.1:62210_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
[junit4] 2> 1579406 INFO (qtp697858653-26158) [n:127.0.0.1:62210_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> 1579407 INFO (qtp697858653-26158) [n:127.0.0.1:62210_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> 1579407 INFO (qtp697858653-26158) [n:127.0.0.1:62210_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 1667598684182806528
[junit4] 2> 1579408 INFO (searcherExecutor-16551-thread-1-processing-n:127.0.0.1:62210_solr x:testScheduledTrigger_shard1_replica_n2 c:testScheduledTrigger s:shard1 r:core_node5) [n:127.0.0.1:62210_solr c:testScheduledTrigger s:shard1 r:core_node5 x:testScheduledTrigger_shard1_replica_n2 ] o.a.s.c.QuerySenderListener QuerySenderListener done.
[junit4] 2> 1579408 INFO (searcherExecutor-16551-thread-1-processing-n:127.0.0.1:62210_solr x:testScheduledTrigger_shard1_replica_n2 c:testScheduledTrigger s:shard1 r:core_node5) [n:127.0.0.1:62210_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> 1579409 INFO (searcherExecutor-16553-thread-1-processing-n:127.0.0.1:62210_solr x:testScheduledTrigger_shard1_replica_n4 c:testScheduledTrigger s:shard1 r:core_node6) [n:127.0.0.1:62210_solr c:testScheduledTrigger s:shard1 r:core_node6 x:testScheduledTrigger_shard1_replica_n4 ] o.a.s.c.QuerySenderListener QuerySenderListener done.
[junit4] 2> 1579409 INFO (searcherExecutor-16553-thread-1-processing-n:127.0.0.1:62210_solr x:testScheduledTrigger_shard1_replica_n4 c:testScheduledTrigger s:shard1 r:core_node6) [n:127.0.0.1:62210_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> 1579409 INFO (searcherExecutor-16551-thread-1-processing-n:127.0.0.1:62210_solr x:testScheduledTrigger_shard1_replica_n2 c:testScheduledTrigger s:shard1 r:core_node5) [n:127.0.0.1:62210_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> 1579409 INFO (searcherExecutor-16553-thread-1-processing-n:127.0.0.1:62210_solr x:testScheduledTrigger_shard1_replica_n4 c:testScheduledTrigger s:shard1 r:core_node6) [n:127.0.0.1:62210_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> 1579411 INFO (qtp697858653-26164) [n:127.0.0.1:62210_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> 1579411 INFO (qtp697858653-26164) [n:127.0.0.1:62210_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> 1579411 INFO (qtp697858653-26158) [n:127.0.0.1:62210_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> 1579411 INFO (qtp697858653-26158) [n:127.0.0.1:62210_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> 1579573 DEBUG (ScheduledTrigger-16530-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> 1579928 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_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> 1579928 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_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> 1579928 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_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:62209/solr/testScheduledTrigger_shard1_replica_n1/
[junit4] 2> 1579930 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_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:62209/solr START replicas=[http://127.0.0.1:62210/solr/testScheduledTrigger_shard1_replica_n2/, http://127.0.0.1:62210/solr/testScheduledTrigger_shard1_replica_n4/] nUpdates=100
[junit4] 2> 1579930 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_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:62209/solr DONE. We have no versions. sync failed.
[junit4] 2> 1579931 INFO (qtp697858653-26162) [n:127.0.0.1:62210_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> 1579932 INFO (qtp697858653-26162) [n:127.0.0.1:62210_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> 1579932 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_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> 1579932 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_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> 1579932 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_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/72098248557330437-core_node3-n_0000000000
[junit4] 2> 1579935 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_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:62209/solr/testScheduledTrigger_shard1_replica_n1/ shard1
[junit4] 2> 1580046 INFO (zkCallback-16510-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> 1580047 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_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> 1580051 INFO (qtp1820822698-26163) [n:127.0.0.1:62209_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=934
[junit4] 2> 1580157 INFO (zkCallback-16510-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> 1580157 INFO (zkCallback-16510-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> 1580488 INFO (qtp697858653-26164) [n:127.0.0.1:62210_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=1342
[junit4] 2> 1580488 INFO (qtp697858653-26158) [n:127.0.0.1:62210_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=1343
[junit4] 2> 1580489 DEBUG (OverseerThreadFactory-16532-thread-1-processing-n:127.0.0.1:62210_solr) [n:127.0.0.1:62210_solr ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 1580491 INFO (qtp697858653-26160) [n:127.0.0.1:62210_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> 1580595 INFO (zkCallback-16510-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> 1580595 INFO (zkCallback-16523-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> 1580595 INFO (zkCallback-16510-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> 1580595 INFO (zkCallback-16523-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> 1580596 INFO (zkCallback-16523-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> 1580596 INFO (qtp697858653-26160) [n:127.0.0.1:62210_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=1862
[junit4] 2> 1580596 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.c.MiniSolrCloudCluster waitForActiveCollection: testScheduledTrigger
[junit4] 2> 1580600 INFO (qtp697858653-26164) [n:127.0.0.1:62210_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> 1580601 INFO (qtp697858653-26158) [n:127.0.0.1:62210_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=1
[junit4] 2> 1580603 INFO (qtp1820822698-26159) [n:127.0.0.1:62209_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> 1580604 INFO (qtp1820822698-26157) [n:127.0.0.1:62209_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=1
[junit4] 2> 1580606 DEBUG (qtp697858653-26162) [n:127.0.0.1:62210_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1580606 INFO (qtp697858653-26162) [n:127.0.0.1:62210_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling params={wt=javabin&version=2} status=0 QTime=7
[junit4] 2> 1580606 DEBUG (zkCallback-16523-thread-3) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 1580607 DEBUG (OverseerAutoScalingTriggerThread-72098248557330438-127.0.0.1:62210_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 1580608 DEBUG (OverseerAutoScalingTriggerThread-72098248557330438-127.0.0.1:62210_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 1580608 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 1580608 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
[junit4] 2> 1580608 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.e.j.s.Server jetty-9.4.27.v20200227; built: 2020-02-27T18:37:21.340Z; git: a304fd9f351f337e7c0e2a7c28878dd536149c6c; jvm 14+36
[junit4] 2> 1580608 DEBUG (OverseerAutoScalingTriggerThread-72098248557330438-127.0.0.1:62210_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 1580609 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1580609 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1580609 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 1580609 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6494b4b2{/solr,null,AVAILABLE}
[junit4] 2> 1580611 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@25d92d97{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:62280}
[junit4] 2> 1580611 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.e.j.s.Server Started @1527227ms
[junit4] 2> 1580611 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=62280}
[junit4] 2> 1580611 ERROR (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1580611 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 1580612 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 9.0.0
[junit4] 2> 1580612 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1580612 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr
[junit4] 2> 1580612 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-05-24T18:47:16.383119300Z
[junit4] 2> 1580613 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1580616 INFO (zkConnectionManagerCallback-16567-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1580616 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1580622 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1580641 DEBUG (ScheduledTrigger-16530-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> 1580740 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 1580742 WARN (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@64f0337[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1580743 WARN (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@64f0337[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1580747 WARN (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@f1b6765[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1580747 WARN (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@f1b6765[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 1580747 INFO (OverseerCollectionConfigSetProcessor-72098248557330438-127.0.0.1:62210_solr-n_0000000000) [n:127.0.0.1:62210_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> 1580748 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:62196/solr
[junit4] 2> 1580751 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [n:127.0.0.1:62280_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 1580755 INFO (zkConnectionManagerCallback-16578-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1580755 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [n:127.0.0.1:62280_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 1580762 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [n:127.0.0.1:62280_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1580768 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [n:127.0.0.1:62280_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:62280_solr as DOWN
[junit4] 2> 1580770 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [n:127.0.0.1:62280_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 1000 transient cores
[junit4] 2> 1580770 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [n:127.0.0.1:62280_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:62280_solr
[junit4] 2> 1580771 INFO (zkCallback-16510-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1580771 INFO (zkCallback-16546-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1580771 INFO (zkCallback-16523-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1580771 INFO (zkCallback-16577-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1580773 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [n:127.0.0.1:62280_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 1580774 WARN (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [n:127.0.0.1:62280_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> 1580804 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [n:127.0.0.1:62280_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 1580831 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [n:127.0.0.1:62280_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_62280.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1be71286
[junit4] 2> 1580842 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [n:127.0.0.1:62280_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_62280.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1be71286
[junit4] 2> 1580843 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [n:127.0.0.1:62280_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_62280.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1be71286
[junit4] 2> 1580845 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [n:127.0.0.1:62280_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J3\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_BF94C777ECD921B4-001\tempDir-001\node3\.
[junit4] 2> 1580889 INFO (TEST-ScheduledTriggerIntegrationTe
[...truncated too long message...]
1) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 1626308 INFO (closeThreadPool-16604-thread-2) [ ] o.a.s.c.Overseer Overseer (id=72098248557330438-127.0.0.1:62210_solr-n_0000000000) closing
[junit4] 2> 1626375 INFO (jetty-closer-16587-thread-3) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@25d92d97{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:0}
[junit4] 2> 1626375 INFO (jetty-closer-16587-thread-3) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@6494b4b2{/solr,null,UNAVAILABLE}
[junit4] 2> 1626375 INFO (jetty-closer-16587-thread-3) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 1626403 INFO (jetty-closer-16587-thread-2) [ ] o.a.s.c.Overseer Overseer (id=72098248557330438-127.0.0.1:62210_solr-n_0000000000) closing
[junit4] 2> 1626404 INFO (jetty-closer-16587-thread-2) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@275f911e{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:0}
[junit4] 2> 1626404 INFO (jetty-closer-16587-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@83b7cc7{/solr,null,UNAVAILABLE}
[junit4] 2> 1626404 INFO (jetty-closer-16587-thread-2) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 1626472 INFO (jetty-closer-16587-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@62407f4a{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:0}
[junit4] 2> 1626472 INFO (jetty-closer-16587-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@56bcce4c{/solr,null,UNAVAILABLE}
[junit4] 2> 1626472 INFO (jetty-closer-16587-thread-1) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 1626472 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.c.ZkTestServer Shutting down ZkTestServer.
[junit4] 2> 1626670 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> 15 /solr/live_nodes
[junit4] 2> 7 /solr/collections
[junit4] 2> 4 /solr/overseer/collection-queue-work
[junit4] 2>
[junit4] 2> 1626677 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.c.ZkTestServer waitForServerDown: 127.0.0.1:62196
[junit4] 2> 1626677 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:62196
[junit4] 2> 1626677 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 62196
[junit4] 2> 1628562 INFO (TEST-ScheduledTriggerIntegrationTest.testScheduledTrigger-seed#[BF94C777ECD921B4]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testScheduledTrigger
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ScheduledTriggerIntegrationTest -Dtests.method=testScheduledTrigger -Dtests.seed=BF94C777ECD921B4 -Dtests.slow=true -Dtests.locale=wae -Dtests.timezone=America/Fortaleza -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[junit4] FAILURE 50.6s J3 | ScheduledTriggerIntegrationTest.testScheduledTrigger <<<
[junit4] > Throwable #1: java.lang.AssertionError: ScheduledTrigger did not fire in time
[junit4] > at __randomizedtesting.SeedInfo.seed([BF94C777ECD921B4:2C8F8F05B2247A80]: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-master-Windows\solr\build\solr-core\test\J3\temp\solr.cloud.autoscaling.ScheduledTriggerIntegrationTest_BF94C777ECD921B4-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene86): {}, docValues:{}, maxPointsInLeafNode=1772, maxMBSortInHeap=7.457563445678626, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@307249cc), locale=wae, timezone=America/Fortaleza
[junit4] 2> NOTE: Windows 10 10.0 amd64/AdoptOpenJDK 14 (64-bit)/cpus=6,threads=1,free=93749152,total=398196736
[junit4] 2> NOTE: All tests run in this JVM: [ShardSplitTest, TestExportTool, AutoAddReplicasPlanActionTest, SolrCloudReportersTest, TestGraphTermsQParserPlugin, TestSchemaVersionResource, TestFileDictionaryLookup, TemplateUpdateProcessorTest, NodeMarkersRegistrationTest, TestChildDocTransformer, CursorPagingTest, TestStressReorder, RangeFacetCloudTest, TestInitParams, BitVectorTest, TestMiniSolrCloudClusterSSL, JvmMetricsTest, OutputWriterTest, TestNestedDocsSort, TestComplexPhraseQParserPlugin, TolerantUpdateProcessorTest, RankQueryTest, AddReplicaTest, SynonymTokenizerTest, ResponseLogComponentTest, TestCursorMarkWithoutUniqueKey, TestConfig, TestSafeXMLParsing, SolrCloudExampleTest, TestSkipOverseerOperations, SplitHandlerTest, TestManagedSchemaThreadSafety, ImplicitSnitchTest, CoreSorterTest, TestDocTermOrds, TestTolerantUpdateProcessorRandomCloud, SpatialFilterTest, BlobRepositoryCloudTest, TestExtendedDismaxParser, TestCustomDocTransformer, SolrCoreCheckLockOnStartupTest, InfixSuggestersTest, TestExportWriter, ResolveAnalyzerByNameTest, LoggingHandlerTest, MetricsHistoryIntegrationTest, TestQueryingOnDownCollection, XMLAtomicUpdateMultivalueTest, TestFieldTypeCollectionResource, TestDynamicFieldNamesIndexCorrectly, LeaderFailoverAfterPartitionTest, DistanceUnitsTest, DistributedUpdateProcessorTest, V2ApiIntegrationTest, UUIDFieldTest, TestManagedSynonymGraphFilterFactory, HttpTriggerListenerTest, ReindexCollectionTest, TestQueryUtils, MoreLikeThisHandlerTest, TestJsonRangeFacets, TestReversedWildcardFilterFactory, BinaryUpdateRequestHandlerTest, TestGroupingSearch, TestSolr4Spatial2, TestRemoteStreaming, AtomicUpdateProcessorFactoryTest, TestEmbeddedSolrServerConstructors, JWTVerificationkeyResolverTest, TestSolrCloudWithHadoopAuthPlugin, TestHdfsCloudBackupRestore, TestMacros, TestSolrConfigHandler, OverseerTest, TestJsonFacetErrors, SimpleFacetsTest, TestCryptoKeys, CollectionsAPIDistributedZkTest, TestStressInPlaceUpdates, IndexSchemaTest, TestNumericTerms64, OverseerRolesTest, DocValuesNotIndexedTest, SoftAutoCommitTest, TestSortByMinMaxFunction, TestFieldCacheSortRandom, TestSQLHandlerNonCloud, TestUnifiedSolrHighlighterWithoutStoredId, MetricTriggerTest, PeerSyncWithBufferUpdatesTest, TestRandomDVFaceting, TestSimpleTrackingShardHandler, BasicDistributedZk2Test, CleanupOldIndexTest, CloudExitableDirectoryReaderTest, ClusterStateMockUtilTest, ClusterStateTest, ClusterStateUpdateTest, CollectionPropsTest, CreateRoutedAliasTest, DistribDocExpirationUpdateProcessorTest, NestedShardedAtomicUpdateTest, RecoveryZkTest, RestartWhileUpdatingTest, RollingRestartTest, SystemCollectionCompatTest, TestCloudPhrasesIdentificationComponent, TestCloudPseudoReturnFields, TestCloudRecovery2, TestConfigSetsAPIZkFailure, TestExactStatsCacheCloud, TestHashPartitioner, TestLeaderElectionWithEmptyReplica, TestSolrCloudWithKerberosAlt, TestWaitForStateWithJettyShutdowns, TlogReplayBufferedWhileIndexingTest, TriLevelCompositeIdRoutingTest, ZkControllerTest, AssignTest, CollectionReloadTest, ConcurrentDeleteAndCreateCollectionTest, CustomCollectionTest, ExecutePlanActionTest, NodeLostTriggerIntegrationTest, ScheduledTriggerIntegrationTest]
[junit4] Completed [594/913 (1!)] on J3 in 50.64s, 1 test, 1 failure <<< FAILURES!
[...truncated 46009 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Windows/8875/consoleText
[repro] Revision: 675956c0041b18d48a7c059ea458c49f5310d74a
[repro] Ant options: "-Dargs=-XX:+UseCompressedOops -XX:+UseSerialGC"
[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 3158 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.ScheduledTriggerIntegrationTest" -Dtests.showOutput=onerror "-Dargs=-XX:+UseCompressedOops -XX:+UseSerialGC" -Dtests.seed=BF94C777ECD921B4 -Dtests.slow=true -Dtests.locale=wae -Dtests.timezone=America/Fortaleza -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[...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...]