You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2019/07/27 20:53:41 UTC
[JENKINS] Lucene-Solr-8.x-Linux (64bit/jdk-11.0.3) - Build # 930 -
Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-8.x-Linux/930/
Java: 64bit/jdk-11.0.3 -XX:-UseCompressedOops -XX:+UseG1GC
5 tests failed.
FAILED: org.apache.lucene.util.TestOfflineSorter.testThreadSafety
Error Message:
Captured an uncaught exception in thread: Thread[id=20, name=Thread-3, state=RUNNABLE, group=TGRP-TestOfflineSorter]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=20, name=Thread-3, state=RUNNABLE, group=TGRP-TestOfflineSorter]
Caused by: java.lang.RuntimeException: java.nio.file.AccessDeniedException: Can't open a file still open for writing: unsorted_tmp_1.tmp
at __randomizedtesting.SeedInfo.seed([C8E4D2456ECBDAB8]:0)
at org.apache.lucene.util.TestOfflineSorter$2.run(TestOfflineSorter.java:271)
Caused by: java.nio.file.AccessDeniedException: Can't open a file still open for writing: unsorted_tmp_1.tmp
at org.apache.lucene.store.ByteBuffersDirectory$FileEntry.openInput(ByteBuffersDirectory.java:251)
at org.apache.lucene.store.ByteBuffersDirectory.openInput(ByteBuffersDirectory.java:218)
at org.apache.lucene.store.NRTCachingDirectory.slowFileExists(NRTCachingDirectory.java:278)
at org.apache.lucene.store.NRTCachingDirectory.createTempOutput(NRTCachingDirectory.java:252)
at org.apache.lucene.store.MockDirectoryWrapper.createTempOutput(MockDirectoryWrapper.java:702)
at org.apache.lucene.util.TestOfflineSorter.checkSort(TestOfflineSorter.java:183)
at org.apache.lucene.util.TestOfflineSorter.access$100(TestOfflineSorter.java:49)
at org.apache.lucene.util.TestOfflineSorter$2.run(TestOfflineSorter.java:267)
FAILED: org.apache.lucene.util.TestOfflineSorter.testThreadSafety
Error Message:
Captured an uncaught exception in thread: Thread[id=27, name=Thread-7, state=RUNNABLE, group=TGRP-TestOfflineSorter]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=27, name=Thread-7, state=RUNNABLE, group=TGRP-TestOfflineSorter]
Caused by: java.lang.RuntimeException: java.nio.file.AccessDeniedException: Can't open a file still open for writing: unsorted_tmp_0.tmp
at __randomizedtesting.SeedInfo.seed([C8E4D2456ECBDAB8]:0)
at org.apache.lucene.util.TestOfflineSorter$2.run(TestOfflineSorter.java:271)
Caused by: java.nio.file.AccessDeniedException: Can't open a file still open for writing: unsorted_tmp_0.tmp
at org.apache.lucene.store.ByteBuffersDirectory$FileEntry.openInput(ByteBuffersDirectory.java:251)
at org.apache.lucene.store.ByteBuffersDirectory.openInput(ByteBuffersDirectory.java:218)
at org.apache.lucene.store.NRTCachingDirectory.slowFileExists(NRTCachingDirectory.java:278)
at org.apache.lucene.store.NRTCachingDirectory.createTempOutput(NRTCachingDirectory.java:252)
at org.apache.lucene.store.MockDirectoryWrapper.createTempOutput(MockDirectoryWrapper.java:702)
at org.apache.lucene.util.TestOfflineSorter.checkSort(TestOfflineSorter.java:183)
at org.apache.lucene.util.TestOfflineSorter.access$100(TestOfflineSorter.java:49)
at org.apache.lucene.util.TestOfflineSorter$2.run(TestOfflineSorter.java:267)
FAILED: org.apache.lucene.util.TestOfflineSorter.testThreadSafety
Error Message:
Captured an uncaught exception in thread: Thread[id=25, name=Thread-5, state=RUNNABLE, group=TGRP-TestOfflineSorter]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=25, name=Thread-5, state=RUNNABLE, group=TGRP-TestOfflineSorter]
Caused by: java.lang.RuntimeException: java.nio.file.AccessDeniedException: Can't open a file still open for writing: unsorted_tmp_0.tmp
at __randomizedtesting.SeedInfo.seed([C8E4D2456ECBDAB8]:0)
at org.apache.lucene.util.TestOfflineSorter$2.run(TestOfflineSorter.java:271)
Caused by: java.nio.file.AccessDeniedException: Can't open a file still open for writing: unsorted_tmp_0.tmp
at org.apache.lucene.store.ByteBuffersDirectory$FileEntry.openInput(ByteBuffersDirectory.java:251)
at org.apache.lucene.store.ByteBuffersDirectory.openInput(ByteBuffersDirectory.java:218)
at org.apache.lucene.store.NRTCachingDirectory.slowFileExists(NRTCachingDirectory.java:278)
at org.apache.lucene.store.NRTCachingDirectory.createTempOutput(NRTCachingDirectory.java:252)
at org.apache.lucene.store.MockDirectoryWrapper.createTempOutput(MockDirectoryWrapper.java:702)
at org.apache.lucene.util.TestOfflineSorter.checkSort(TestOfflineSorter.java:183)
at org.apache.lucene.util.TestOfflineSorter.access$100(TestOfflineSorter.java:49)
at org.apache.lucene.util.TestOfflineSorter$2.run(TestOfflineSorter.java:267)
FAILED: org.apache.lucene.util.TestOfflineSorter.testThreadSafety
Error Message:
Captured an uncaught exception in thread: Thread[id=2807, name=Thread-2774, state=RUNNABLE, group=TGRP-TestOfflineSorter]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=2807, name=Thread-2774, state=RUNNABLE, group=TGRP-TestOfflineSorter]
Caused by: java.lang.RuntimeException: java.nio.file.AccessDeniedException: Can't open a file still open for writing: unsorted_tmp_0.tmp
at __randomizedtesting.SeedInfo.seed([C8E4D2456ECBDAB8]:0)
at org.apache.lucene.util.TestOfflineSorter$2.run(TestOfflineSorter.java:271)
Caused by: java.nio.file.AccessDeniedException: Can't open a file still open for writing: unsorted_tmp_0.tmp
at org.apache.lucene.store.ByteBuffersDirectory$FileEntry.openInput(ByteBuffersDirectory.java:251)
at org.apache.lucene.store.ByteBuffersDirectory.openInput(ByteBuffersDirectory.java:218)
at org.apache.lucene.store.NRTCachingDirectory.slowFileExists(NRTCachingDirectory.java:278)
at org.apache.lucene.store.NRTCachingDirectory.createTempOutput(NRTCachingDirectory.java:252)
at org.apache.lucene.store.MockDirectoryWrapper.createTempOutput(MockDirectoryWrapper.java:702)
at org.apache.lucene.util.TestOfflineSorter.checkSort(TestOfflineSorter.java:183)
at org.apache.lucene.util.TestOfflineSorter.access$100(TestOfflineSorter.java:49)
at org.apache.lucene.util.TestOfflineSorter$2.run(TestOfflineSorter.java:267)
FAILED: org.apache.solr.cloud.AliasIntegrationTest.testClusterStateProviderAPI
Error Message:
{} expected:<2> but was:<0>
Stack Trace:
java.lang.AssertionError: {} expected:<2> but was:<0>
at __randomizedtesting.SeedInfo.seed([819CE69C519C3377:9E4B7AB02297CA3C]:0)
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.failNotEquals(Assert.java:834)
at org.junit.Assert.assertEquals(Assert.java:645)
at org.apache.solr.cloud.AliasIntegrationTest.testClusterStateProviderAPI(AliasIntegrationTest.java:303)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1750)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:947)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.base/java.lang.Thread.run(Thread.java:834)
Build Log:
[...truncated 1342 lines...]
[junit4] Suite: org.apache.lucene.util.TestOfflineSorter
[junit4] 2> ?? 28, 2019 7:29:54 ?? com.carrotsearch.randomizedtesting.RandomizedRunner$QueueUncaughtExceptionsHandler uncaughtException
[junit4] 2> WARNING: Uncaught exception in thread: Thread[Thread-2774,5,TGRP-TestOfflineSorter]
[junit4] 2> java.lang.RuntimeException: java.nio.file.AccessDeniedException: Can't open a file still open for writing: unsorted_tmp_0.tmp
[junit4] 2> at __randomizedtesting.SeedInfo.seed([C8E4D2456ECBDAB8]:0)
[junit4] 2> at org.apache.lucene.util.TestOfflineSorter$2.run(TestOfflineSorter.java:271)
[junit4] 2> Caused by: java.nio.file.AccessDeniedException: Can't open a file still open for writing: unsorted_tmp_0.tmp
[junit4] 2> at org.apache.lucene.store.ByteBuffersDirectory$FileEntry.openInput(ByteBuffersDirectory.java:251)
[junit4] 2> at org.apache.lucene.store.ByteBuffersDirectory.openInput(ByteBuffersDirectory.java:218)
[junit4] 2> at org.apache.lucene.store.NRTCachingDirectory.slowFileExists(NRTCachingDirectory.java:278)
[junit4] 2> at org.apache.lucene.store.NRTCachingDirectory.createTempOutput(NRTCachingDirectory.java:252)
[junit4] 2> at org.apache.lucene.store.MockDirectoryWrapper.createTempOutput(MockDirectoryWrapper.java:702)
[junit4] 2> at org.apache.lucene.util.TestOfflineSorter.checkSort(TestOfflineSorter.java:183)
[junit4] 2> at org.apache.lucene.util.TestOfflineSorter.access$100(TestOfflineSorter.java:49)
[junit4] 2> at org.apache.lucene.util.TestOfflineSorter$2.run(TestOfflineSorter.java:267)
[junit4] 2>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestOfflineSorter -Dtests.method=testThreadSafety -Dtests.seed=C8E4D2456ECBDAB8 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ii -Dtests.timezone=Pacific/Nauru -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[junit4] ERROR 0.07s J2 | TestOfflineSorter.testThreadSafety <<<
[junit4] > Throwable #1: java.lang.AssertionError
[junit4] > at org.apache.lucene.util.TestOfflineSorter.testThreadSafety(TestOfflineSorter.java:282)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] > at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] > at java.base/java.lang.reflect.Method.invoke(Method.java:566)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:834)Throwable #2: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=2807, name=Thread-2774, state=RUNNABLE, group=TGRP-TestOfflineSorter]
[junit4] > Caused by: java.lang.RuntimeException: java.nio.file.AccessDeniedException: Can't open a file still open for writing: unsorted_tmp_0.tmp
[junit4] > at __randomizedtesting.SeedInfo.seed([C8E4D2456ECBDAB8]:0)
[junit4] > at org.apache.lucene.util.TestOfflineSorter$2.run(TestOfflineSorter.java:271)
[junit4] > Caused by: java.nio.file.AccessDeniedException: Can't open a file still open for writing: unsorted_tmp_0.tmp
[junit4] > at org.apache.lucene.store.ByteBuffersDirectory$FileEntry.openInput(ByteBuffersDirectory.java:251)
[junit4] > at org.apache.lucene.store.ByteBuffersDirectory.openInput(ByteBuffersDirectory.java:218)
[junit4] > at org.apache.lucene.store.NRTCachingDirectory.slowFileExists(NRTCachingDirectory.java:278)
[junit4] > at org.apache.lucene.store.NRTCachingDirectory.createTempOutput(NRTCachingDirectory.java:252)
[junit4] > at org.apache.lucene.store.MockDirectoryWrapper.createTempOutput(MockDirectoryWrapper.java:702)
[junit4] > at org.apache.lucene.util.TestOfflineSorter.checkSort(TestOfflineSorter.java:183)
[junit4] > at org.apache.lucene.util.TestOfflineSorter.access$100(TestOfflineSorter.java:49)
[junit4] > at org.apache.lucene.util.TestOfflineSorter$2.run(TestOfflineSorter.java:267)
[junit4] IGNOR/A 0.00s J2 | TestOfflineSorter.testLargerRandom
[junit4] > Assumption #1: 'nightly' test group is disabled (@Nightly())
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-8.x-Linux/lucene/build/core/test/J2/temp/lucene.util.TestOfflineSorter_C8E4D2456ECBDAB8-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene80): {}, docValues:{}, maxPointsInLeafNode=1482, maxMBSortInHeap=6.8659559105559556, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@60c4c22c), locale=ii, timezone=Pacific/Nauru
[junit4] 2> NOTE: Linux 4.18.0-25-generic amd64/AdoptOpenJDK 11.0.3 (64-bit)/cpus=8,threads=1,free=440485112,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [TestIndexingSequenceNumbers, TestNewestSegment, TestCharsRef, TestLucene80DocValuesFormat, TestFrequencyTrackingRingBuffer, TestMultiPhraseQuery, TestMultiThreadTermVectors, TestBooleanScorer, TestOfflineSorter]
[junit4] Completed [301/525 (1!)] on J2 in 4.29s, 15 tests, 1 error, 1 skipped <<< FAILURES!
[...truncated 12738 lines...]
[junit4] Suite: org.apache.solr.cloud.AliasIntegrationTest
[junit4] 2> 624678 INFO (SUITE-AliasIntegrationTest-seed#[819CE69C519C3377]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.AliasIntegrationTest_819CE69C519C3377-001/init-core-data-001
[junit4] 2> 624679 WARN (SUITE-AliasIntegrationTest-seed#[819CE69C519C3377]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=33 numCloses=33
[junit4] 2> 624679 INFO (SUITE-AliasIntegrationTest-seed#[819CE69C519C3377]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 624680 INFO (SUITE-AliasIntegrationTest-seed#[819CE69C519C3377]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason="", ssl=0.0/0.0, value=0.0/0.0, clientAuth=0.0/0.0)
[junit4] 2> 624680 INFO (SUITE-AliasIntegrationTest-seed#[819CE69C519C3377]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.AliasIntegrationTest_819CE69C519C3377-001/tempDir-001
[junit4] 2> 624680 INFO (SUITE-AliasIntegrationTest-seed#[819CE69C519C3377]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 624684 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 624684 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 624784 INFO (SUITE-AliasIntegrationTest-seed#[819CE69C519C3377]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:35507
[junit4] 2> 624784 INFO (SUITE-AliasIntegrationTest-seed#[819CE69C519C3377]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:35507
[junit4] 2> 624784 INFO (SUITE-AliasIntegrationTest-seed#[819CE69C519C3377]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 35507
[junit4] 2> 624808 INFO (SUITE-AliasIntegrationTest-seed#[819CE69C519C3377]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 624823 INFO (zkConnectionManagerCallback-2052-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 624823 INFO (SUITE-AliasIntegrationTest-seed#[819CE69C519C3377]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 624841 INFO (SUITE-AliasIntegrationTest-seed#[819CE69C519C3377]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 624856 INFO (zkConnectionManagerCallback-2054-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 624856 INFO (SUITE-AliasIntegrationTest-seed#[819CE69C519C3377]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 624872 INFO (SUITE-AliasIntegrationTest-seed#[819CE69C519C3377]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 624936 INFO (zkConnectionManagerCallback-2056-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 624936 INFO (SUITE-AliasIntegrationTest-seed#[819CE69C519C3377]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 625042 WARN (jetty-launcher-2057-thread-2) [ ] o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time
[junit4] 2> 625042 WARN (jetty-launcher-2057-thread-1) [ ] o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time
[junit4] 2> 625042 INFO (jetty-launcher-2057-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (original configured port=0)
[junit4] 2> 625042 INFO (jetty-launcher-2057-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 625042 INFO (jetty-launcher-2057-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (original configured port=0)
[junit4] 2> 625042 INFO (jetty-launcher-2057-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 625042 INFO (jetty-launcher-2057-thread-1) [ ] o.e.j.s.Server jetty-9.4.19.v20190610; built: 2019-06-10T16:30:51.723Z; git: afcf563148970e98786327af5e07c261fda175d3; jvm 11.0.3+7
[junit4] 2> 625042 INFO (jetty-launcher-2057-thread-2) [ ] o.e.j.s.Server jetty-9.4.19.v20190610; built: 2019-06-10T16:30:51.723Z; git: afcf563148970e98786327af5e07c261fda175d3; jvm 11.0.3+7
[junit4] 2> 625116 INFO (jetty-launcher-2057-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 625116 INFO (jetty-launcher-2057-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 625116 INFO (jetty-launcher-2057-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 625124 INFO (jetty-launcher-2057-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 625124 INFO (jetty-launcher-2057-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 625124 INFO (jetty-launcher-2057-thread-2) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 625128 INFO (jetty-launcher-2057-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@25a3377{/solr,null,AVAILABLE}
[junit4] 2> 625129 INFO (jetty-launcher-2057-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@48b5c882{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:46331}
[junit4] 2> 625129 INFO (jetty-launcher-2057-thread-2) [ ] o.e.j.s.Server Started @625177ms
[junit4] 2> 625129 INFO (jetty-launcher-2057-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=46331}
[junit4] 2> 625129 ERROR (jetty-launcher-2057-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 625129 INFO (jetty-launcher-2057-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 625129 INFO (jetty-launcher-2057-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.3.0
[junit4] 2> 625129 INFO (jetty-launcher-2057-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 625129 INFO (jetty-launcher-2057-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 625129 INFO (jetty-launcher-2057-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2019-07-27T20:07:45.220655Z
[junit4] 2> 625136 INFO (jetty-launcher-2057-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@3c4a3b4b{/solr,null,AVAILABLE}
[junit4] 2> 625137 INFO (jetty-launcher-2057-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@2f876bcf{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:32777}
[junit4] 2> 625137 INFO (jetty-launcher-2057-thread-1) [ ] o.e.j.s.Server Started @625185ms
[junit4] 2> 625137 INFO (jetty-launcher-2057-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=32777}
[junit4] 2> 625137 ERROR (jetty-launcher-2057-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 625137 INFO (jetty-launcher-2057-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 625137 INFO (jetty-launcher-2057-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.3.0
[junit4] 2> 625137 INFO (jetty-launcher-2057-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 625137 INFO (jetty-launcher-2057-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 625137 INFO (jetty-launcher-2057-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2019-07-27T20:07:45.228704Z
[junit4] 2> 625164 INFO (jetty-launcher-2057-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 625176 INFO (jetty-launcher-2057-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 625176 INFO (zkConnectionManagerCallback-2059-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 625176 INFO (jetty-launcher-2057-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 625178 INFO (jetty-launcher-2057-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 625180 INFO (zkConnectionManagerCallback-2061-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 625180 INFO (jetty-launcher-2057-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 625180 INFO (jetty-launcher-2057-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 625359 INFO (jetty-launcher-2057-thread-2) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 625372 WARN (jetty-launcher-2057-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@391b147e[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 625372 WARN (jetty-launcher-2057-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@391b147e[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 625385 WARN (jetty-launcher-2057-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@4383f1b5[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 625385 WARN (jetty-launcher-2057-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@4383f1b5[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 625386 INFO (jetty-launcher-2057-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:35507/solr
[junit4] 2> 625387 INFO (jetty-launcher-2057-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 625388 INFO (zkConnectionManagerCallback-2069-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 625388 INFO (jetty-launcher-2057-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 625482 INFO (jetty-launcher-2057-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 625488 WARN (jetty-launcher-2057-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@34fca105[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 625488 WARN (jetty-launcher-2057-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@34fca105[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 625500 INFO (jetty-launcher-2057-thread-2) [n:127.0.0.1:46331_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 625508 INFO (zkConnectionManagerCallback-2072-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 625508 INFO (jetty-launcher-2057-thread-2) [n:127.0.0.1:46331_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 625508 WARN (jetty-launcher-2057-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@232430a4[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 625508 WARN (jetty-launcher-2057-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@232430a4[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 625510 INFO (jetty-launcher-2057-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:35507/solr
[junit4] 2> 625515 INFO (jetty-launcher-2057-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 625523 INFO (zkConnectionManagerCallback-2077-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 625523 INFO (jetty-launcher-2057-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 625592 INFO (jetty-launcher-2057-thread-2) [n:127.0.0.1:46331_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:46331_solr
[junit4] 2> 625593 INFO (jetty-launcher-2057-thread-2) [n:127.0.0.1:46331_solr ] o.a.s.c.Overseer Overseer (id=72073745001545734-127.0.0.1:46331_solr-n_0000000000) starting
[junit4] 2> 625601 INFO (jetty-launcher-2057-thread-2) [n:127.0.0.1:46331_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 625601 INFO (zkConnectionManagerCallback-2084-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 625601 INFO (jetty-launcher-2057-thread-2) [n:127.0.0.1:46331_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 625604 INFO (jetty-launcher-2057-thread-2) [n:127.0.0.1:46331_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:35507/solr ready
[junit4] 2> 625605 INFO (OverseerStateUpdate-72073745001545734-127.0.0.1:46331_solr-n_0000000000) [n:127.0.0.1:46331_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:46331_solr
[junit4] 2> 625607 INFO (jetty-launcher-2057-thread-2) [n:127.0.0.1:46331_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46331_solr
[junit4] 2> 625608 INFO (OverseerStateUpdate-72073745001545734-127.0.0.1:46331_solr-n_0000000000) [n:127.0.0.1:46331_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 625613 INFO (jetty-launcher-2057-thread-2) [n:127.0.0.1:46331_solr ] o.a.s.c.LibListener clusterprops.json changed , version -1
[junit4] 2> 625632 INFO (zkCallback-2083-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 625668 INFO (jetty-launcher-2057-thread-2) [n:127.0.0.1:46331_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 625685 INFO (jetty-launcher-2057-thread-1) [n:127.0.0.1:32777_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 625686 INFO (zkConnectionManagerCallback-2086-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 625686 INFO (jetty-launcher-2057-thread-1) [n:127.0.0.1:32777_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 625690 INFO (jetty-launcher-2057-thread-2) [n:127.0.0.1:46331_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46331.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@49f3576e
[junit4] 2> 625696 INFO (jetty-launcher-2057-thread-1) [n:127.0.0.1:32777_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 625698 INFO (jetty-launcher-2057-thread-1) [n:127.0.0.1:32777_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:32777_solr as DOWN
[junit4] 2> 625699 INFO (jetty-launcher-2057-thread-1) [n:127.0.0.1:32777_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 625699 INFO (jetty-launcher-2057-thread-1) [n:127.0.0.1:32777_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:32777_solr
[junit4] 2> 625700 INFO (zkCallback-2083-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 625701 INFO (zkCallback-2071-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 625701 INFO (zkCallback-2085-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 625712 INFO (jetty-launcher-2057-thread-2) [n:127.0.0.1:46331_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46331.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@49f3576e
[junit4] 2> 625712 INFO (jetty-launcher-2057-thread-2) [n:127.0.0.1:46331_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46331.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@49f3576e
[junit4] 2> 625713 INFO (jetty-launcher-2057-thread-2) [n:127.0.0.1:46331_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.AliasIntegrationTest_819CE69C519C3377-001/tempDir-001/node2/.
[junit4] 2> 625717 INFO (jetty-launcher-2057-thread-1) [n:127.0.0.1:32777_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 625717 INFO (zkConnectionManagerCallback-2094-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 625718 INFO (jetty-launcher-2057-thread-1) [n:127.0.0.1:32777_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 625718 INFO (jetty-launcher-2057-thread-1) [n:127.0.0.1:32777_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 625719 INFO (jetty-launcher-2057-thread-1) [n:127.0.0.1:32777_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:35507/solr ready
[junit4] 2> 625719 INFO (jetty-launcher-2057-thread-1) [n:127.0.0.1:32777_solr ] o.a.s.c.LibListener clusterprops.json changed , version -1
[junit4] 2> 625746 INFO (jetty-launcher-2057-thread-1) [n:127.0.0.1:32777_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 625762 INFO (jetty-launcher-2057-thread-1) [n:127.0.0.1:32777_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_32777.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@49f3576e
[junit4] 2> 625779 INFO (jetty-launcher-2057-thread-1) [n:127.0.0.1:32777_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_32777.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@49f3576e
[junit4] 2> 625779 INFO (jetty-launcher-2057-thread-1) [n:127.0.0.1:32777_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_32777.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@49f3576e
[junit4] 2> 625780 INFO (jetty-launcher-2057-thread-1) [n:127.0.0.1:32777_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.AliasIntegrationTest_819CE69C519C3377-001/tempDir-001/node1/.
[junit4] 2> 625819 INFO (SUITE-AliasIntegrationTest-seed#[819CE69C519C3377]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 625821 INFO (zkConnectionManagerCallback-2100-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 625821 INFO (SUITE-AliasIntegrationTest-seed#[819CE69C519C3377]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 625833 INFO (SUITE-AliasIntegrationTest-seed#[819CE69C519C3377]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 625834 INFO (SUITE-AliasIntegrationTest-seed#[819CE69C519C3377]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:35507/solr ready
[junit4] 2> 625851 INFO (TEST-AliasIntegrationTest.testModifyPropertiesV1-seed#[819CE69C519C3377]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testModifyPropertiesV1
[junit4] 2> 625859 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :clusterstatus with params action=CLUSTERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 625860 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=CLUSTERSTATUS&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 625888 INFO (qtp1181888060-7136) [n:127.0.0.1:46331_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params collection.configName=conf&name=collection1meta&nrtReplicas=1&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 625892 INFO (OverseerThreadFactory-2316-thread-1-processing-n:127.0.0.1:46331_solr) [n:127.0.0.1:46331_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection collection1meta
[junit4] 2> 626020 INFO (OverseerStateUpdate-72073745001545734-127.0.0.1:46331_solr-n_0000000000) [n:127.0.0.1:46331_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"collection1meta",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"collection1meta_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:32777/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 626022 INFO (OverseerStateUpdate-72073745001545734-127.0.0.1:46331_solr-n_0000000000) [n:127.0.0.1:46331_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"collection1meta",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"collection1meta_shard2_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:46331/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 626223 INFO (qtp1181888060-7132) [n:127.0.0.1:46331_solr x:collection1meta_shard2_replica_n2 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf&newCollection=true&name=collection1meta_shard2_replica_n2&action=CREATE&numShards=2&collection=collection1meta&shard=shard2&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 626223 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr x:collection1meta_shard1_replica_n1 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=collection1meta_shard1_replica_n1&action=CREATE&numShards=2&collection=collection1meta&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 626224 INFO (qtp1181888060-7132) [n:127.0.0.1:46331_solr x:collection1meta_shard2_replica_n2 ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 627230 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr c:collection1meta s:shard1 r:core_node3 x:collection1meta_shard1_replica_n1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.3.0
[junit4] 2> 627230 INFO (qtp1181888060-7132) [n:127.0.0.1:46331_solr c:collection1meta s:shard2 r:core_node4 x:collection1meta_shard2_replica_n2 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.3.0
[junit4] 2> 627236 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr c:collection1meta s:shard1 r:core_node3 x:collection1meta_shard1_replica_n1 ] o.a.s.s.IndexSchema [collection1meta_shard1_replica_n1] Schema name=minimal
[junit4] 2> 627236 INFO (qtp1181888060-7132) [n:127.0.0.1:46331_solr c:collection1meta s:shard2 r:core_node4 x:collection1meta_shard2_replica_n2 ] o.a.s.s.IndexSchema [collection1meta_shard2_replica_n2] Schema name=minimal
[junit4] 2> 627237 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr c:collection1meta s:shard1 r:core_node3 x:collection1meta_shard1_replica_n1 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 627237 INFO (qtp1181888060-7132) [n:127.0.0.1:46331_solr c:collection1meta s:shard2 r:core_node4 x:collection1meta_shard2_replica_n2 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 627237 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr c:collection1meta s:shard1 r:core_node3 x:collection1meta_shard1_replica_n1 ] o.a.s.c.CoreContainer Creating SolrCore 'collection1meta_shard1_replica_n1' using configuration from collection collection1meta, trusted=true
[junit4] 2> 627237 INFO (qtp1181888060-7132) [n:127.0.0.1:46331_solr c:collection1meta s:shard2 r:core_node4 x:collection1meta_shard2_replica_n2 ] o.a.s.c.CoreContainer Creating SolrCore 'collection1meta_shard2_replica_n2' using configuration from collection collection1meta, trusted=true
[junit4] 2> 627238 INFO (qtp1181888060-7132) [n:127.0.0.1:46331_solr c:collection1meta s:shard2 r:core_node4 x:collection1meta_shard2_replica_n2 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46331.solr.core.collection1meta.shard2.replica_n2' (registry 'solr.core.collection1meta.shard2.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@49f3576e
[junit4] 2> 627238 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr c:collection1meta s:shard1 r:core_node3 x:collection1meta_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_32777.solr.core.collection1meta.shard1.replica_n1' (registry 'solr.core.collection1meta.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@49f3576e
[junit4] 2> 627238 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr c:collection1meta s:shard1 r:core_node3 x:collection1meta_shard1_replica_n1 ] o.a.s.c.SolrCore [[collection1meta_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.AliasIntegrationTest_819CE69C519C3377-001/tempDir-001/node1/collection1meta_shard1_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.AliasIntegrationTest_819CE69C519C3377-001/tempDir-001/node1/./collection1meta_shard1_replica_n1/data/]
[junit4] 2> 627238 INFO (qtp1181888060-7132) [n:127.0.0.1:46331_solr c:collection1meta s:shard2 r:core_node4 x:collection1meta_shard2_replica_n2 ] o.a.s.c.SolrCore [[collection1meta_shard2_replica_n2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.AliasIntegrationTest_819CE69C519C3377-001/tempDir-001/node2/collection1meta_shard2_replica_n2], dataDir=[/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.AliasIntegrationTest_819CE69C519C3377-001/tempDir-001/node2/./collection1meta_shard2_replica_n2/data/]
[junit4] 2> 627264 INFO (qtp1181888060-7132) [n:127.0.0.1:46331_solr c:collection1meta s:shard2 r:core_node4 x:collection1meta_shard2_replica_n2 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 627264 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr c:collection1meta s:shard1 r:core_node3 x:collection1meta_shard1_replica_n1 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 627264 INFO (qtp1181888060-7132) [n:127.0.0.1:46331_solr c:collection1meta s:shard2 r:core_node4 x:collection1meta_shard2_replica_n2 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 627264 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr c:collection1meta s:shard1 r:core_node3 x:collection1meta_shard1_replica_n1 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 627271 INFO (qtp1181888060-7132) [n:127.0.0.1:46331_solr c:collection1meta s:shard2 r:core_node4 x:collection1meta_shard2_replica_n2 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 627271 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr c:collection1meta s:shard1 r:core_node3 x:collection1meta_shard1_replica_n1 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 627271 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr c:collection1meta s:shard1 r:core_node3 x:collection1meta_shard1_replica_n1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 627271 INFO (qtp1181888060-7132) [n:127.0.0.1:46331_solr c:collection1meta s:shard2 r:core_node4 x:collection1meta_shard2_replica_n2 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 627272 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr c:collection1meta s:shard1 r:core_node3 x:collection1meta_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@511d7bad[collection1meta_shard1_replica_n1] main]
[junit4] 2> 627272 INFO (qtp1181888060-7132) [n:127.0.0.1:46331_solr c:collection1meta s:shard2 r:core_node4 x:collection1meta_shard2_replica_n2 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@7db9b9c0[collection1meta_shard2_replica_n2] main]
[junit4] 2> 627272 INFO (qtp1181888060-7132) [n:127.0.0.1:46331_solr c:collection1meta s:shard2 r:core_node4 x:collection1meta_shard2_replica_n2 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 627273 INFO (qtp1181888060-7132) [n:127.0.0.1:46331_solr c:collection1meta s:shard2 r:core_node4 x:collection1meta_shard2_replica_n2 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 627273 INFO (qtp1181888060-7132) [n:127.0.0.1:46331_solr c:collection1meta s:shard2 r:core_node4 x:collection1meta_shard2_replica_n2 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 627273 INFO (qtp1181888060-7132) [n:127.0.0.1:46331_solr c:collection1meta s:shard2 r:core_node4 x:collection1meta_shard2_replica_n2 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1640243467244273664
[junit4] 2> 627275 INFO (searcherExecutor-2325-thread-1-processing-n:127.0.0.1:46331_solr x:collection1meta_shard2_replica_n2 c:collection1meta s:shard2 r:core_node4) [n:127.0.0.1:46331_solr c:collection1meta s:shard2 r:core_node4 x:collection1meta_shard2_replica_n2 ] o.a.s.c.SolrCore [collection1meta_shard2_replica_n2] Registered new searcher Searcher@7db9b9c0[collection1meta_shard2_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 627276 INFO (qtp1181888060-7132) [n:127.0.0.1:46331_solr c:collection1meta s:shard2 r:core_node4 x:collection1meta_shard2_replica_n2 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/collection1meta/terms/shard2 to Terms{values={core_node4=0}, version=0}
[junit4] 2> 627276 INFO (qtp1181888060-7132) [n:127.0.0.1:46331_solr c:collection1meta s:shard2 r:core_node4 x:collection1meta_shard2_replica_n2 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/collection1meta/leaders/shard2
[junit4] 2> 627277 INFO (qtp1181888060-7132) [n:127.0.0.1:46331_solr c:collection1meta s:shard2 r:core_node4 x:collection1meta_shard2_replica_n2 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 627277 INFO (qtp1181888060-7132) [n:127.0.0.1:46331_solr c:collection1meta s:shard2 r:core_node4 x:collection1meta_shard2_replica_n2 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 627277 INFO (qtp1181888060-7132) [n:127.0.0.1:46331_solr c:collection1meta s:shard2 r:core_node4 x:collection1meta_shard2_replica_n2 ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:46331/solr/collection1meta_shard2_replica_n2/
[junit4] 2> 627278 INFO (qtp1181888060-7132) [n:127.0.0.1:46331_solr c:collection1meta s:shard2 r:core_node4 x:collection1meta_shard2_replica_n2 ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 627278 INFO (qtp1181888060-7132) [n:127.0.0.1:46331_solr c:collection1meta s:shard2 r:core_node4 x:collection1meta_shard2_replica_n2 ] o.a.s.c.SyncStrategy http://127.0.0.1:46331/solr/collection1meta_shard2_replica_n2/ has no replicas
[junit4] 2> 627278 INFO (qtp1181888060-7132) [n:127.0.0.1:46331_solr c:collection1meta s:shard2 r:core_node4 x:collection1meta_shard2_replica_n2 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/collection1meta/leaders/shard2/leader after winning as /collections/collection1meta/leader_elect/shard2/election/72073745001545734-core_node4-n_0000000000
[junit4] 2> 627279 INFO (qtp1181888060-7132) [n:127.0.0.1:46331_solr c:collection1meta s:shard2 r:core_node4 x:collection1meta_shard2_replica_n2 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:46331/solr/collection1meta_shard2_replica_n2/ shard2
[junit4] 2> 627280 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr c:collection1meta s:shard1 r:core_node3 x:collection1meta_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 627280 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr c:collection1meta s:shard1 r:core_node3 x:collection1meta_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 627281 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr c:collection1meta s:shard1 r:core_node3 x:collection1meta_shard1_replica_n1 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 627281 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr c:collection1meta s:shard1 r:core_node3 x:collection1meta_shard1_replica_n1 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1640243467252662272
[junit4] 2> 627283 INFO (searcherExecutor-2326-thread-1-processing-n:127.0.0.1:32777_solr x:collection1meta_shard1_replica_n1 c:collection1meta s:shard1 r:core_node3) [n:127.0.0.1:32777_solr c:collection1meta s:shard1 r:core_node3 x:collection1meta_shard1_replica_n1 ] o.a.s.c.SolrCore [collection1meta_shard1_replica_n1] Registered new searcher Searcher@511d7bad[collection1meta_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 627284 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr c:collection1meta s:shard1 r:core_node3 x:collection1meta_shard1_replica_n1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/collection1meta/terms/shard1 to Terms{values={core_node3=0}, version=0}
[junit4] 2> 627284 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr c:collection1meta s:shard1 r:core_node3 x:collection1meta_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/collection1meta/leaders/shard1
[junit4] 2> 627286 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr c:collection1meta s:shard1 r:core_node3 x:collection1meta_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 627286 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr c:collection1meta s:shard1 r:core_node3 x:collection1meta_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 627286 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr c:collection1meta s:shard1 r:core_node3 x:collection1meta_shard1_replica_n1 ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:32777/solr/collection1meta_shard1_replica_n1/
[junit4] 2> 627286 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr c:collection1meta s:shard1 r:core_node3 x:collection1meta_shard1_replica_n1 ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 627286 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr c:collection1meta s:shard1 r:core_node3 x:collection1meta_shard1_replica_n1 ] o.a.s.c.SyncStrategy http://127.0.0.1:32777/solr/collection1meta_shard1_replica_n1/ has no replicas
[junit4] 2> 627286 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr c:collection1meta s:shard1 r:core_node3 x:collection1meta_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/collection1meta/leaders/shard1/leader after winning as /collections/collection1meta/leader_elect/shard1/election/72073745001545737-core_node3-n_0000000000
[junit4] 2> 627287 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr c:collection1meta s:shard1 r:core_node3 x:collection1meta_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:32777/solr/collection1meta_shard1_replica_n1/ shard1
[junit4] 2> 627388 INFO (zkCallback-2085-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1meta/state.json] for collection [collection1meta] has occurred - updating... (live nodes size: [2])
[junit4] 2> 627388 INFO (zkCallback-2071-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1meta/state.json] for collection [collection1meta] has occurred - updating... (live nodes size: [2])
[junit4] 2> 627388 INFO (zkCallback-2085-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1meta/state.json] for collection [collection1meta] has occurred - updating... (live nodes size: [2])
[junit4] 2> 627389 INFO (zkCallback-2071-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1meta/state.json] for collection [collection1meta] has occurred - updating... (live nodes size: [2])
[junit4] 2> 627389 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr c:collection1meta s:shard1 r:core_node3 x:collection1meta_shard1_replica_n1 ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 627389 INFO (qtp1181888060-7132) [n:127.0.0.1:46331_solr c:collection1meta s:shard2 r:core_node4 x:collection1meta_shard2_replica_n2 ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 627431 INFO (qtp1181888060-7132) [n:127.0.0.1:46331_solr c:collection1meta s:shard2 r:core_node4 x:collection1meta_shard2_replica_n2 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf&newCollection=true&name=collection1meta_shard2_replica_n2&action=CREATE&numShards=2&collection=collection1meta&shard=shard2&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1208
[junit4] 2> 627431 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr c:collection1meta s:shard1 r:core_node3 x:collection1meta_shard1_replica_n1 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=collection1meta_shard1_replica_n1&action=CREATE&numShards=2&collection=collection1meta&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1208
[junit4] 2> 627434 INFO (qtp1181888060-7136) [n:127.0.0.1:46331_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> 627491 INFO (zkCallback-2085-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1meta/state.json] for collection [collection1meta] has occurred - updating... (live nodes size: [2])
[junit4] 2> 627491 INFO (zkCallback-2071-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1meta/state.json] for collection [collection1meta] has occurred - updating... (live nodes size: [2])
[junit4] 2> 627491 INFO (zkCallback-2085-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1meta/state.json] for collection [collection1meta] has occurred - updating... (live nodes size: [2])
[junit4] 2> 627491 INFO (zkCallback-2071-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1meta/state.json] for collection [collection1meta] has occurred - updating... (live nodes size: [2])
[junit4] 2> 627491 INFO (zkCallback-2071-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1meta/state.json] for collection [collection1meta] has occurred - updating... (live nodes size: [2])
[junit4] 2> 627491 INFO (zkCallback-2085-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1meta/state.json] for collection [collection1meta] has occurred - updating... (live nodes size: [2])
[junit4] 2> 627491 INFO (qtp1181888060-7136) [n:127.0.0.1:46331_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={collection.configName=conf&name=collection1meta&nrtReplicas=1&action=CREATE&numShards=2&wt=javabin&version=2} status=0 QTime=1602
[junit4] 2> 627491 INFO (qtp1181888060-7138) [n:127.0.0.1:46331_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params collection.configName=conf&name=collection2meta&nrtReplicas=1&action=CREATE&numShards=1&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 627493 INFO (OverseerThreadFactory-2316-thread-2-processing-n:127.0.0.1:46331_solr) [n:127.0.0.1:46331_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection collection2meta
[junit4] 2> 627493 INFO (OverseerCollectionConfigSetProcessor-72073745001545734-127.0.0.1:46331_solr-n_0000000000) [n:127.0.0.1:46331_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> 627699 INFO (OverseerStateUpdate-72073745001545734-127.0.0.1:46331_solr-n_0000000000) [n:127.0.0.1:46331_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"collection2meta",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"collection2meta_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:32777/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 627900 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr x:collection2meta_shard1_replica_n1 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf&newCollection=true&name=collection2meta_shard1_replica_n1&action=CREATE&numShards=1&collection=collection2meta&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 628907 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr c:collection2meta s:shard1 r:core_node2 x:collection2meta_shard1_replica_n1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.3.0
[junit4] 2> 628912 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr c:collection2meta s:shard1 r:core_node2 x:collection2meta_shard1_replica_n1 ] o.a.s.s.IndexSchema [collection2meta_shard1_replica_n1] Schema name=minimal
[junit4] 2> 628913 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr c:collection2meta s:shard1 r:core_node2 x:collection2meta_shard1_replica_n1 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 628913 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr c:collection2meta s:shard1 r:core_node2 x:collection2meta_shard1_replica_n1 ] o.a.s.c.CoreContainer Creating SolrCore 'collection2meta_shard1_replica_n1' using configuration from collection collection2meta, trusted=true
[junit4] 2> 628913 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr c:collection2meta s:shard1 r:core_node2 x:collection2meta_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_32777.solr.core.collection2meta.shard1.replica_n1' (registry 'solr.core.collection2meta.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@49f3576e
[junit4] 2> 628913 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr c:collection2meta s:shard1 r:core_node2 x:collection2meta_shard1_replica_n1 ] o.a.s.c.SolrCore [[collection2meta_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.AliasIntegrationTest_819CE69C519C3377-001/tempDir-001/node1/collection2meta_shard1_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.AliasIntegrationTest_819CE69C519C3377-001/tempDir-001/node1/./collection2meta_shard1_replica_n1/data/]
[junit4] 2> 628939 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr c:collection2meta s:shard1 r:core_node2 x:collection2meta_shard1_replica_n1 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 628939 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr c:collection2meta s:shard1 r:core_node2 x:collection2meta_shard1_replica_n1 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 628941 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr c:collection2meta s:shard1 r:core_node2 x:collection2meta_shard1_replica_n1 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 628941 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr c:collection2meta s:shard1 r:core_node2 x:collection2meta_shard1_replica_n1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 628941 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr c:collection2meta s:shard1 r:core_node2 x:collection2meta_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@2f43ae5d[collection2meta_shard1_replica_n1] main]
[junit4] 2> 628942 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr c:collection2meta s:shard1 r:core_node2 x:collection2meta_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 628943 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr c:collection2meta s:shard1 r:core_node2 x:collection2meta_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 628943 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr c:collection2meta s:shard1 r:core_node2 x:collection2meta_shard1_replica_n1 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 628943 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr c:collection2meta s:shard1 r:core_node2 x:collection2meta_shard1_replica_n1 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1640243468995395584
[junit4] 2> 628945 INFO (searcherExecutor-2335-thread-1-processing-n:127.0.0.1:32777_solr x:collection2meta_shard1_replica_n1 c:collection2meta s:shard1 r:core_node2) [n:127.0.0.1:32777_solr c:collection2meta s:shard1 r:core_node2 x:collection2meta_shard1_replica_n1 ] o.a.s.c.SolrCore [collection2meta_shard1_replica_n1] Registered new searcher Searcher@2f43ae5d[collection2meta_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 628947 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr c:collection2meta s:shard1 r:core_node2 x:collection2meta_shard1_replica_n1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/collection2meta/terms/shard1 to Terms{values={core_node2=0}, version=0}
[junit4] 2> 628947 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr c:collection2meta s:shard1 r:core_node2 x:collection2meta_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/collection2meta/leaders/shard1
[junit4] 2> 628948 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr c:collection2meta s:shard1 r:core_node2 x:collection2meta_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 628948 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr c:collection2meta s:shard1 r:core_node2 x:collection2meta_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 628948 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr c:collection2meta s:shard1 r:core_node2 x:collection2meta_shard1_replica_n1 ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:32777/solr/collection2meta_shard1_replica_n1/
[junit4] 2> 628949 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr c:collection2meta s:shard1 r:core_node2 x:collection2meta_shard1_replica_n1 ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 628949 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr c:collection2meta s:shard1 r:core_node2 x:collection2meta_shard1_replica_n1 ] o.a.s.c.SyncStrategy http://127.0.0.1:32777/solr/collection2meta_shard1_replica_n1/ has no replicas
[junit4] 2> 628949 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr c:collection2meta s:shard1 r:core_node2 x:collection2meta_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/collection2meta/leaders/shard1/leader after winning as /collections/collection2meta/leader_elect/shard1/election/72073745001545737-core_node2-n_0000000000
[junit4] 2> 628949 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr c:collection2meta s:shard1 r:core_node2 x:collection2meta_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:32777/solr/collection2meta_shard1_replica_n1/ shard1
[junit4] 2> 629051 INFO (zkCallback-2085-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection2meta/state.json] for collection [collection2meta] has occurred - updating... (live nodes size: [2])
[junit4] 2> 629051 INFO (zkCallback-2085-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection2meta/state.json] for collection [collection2meta] has occurred - updating... (live nodes size: [2])
[junit4] 2> 629051 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr c:collection2meta s:shard1 r:core_node2 x:collection2meta_shard1_replica_n1 ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 629053 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr c:collection2meta s:shard1 r:core_node2 x:collection2meta_shard1_replica_n1 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf&newCollection=true&name=collection2meta_shard1_replica_n1&action=CREATE&numShards=1&collection=collection2meta&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1152
[junit4] 2> 629054 INFO (qtp1181888060-7138) [n:127.0.0.1:46331_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> 629153 INFO (zkCallback-2085-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection2meta/state.json] for collection [collection2meta] has occurred - updating... (live nodes size: [2])
[junit4] 2> 629153 INFO (zkCallback-2085-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection2meta/state.json] for collection [collection2meta] has occurred - updating... (live nodes size: [2])
[junit4] 2> 629153 INFO (zkCallback-2085-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection2meta/state.json] for collection [collection2meta] has occurred - updating... (live nodes size: [2])
[junit4] 2> 629153 INFO (zkCallback-2071-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection2meta/state.json] for collection [collection2meta] has occurred - updating... (live nodes size: [2])
[junit4] 2> 629154 INFO (qtp1181888060-7138) [n:127.0.0.1:46331_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={collection.configName=conf&name=collection2meta&nrtReplicas=1&action=CREATE&numShards=1&wt=javabin&version=2} status=0 QTime=1662
[junit4] 2> 629155 INFO (TEST-AliasIntegrationTest.testModifyPropertiesV1-seed#[819CE69C519C3377]) [ ] o.a.s.c.SolrCloudTestCase active replica count: 2 expected replica count: 2
[junit4] 2> 629155 INFO (watches-2097-thread-1) [ ] o.a.s.c.SolrCloudTestCase active replica count: 2 expected replica count: 2
[junit4] 2> 629155 INFO (TEST-AliasIntegrationTest.testModifyPropertiesV1-seed#[819CE69C519C3377]) [ ] o.a.s.c.SolrCloudTestCase active replica count: 2 expected replica count: 2
[junit4] 2> 629156 INFO (TEST-AliasIntegrationTest.testModifyPropertiesV1-seed#[819CE69C519C3377]) [ ] o.a.s.c.SolrCloudTestCase active replica count: 2 expected replica count: 2
[junit4] 2> 629156 INFO (TEST-AliasIntegrationTest.testModifyPropertiesV1-seed#[819CE69C519C3377]) [ ] o.a.s.c.SolrCloudTestCase active replica count: 1 expected replica count: 1
[junit4] 2> 629156 INFO (watches-2097-thread-1) [ ] o.a.s.c.SolrCloudTestCase active replica count: 1 expected replica count: 1
[junit4] 2> 629156 INFO (TEST-AliasIntegrationTest.testModifyPropertiesV1-seed#[819CE69C519C3377]) [ ] o.a.s.c.SolrCloudTestCase active replica count: 1 expected replica count: 1
[junit4] 2> 629156 INFO (TEST-AliasIntegrationTest.testModifyPropertiesV1-seed#[819CE69C519C3377]) [ ] o.a.s.c.SolrCloudTestCase active replica count: 1 expected replica count: 1
[junit4] 2> 629159 INFO (qtp1181888060-7136) [n:127.0.0.1:46331_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :aliasprop with params name=testModifyPropertiesV1&action=ALIASPROP&property.foo=baz&wt=xml&property.bar=bam and sendToOCPQueue=true
[junit4] 2> 629165 INFO (OverseerCollectionConfigSetProcessor-72073745001545734-127.0.0.1:46331_solr-n_0000000000) [n:127.0.0.1:46331_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000002 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 629166 INFO (qtp1181888060-7136) [n:127.0.0.1:46331_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=testModifyPropertiesV1&action=ALIASPROP&property.foo=baz&wt=xml&property.bar=bam} status=0 QTime=7
[junit4] 2> 629167 INFO (TEST-AliasIntegrationTest.testModifyPropertiesV1-seed#[819CE69C519C3377]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testModifyPropertiesV1
[junit4] 2> 629168 INFO (TEST-AliasIntegrationTest.testModifyPropertiesV1-seed#[819CE69C519C3377]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 629169 INFO (qtp1181888060-7136) [n:127.0.0.1:46331_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=collection2meta&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 629170 INFO (OverseerCollectionConfigSetProcessor-72073745001545734-127.0.0.1:46331_solr-n_0000000000) [n:127.0.0.1:46331_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000004 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 629171 INFO (OverseerThreadFactory-2316-thread-4-processing-n:127.0.0.1:46331_solr) [n:127.0.0.1:46331_solr ] o.a.s.c.a.c.OverseerCollectionMessageHandler Executing Collection Cmd=action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true&deleteMetricsHistory=true, asyncId=null
[junit4] 2> 629171 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr x:collection2meta_shard1_replica_n1 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection2meta.shard1.replica_n1, tag=null
[junit4] 2> 629171 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr x:collection2meta_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@346ca41: rootName = solr_32777, domain = solr.core.collection2meta.shard1.replica_n1, service url = null, agent id = null] for registry solr.core.collection2meta.shard1.replica_n1 / com.codahale.metrics.MetricRegistry@2f25e8c2
[junit4] 2> 629180 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr x:collection2meta_shard1_replica_n1 ] o.a.s.c.SolrCore [collection2meta_shard1_replica_n1] CLOSING SolrCore org.apache.solr.core.SolrCore@516e60d8
[junit4] 2> 629180 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr x:collection2meta_shard1_replica_n1 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection2meta.shard1.replica_n1, tag=516e60d8
[junit4] 2> 629180 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr x:collection2meta_shard1_replica_n1 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.collection2meta.shard1.leader, tag=516e60d8
[junit4] 2> 629182 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr x:collection2meta_shard1_replica_n1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/collection2meta/terms/shard1 to Terms{values={}, version=1}
[junit4] 2> 629182 INFO (qtp557875607-7134) [n:127.0.0.1:32777_solr x:collection2meta_shard1_replica_n1 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&deleteMetricsHistory=true&core=collection2meta_shard1_replica_n1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=11
[junit4] 2> 629284 INFO (zkCallback-2085-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDeleted path:/collections/collection2meta/state.json] for collection [collection2meta] has occurred - updating... (live nodes size: [2])
[junit4] 2> 629284 INFO (zkCallback-2071-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDeleted path:/collections/collection2meta/state.json] for collection [collection2meta] has occurred - updating... (live nodes size: [2])
[junit4] 2> 629284 INFO (zkCallback-2085-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDeleted path:/collections/collection2meta/state.json] for collection [collection2meta] has occurred - updating... (live nodes size: [2])
[junit4] 2> 629284 INFO (zkCallback-2085-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDeleted path:/collections/collection2meta/state.json] for collection [collection2meta] has occurred - updating... (live nodes size: [2])
[junit4] 2> 629284 INFO (zkCallback-2071-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDeleted path:/collections/collection2meta/state.json] for collection [collection2meta] has occurred - updating... (live nodes size: [2])
[junit4] 2> 629287 INFO (qtp1181888060-7136) [n:127.0.0.1:46331_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=collection2meta&action=DELETE&wt=javabin&version=2} status=0 QTime=117
[junit4] 2> 629287 INFO (qtp1181888060-7132) [n:127.0.0.1:46331_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=collection1meta&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 629288 INFO (OverseerCollectionConfigSetProcessor-72073745001545734-127.0.0.1:46331_solr-n_0000000000) [n:127.0.0.1:46331_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000006 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 629289 INFO (OverseerThreadFactory-2316-thread-5-processing-n:127.0.0.1:46331_solr) [n:127.0.0.1:46331_solr ] o.a.s.c.a.c.OverseerCollectionMessageHandler Executing Collection Cmd=action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true&deleteMetricsHistory=true, asyncId=null
[junit4] 2> 629289 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr x:collection1meta_shard1_replica_n1 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1meta.shard1.replica_n1, tag=null
[junit4] 2> 629289 INFO (qtp1181888060-7138) [n:127.0.0.1:46331_solr x:collection1meta_shard2_replica_n2 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1meta.shard2.replica_n2, tag=null
[junit4] 2> 629289 INFO (qtp1181888060-7138) [n:127.0.0.1:46331_solr x:collection1meta_shard2_replica_n2 ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@27bf0ce5: rootName = solr_46331, domain = solr.core.collection1meta.shard2.replica_n2, service url = null, agent id = null] for registry solr.core.collection1meta.shard2.replica_n2 / com.codahale.metrics.MetricRegistry@28b5d76c
[junit4] 2> 629289 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr x:collection1meta_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4d94a4b8: rootName = solr_32777, domain = solr.core.collection1meta.shard1.replica_n1, service url = null, agent id = null] for registry solr.core.collection1meta.shard1.replica_n1 / com.codahale.metrics.MetricRegistry@122b713
[junit4] 2> 629297 INFO (qtp1181888060-7138) [n:127.0.0.1:46331_solr x:collection1meta_shard2_replica_n2 ] o.a.s.c.SolrCore [collection1meta_shard2_replica_n2] CLOSING SolrCore org.apache.solr.core.SolrCore@73779e8e
[junit4] 2> 629297 INFO (qtp1181888060-7138) [n:127.0.0.1:46331_solr x:collection1meta_shard2_replica_n2 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1meta.shard2.replica_n2, tag=73779e8e
[junit4] 2> 629297 INFO (qtp1181888060-7138) [n:127.0.0.1:46331_solr x:collection1meta_shard2_replica_n2 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.collection1meta.shard2.leader, tag=73779e8e
[junit4] 2> 629298 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr x:collection1meta_shard1_replica_n1 ] o.a.s.c.SolrCore [collection1meta_shard1_replica_n1] CLOSING SolrCore org.apache.solr.core.SolrCore@555ac263
[junit4] 2> 629298 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr x:collection1meta_shard1_replica_n1 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1meta.shard1.replica_n1, tag=555ac263
[junit4] 2> 629298 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr x:collection1meta_shard1_replica_n1 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.collection1meta.shard1.leader, tag=555ac263
[junit4] 2> 629299 INFO (qtp1181888060-7138) [n:127.0.0.1:46331_solr x:collection1meta_shard2_replica_n2 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/collection1meta/terms/shard2 to Terms{values={}, version=1}
[junit4] 2> 629300 INFO (qtp1181888060-7138) [n:127.0.0.1:46331_solr x:collection1meta_shard2_replica_n2 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&deleteMetricsHistory=true&core=collection1meta_shard2_replica_n2&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=10
[junit4] 2> 629300 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr x:collection1meta_shard1_replica_n1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/collection1meta/terms/shard1 to Terms{values={}, version=1}
[junit4] 2> 629300 INFO (qtp557875607-7133) [n:127.0.0.1:32777_solr x:collection1meta_shard1_replica_n1 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&deleteMetricsHistory=true&core=collection1meta_shard1_replica_n1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=11
[junit4] 2> 629401 INFO (zkCallback-2085-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDeleted path:/collections/collection1meta/state.json] for collection [collection1meta] has occurred - updating... (live nodes size: [2])
[junit4] 2> 629401 INFO (zkCallback-2085-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDeleted path:/collections/collection1meta/state.json] for collection [collection1meta] has occurred - updating... (live nodes size: [2])
[junit4] 2> 629402 INFO (zkCallback-2071-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDeleted path:/collections/collection1meta/state.json] for collection [collection1meta] has occurred - updating... (live nodes size: [2])
[junit4] 2> 629402 INFO (zkCallback-2071-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDeleted path:/collections/collection1meta/state.json] for collection [collection1meta] has occurred - updating... (live nodes size: [2])
[junit4] 2> 629402 INFO (zkCallback-2085-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDeleted path:/collections/collection1meta/state.json] for collection [collection1meta] has occurred - updating... (live nodes size: [2])
[junit4] 2> 629402 INFO (zkCallback-2071-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDeleted path:/collections/collection1meta/state.json] for collection [collection1meta] has occurred - updating... (live nodes size: [2])
[junit4] 2> 629406 INFO (qtp1181888060-7132) [n:127.0.0.1:46331_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=collection1meta&action=DELETE&wt=javabin&version=2} status=0 QTime=118
[junit4] 2> 629419 INFO (TEST-AliasIntegrationTest.test-seed#[819CE69C519C3377]) [ ] o.a.s.SolrTestCaseJ4 ###Starting test
[junit4] 2> 629420 INFO (qtp1181888060-7136) [n:127.0.0.1:46331_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params collection.configName=conf&name=collection1&nrtReplicas=1&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 629421 INFO (OverseerThreadFactory-2316-thread-5-processing-n:127.0.0.1:46331_solr) [n:127.0.0.1:46331_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection collection1
[junit4] 2> 629421 INFO (OverseerCollectionConfigSetProcessor-72073745001545734-127.0.0.1:46331_solr-n_0000000000) [n:127.0.0.1:46331_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000008 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 629625 INFO (OverseerStateUpdate-72073745001545734-127.0.0.1:46331_solr-n_0000000000) [n:127.0.0.1:46331_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"collection1_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:32777/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 629632 INFO (OverseerStateUpdate-72073745001545734-127.0.0.1:46331_solr-n_0000000000) [n:127.0.0.1:46331_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"collection1_shard2_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:46331/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 629834 INFO (qtp1181888060-7138) [n:127.0.0.1:46331_solr x:collection1_shard2_replica_n2 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf&newCollection=true&name=collection1_shard2_replica_n2&action=CREATE&numShards=2&collection=collection1&shard=shard2&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 629834 INFO (qtp557875607-7135) [n:127.0.0.1:32777_solr x:collection1_shard1_replica_n1 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=collection1_shard1_replica_n1&action=CREATE&numShards=2&collection=collection1&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 630839 INFO (qtp1181888060-7138) [n:127.0.0.1:46331_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.3.0
[junit4] 2> 630841 INFO (qtp557875607-7135) [n:127.0.0.1:32777_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.3.0
[junit4] 2> 630845 INFO (qtp1181888060-7138) [n:127.0.0.1:46331_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.s.IndexSchema [collection1_shard2_replica_n2] Schema name=minimal
[junit4] 2> 630847 INFO (qtp1181888060-7138) [n:127.0.0.1:46331_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 630847 INFO (qtp1181888060-7138) [n:127.0.0.1:46331_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.CoreContainer Creating SolrCore 'collection1_shard2_replica_n2' using configuration from collection collection1, trusted=true
[junit4] 2> 630847 INFO (qtp1181888060-7138) [n:127.0.0.1:46331_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46331.solr.core.collection1.shard2.replica_n2' (registry 'solr.core.collection1.shard2.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@49f3576e
[junit4] 2> 630847 INFO (qtp1181888060-7138) [n:127.0.0.1:46331_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.SolrCore [[collection1_shard2_replica_n2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.AliasIntegrationTest_819CE69C519C3377-001/tempDir-001/node2/collection1_shard2_replica_n2], dataDir=[/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.AliasIntegrationTest_819CE69C519C3377-001/tempDir-001/node2/./collection1_shard2_replica_n2/data/]
[junit4] 2> 630847 INFO (qtp557875607-7135) [n:127.0.0.1:32777_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.s.IndexSchema [collection1_shard1_replica_n1] Schema name=minimal
[junit4] 2> 630849 INFO (qtp557875607-7135) [n:127.0.0.1:32777_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 630849 INFO (qtp557875607-7135) [n:127.0.0.1:32777_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.CoreContainer Creating SolrCore 'collection1_shard1_replica_n1' using configuration from collection collection1, trusted=true
[junit4] 2> 630849 INFO (qtp557875607-7135) [n:127.0.0.1:32777_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_32777.solr.core.collection1.shard1.replica_n1' (registry 'solr.core.collection1.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@49f3576e
[junit4] 2> 630849 INFO (qtp557875607-7135) [n:127.0.0.1:32777_solr c:collection1 s:shard1 r:core_node3 x:collection1_shar
[...truncated too long message...]
-Dtests.class="*.AliasIntegrationTest" -Dtests.showOutput=onerror "-Dargs=-XX:-UseCompressedOops -XX:+UseG1GC" -Dtests.seed=819CE69C519C3377 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=sg -Dtests.timezone=Indian/Mayotte -Dtests.asserts=true -Dtests.file.encoding=UTF-8
Buildfile: /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/core/build.xml
-clover.disable:
ivy-configure:
[ivy:configure] :: Apache Ivy 2.4.0 - 20141213170938 :: http://ant.apache.org/ivy/ ::
[ivy:configure] :: loading settings :: file = /home/jenkins/workspace/Lucene-Solr-8.x-Linux/lucene/top-level-ivy-settings.xml
install-junit4-taskdef:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
resolve-groovy:
[ivy:cachepath] :: resolving dependencies :: org.codehaus.groovy#groovy-all-caller;working
[ivy:cachepath] confs: [default]
[ivy:cachepath] found org.codehaus.groovy#groovy-all;2.4.16 in public
[ivy:cachepath] :: resolution report :: resolve 10ms :: artifacts dl 1ms
---------------------------------------------------------------------
| | modules || artifacts |
| conf | number| search|dwnlded|evicted|| number|dwnlded|
---------------------------------------------------------------------
| default | 1 | 0 | 0 | 0 || 1 | 0 |
---------------------------------------------------------------------
-init-totals:
-test:
[mkdir] Created dir: /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test
[junit4:pickseed] Seed property 'tests.seed' already defined: 819CE69C519C3377
[mkdir] Created dir: /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/temp
[junit4] <JUnit4> says ᐊᐃ! Master seed: 819CE69C519C3377
[junit4] Executing 5 suites with 3 JVMs.
[junit4]
[junit4] Started J0 PID(27157@serv1.sd-datasolutions.de).
[junit4] Started J2 PID(27156@serv1.sd-datasolutions.de).
[junit4] Started J1 PID(27155@serv1.sd-datasolutions.de).
[junit4] Suite: org.apache.solr.cloud.AliasIntegrationTest
[junit4] OK 5.74s J0 | AliasIntegrationTest.testModifyPropertiesV1
[junit4] OK 6.81s J0 | AliasIntegrationTest.test
[junit4] OK 3.84s J0 | AliasIntegrationTest.testProperties
[junit4] OK 3.73s J0 | AliasIntegrationTest.testModifyPropertiesV2
[junit4] OK 2.10s J0 | AliasIntegrationTest.testErrorChecks
[junit4] OK 14.0s J0 | AliasIntegrationTest.testDeleteOneOfTwoCollectionsAliased
[junit4] OK 4.05s J0 | AliasIntegrationTest.testModifyPropertiesCAR
[junit4] OK 11.0s J0 | AliasIntegrationTest.testDeleteAliasWithExistingCollectionName
[junit4] OK 3.72s J0 | AliasIntegrationTest.testClusterStateProviderAPI
[junit4] Completed [1/5] on J0 in 61.73s, 9 tests
[junit4]
[junit4] Suite: org.apache.solr.cloud.AliasIntegrationTest
[junit4] OK 5.56s J1 | AliasIntegrationTest.testModifyPropertiesV1
[junit4] OK 6.82s J1 | AliasIntegrationTest.test
[junit4] OK 3.87s J1 | AliasIntegrationTest.testProperties
[junit4] OK 3.73s J1 | AliasIntegrationTest.testModifyPropertiesV2
[junit4] OK 2.12s J1 | AliasIntegrationTest.testErrorChecks
[junit4] OK 14.0s J1 | AliasIntegrationTest.testDeleteOneOfTwoCollectionsAliased
[junit4] OK 3.93s J1 | AliasIntegrationTest.testModifyPropertiesCAR
[junit4] OK 10.9s J1 | AliasIntegrationTest.testDeleteAliasWithExistingCollectionName
[junit4] OK 4.42s J1 | AliasIntegrationTest.testClusterStateProviderAPI
[junit4] Completed [2/5] on J1 in 62.84s, 9 tests
[junit4]
[junit4] Suite: org.apache.solr.cloud.AliasIntegrationTest
[junit4] OK 5.46s J2 | AliasIntegrationTest.testModifyPropertiesV1
[junit4] OK 6.44s J2 | AliasIntegrationTest.test
[junit4] OK 3.89s J2 | AliasIntegrationTest.testProperties
[junit4] OK 3.70s J2 | AliasIntegrationTest.testModifyPropertiesV2
[junit4] OK 2.25s J2 | AliasIntegrationTest.testErrorChecks
[junit4] OK 13.9s J2 | AliasIntegrationTest.testDeleteOneOfTwoCollectionsAliased
[junit4] OK 4.24s J2 | AliasIntegrationTest.testModifyPropertiesCAR
[junit4] OK 10.8s J2 | AliasIntegrationTest.testDeleteAliasWithExistingCollectionName
[junit4] OK 4.63s J2 | AliasIntegrationTest.testClusterStateProviderAPI
[junit4] Completed [3/5] on J2 in 62.80s, 9 tests
[junit4]
[junit4] Suite: org.apache.solr.cloud.AliasIntegrationTest
[junit4] OK 4.38s J1 | AliasIntegrationTest.testModifyPropertiesV1
[junit4] OK 6.02s J1 | AliasIntegrationTest.test
[junit4] OK 4.39s J1 | AliasIntegrationTest.testProperties
[junit4] OK 4.98s J1 | AliasIntegrationTest.testModifyPropertiesV2
[junit4] OK 2.40s J1 | AliasIntegrationTest.testErrorChecks
[junit4] OK 14.0s J1 | AliasIntegrationTest.testDeleteOneOfTwoCollectionsAliased
[junit4] OK 3.74s J1 | AliasIntegrationTest.testModifyPropertiesCAR
[junit4] OK 10.7s J1 | AliasIntegrationTest.testDeleteAliasWithExistingCollectionName
[junit4] OK 3.69s J1 | AliasIntegrationTest.testClusterStateProviderAPI
[junit4] Completed [4/5] on J1 in 56.78s, 9 tests
[junit4]
[junit4] Suite: org.apache.solr.cloud.AliasIntegrationTest
[junit4] OK 4.02s J0 | AliasIntegrationTest.testModifyPropertiesV1
[junit4] OK 6.02s J0 | AliasIntegrationTest.test
[junit4] OK 4.39s J0 | AliasIntegrationTest.testProperties
[junit4] OK 5.02s J0 | AliasIntegrationTest.testModifyPropertiesV2
[junit4] OK 2.40s J0 | AliasIntegrationTest.testErrorChecks
[junit4] OK 14.0s J0 | AliasIntegrationTest.testDeleteOneOfTwoCollectionsAliased
[junit4] OK 3.72s J0 | AliasIntegrationTest.testModifyPropertiesCAR
[junit4] OK 10.7s J0 | AliasIntegrationTest.testDeleteAliasWithExistingCollectionName
[junit4] OK 3.72s J0 | AliasIntegrationTest.testClusterStateProviderAPI
[junit4] Completed [5/5] on J0 in 57.81s, 9 tests
[junit4]
[junit4] JVM J0: 0.72 .. 121.31 = 120.59s
[junit4] JVM J1: 0.74 .. 121.00 = 120.26s
[junit4] JVM J2: 0.74 .. 64.37 = 63.64s
[junit4] Execution time total: 2 minutes 1 second
[junit4] Tests summary: 5 suites, 45 tests
[junit4] Could not remove temporary path: /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J2 (java.nio.file.DirectoryNotEmptyException: Remaining files: [/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J2/temp])
[junit4] Could not remove temporary path: /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J1 (java.nio.file.DirectoryNotEmptyException: Remaining files: [/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J1/temp])
[junit4] Could not remove temporary path: /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J0 (java.nio.file.DirectoryNotEmptyException: Remaining files: [/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J0/temp])
[echo] 5 slowest tests:
[junit4:tophints] 259.38s | org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest
[junit4:tophints] 243.10s | org.apache.solr.cloud.TestStressLiveNodes
[junit4:tophints] 192.76s | org.apache.solr.cloud.api.collections.ShardSplitTest
[junit4:tophints] 117.63s | org.apache.solr.cloud.CollectionsAPISolrJTest
[junit4:tophints] 116.55s | org.apache.solr.update.SoftAutoCommitTest
-check-totals:
WARNING: An illegal reflective access operation has occurred
WARNING: Illegal reflective access by org.codehaus.groovy.reflection.CachedClass (file:/home/jenkins/.ivy2/cache/org.codehaus.groovy/groovy-all/jars/groovy-all-2.4.16.jar) to method java.lang.Object.finalize()
WARNING: Please consider reporting this to the maintainers of org.codehaus.groovy.reflection.CachedClass
WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
WARNING: All illegal access operations will be denied in a future release
test-nocompile:
BUILD SUCCESSFUL
Total time: 2 minutes 3 seconds
[repro] Failures:
[repro] 0/5 failed: org.apache.solr.cloud.AliasIntegrationTest
[repro] 5/5 failed: org.apache.lucene.util.TestOfflineSorter
[repro] Exiting with code 256
+ mv lucene/build lucene/build.repro
+ mv solr/build solr/build.repro
+ mv lucene/build.orig lucene/build
+ mv solr/build.orig solr/build
Archiving artifacts
Setting ANT_1_8_2_HOME=/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
[WARNINGS] Parsing warnings in console log with parser Java Compiler (javac)
Setting ANT_1_8_2_HOME=/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
No credentials specified
Setting ANT_1_8_2_HOME=/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
<Git Blamer> Using GitBlamer to create author and commit information for all warnings.
<Git Blamer> GIT_COMMIT=32da33936532a13523be522a8e86820c5bd9a497, workspace=/home/jenkins/workspace/Lucene-Solr-8.x-Linux
[WARNINGS] Computing warning deltas based on reference build #929
Recording test results
Setting ANT_1_8_2_HOME=/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Build step 'Publish JUnit test result report' changed build result to UNSTABLE
Email was triggered for: Unstable (Test Failures)
Sending email for trigger: Unstable (Test Failures)
Setting ANT_1_8_2_HOME=/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2