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 2018/04/01 23:22:23 UTC
[JENKINS] Lucene-Solr-7.x-Linux (64bit/jdk-9.0.4) - Build # 1631 -
Still Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Linux/1631/
Java: 64bit/jdk-9.0.4 -XX:+UseCompressedOops -XX:+UseParallelGC
1 tests failed.
FAILED: org.apache.solr.cloud.hdfs.HDFSCollectionsAPITest.testDataDirIsNotReused
Error Message:
null Live Nodes: [127.0.0.1:34345_solr, 127.0.0.1:35105_solr] Last available state: DocCollection(test//collections/test/state.json/5)={ "pullReplicas":"0", "replicationFactor":"1", "shards":{"shard1":{ "range":"80000000-7fffffff", "state":"active", "replicas":{"core_node2":{ "dataDir":"hdfs://localhost.localdomain:38129/data/test/core_node2/data/", "base_url":"https://127.0.0.1:34345/solr", "node_name":"127.0.0.1:34345_solr", "type":"NRT", "ulogDir":"hdfs://localhost.localdomain:38129/data/test/core_node2/data/tlog", "core":"test_shard1_replica_n1", "shared_storage":"true", "state":"down", "leader":"true"}}}}, "router":{"name":"compositeId"}, "maxShardsPerNode":"1", "autoAddReplicas":"false", "nrtReplicas":"1", "tlogReplicas":"0"}
Stack Trace:
java.lang.AssertionError:
null
Live Nodes: [127.0.0.1:34345_solr, 127.0.0.1:35105_solr]
Last available state: DocCollection(test//collections/test/state.json/5)={
"pullReplicas":"0",
"replicationFactor":"1",
"shards":{"shard1":{
"range":"80000000-7fffffff",
"state":"active",
"replicas":{"core_node2":{
"dataDir":"hdfs://localhost.localdomain:38129/data/test/core_node2/data/",
"base_url":"https://127.0.0.1:34345/solr",
"node_name":"127.0.0.1:34345_solr",
"type":"NRT",
"ulogDir":"hdfs://localhost.localdomain:38129/data/test/core_node2/data/tlog",
"core":"test_shard1_replica_n1",
"shared_storage":"true",
"state":"down",
"leader":"true"}}}},
"router":{"name":"compositeId"},
"maxShardsPerNode":"1",
"autoAddReplicas":"false",
"nrtReplicas":"1",
"tlogReplicas":"0"}
at __randomizedtesting.SeedInfo.seed([C2DFCCA168D328D7:DAC08ED57B8A8A70]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.SolrCloudTestCase.waitForState(SolrCloudTestCase.java:269)
at org.apache.solr.cloud.hdfs.HDFSCollectionsAPITest.testDataDirIsNotReused(HDFSCollectionsAPITest.java:90)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:564)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.base/java.lang.Thread.run(Thread.java:844)
Build Log:
[...truncated 1796 lines...]
[junit4] JVM J0: stdout was not empty, see: /home/jenkins/workspace/Lucene-Solr-7.x-Linux/lucene/build/core/test/temp/junit4-J0-20180401_221410_37414108589221762589529.sysout
[junit4] >>> JVM J0 emitted unexpected output (verbatim) ----
[junit4] codec: HighCompressionCompressingStoredFields, pf: Asserting, dvf: Direct
[junit4] <<< JVM J0: EOF ----
[...truncated 12702 lines...]
[junit4] Suite: org.apache.solr.cloud.hdfs.HDFSCollectionsAPITest
[junit4] 2> 1736056 INFO (SUITE-HDFSCollectionsAPITest-seed#[C2DFCCA168D328D7]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HDFSCollectionsAPITest_C2DFCCA168D328D7-001/init-core-data-001
[junit4] 2> 1736056 WARN (SUITE-HDFSCollectionsAPITest-seed#[C2DFCCA168D328D7]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=26 numCloses=26
[junit4] 2> 1736056 INFO (SUITE-HDFSCollectionsAPITest-seed#[C2DFCCA168D328D7]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 1736057 INFO (SUITE-HDFSCollectionsAPITest-seed#[C2DFCCA168D328D7]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason="", value=0.0/0.0, ssl=0.0/0.0, clientAuth=0.0/0.0)
[junit4] 2> 1736057 INFO (SUITE-HDFSCollectionsAPITest-seed#[C2DFCCA168D328D7]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HDFSCollectionsAPITest_C2DFCCA168D328D7-001/tempDir-001
[junit4] 2> 1736057 INFO (SUITE-HDFSCollectionsAPITest-seed#[C2DFCCA168D328D7]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 1736058 INFO (Thread-5379) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1736058 INFO (Thread-5379) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 1736059 ERROR (Thread-5379) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
[junit4] 2> 1736158 INFO (SUITE-HDFSCollectionsAPITest-seed#[C2DFCCA168D328D7]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:34001
[junit4] 2> 1736159 INFO (zkConnectionManagerCallback-11330-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1736161 INFO (jetty-launcher-11327-thread-1) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-22T08:27:37+11:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 1736161 INFO (jetty-launcher-11327-thread-2) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-22T08:27:37+11:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 1736162 INFO (jetty-launcher-11327-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1736162 INFO (jetty-launcher-11327-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1736162 INFO (jetty-launcher-11327-thread-1) [ ] o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 1736162 INFO (jetty-launcher-11327-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1736162 INFO (jetty-launcher-11327-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1736162 INFO (jetty-launcher-11327-thread-2) [ ] o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 1736162 INFO (jetty-launcher-11327-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@46bceb42{/solr,null,AVAILABLE}
[junit4] 2> 1736162 INFO (jetty-launcher-11327-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@5d24d7d8{/solr,null,AVAILABLE}
[junit4] 2> 1736164 INFO (jetty-launcher-11327-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1abbecd3{SSL,[ssl, http/1.1]}{127.0.0.1:34345}
[junit4] 2> 1736164 INFO (jetty-launcher-11327-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@284ec831{SSL,[ssl, http/1.1]}{127.0.0.1:35105}
[junit4] 2> 1736164 INFO (jetty-launcher-11327-thread-2) [ ] o.e.j.s.Server Started @1736204ms
[junit4] 2> 1736164 INFO (jetty-launcher-11327-thread-1) [ ] o.e.j.s.Server Started @1736204ms
[junit4] 2> 1736164 INFO (jetty-launcher-11327-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=35105}
[junit4] 2> 1736164 INFO (jetty-launcher-11327-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=34345}
[junit4] 2> 1736164 ERROR (jetty-launcher-11327-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1736164 ERROR (jetty-launcher-11327-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1736164 INFO (jetty-launcher-11327-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 1736164 INFO (jetty-launcher-11327-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 1736164 INFO (jetty-launcher-11327-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.4.0
[junit4] 2> 1736164 INFO (jetty-launcher-11327-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.4.0
[junit4] 2> 1736164 INFO (jetty-launcher-11327-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1736164 INFO (jetty-launcher-11327-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1736164 INFO (jetty-launcher-11327-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1736164 INFO (jetty-launcher-11327-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1736164 INFO (jetty-launcher-11327-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-04-01T23:05:50.937675Z
[junit4] 2> 1736164 INFO (jetty-launcher-11327-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-04-01T23:05:50.937682Z
[junit4] 2> 1736165 INFO (zkConnectionManagerCallback-11334-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1736165 INFO (zkConnectionManagerCallback-11333-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1736165 INFO (jetty-launcher-11327-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1736165 INFO (jetty-launcher-11327-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1736176 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x1000870486e0002, likely client has closed socket
[junit4] 2> 1736178 INFO (jetty-launcher-11327-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34001/solr
[junit4] 2> 1736178 INFO (jetty-launcher-11327-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34001/solr
[junit4] 2> 1736179 INFO (zkConnectionManagerCallback-11341-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1736179 INFO (zkConnectionManagerCallback-11342-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1736180 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x1000870486e0004, likely client has closed socket
[junit4] 2> 1736180 INFO (zkConnectionManagerCallback-11344-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1736180 INFO (zkConnectionManagerCallback-11346-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1736213 INFO (jetty-launcher-11327-thread-1) [n:127.0.0.1:35105_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1736213 INFO (jetty-launcher-11327-thread-1) [n:127.0.0.1:35105_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:35105_solr
[junit4] 2> 1736213 INFO (jetty-launcher-11327-thread-1) [n:127.0.0.1:35105_solr ] o.a.s.c.Overseer Overseer (id=72066872382455813-127.0.0.1:35105_solr-n_0000000000) starting
[junit4] 2> 1736213 INFO (jetty-launcher-11327-thread-2) [n:127.0.0.1:34345_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1736214 INFO (jetty-launcher-11327-thread-2) [n:127.0.0.1:34345_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34345_solr
[junit4] 2> 1736214 INFO (zkCallback-11343-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1736217 INFO (zkCallback-11345-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1736217 INFO (zkConnectionManagerCallback-11352-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1736217 INFO (jetty-launcher-11327-thread-1) [n:127.0.0.1:35105_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1736218 INFO (jetty-launcher-11327-thread-1) [n:127.0.0.1:35105_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:34001/solr ready
[junit4] 2> 1736219 INFO (jetty-launcher-11327-thread-1) [n:127.0.0.1:35105_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 1736219 INFO (jetty-launcher-11327-thread-1) [n:127.0.0.1:35105_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35105_solr
[junit4] 2> 1736220 INFO (zkCallback-11343-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1736220 INFO (zkCallback-11351-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1736220 INFO (zkCallback-11345-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1736317 INFO (jetty-launcher-11327-thread-2) [n:127.0.0.1:34345_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_34345.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5436eb9f
[junit4] 2> 1736322 INFO (jetty-launcher-11327-thread-2) [n:127.0.0.1:34345_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_34345.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5436eb9f
[junit4] 2> 1736322 INFO (jetty-launcher-11327-thread-2) [n:127.0.0.1:34345_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_34345.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5436eb9f
[junit4] 2> 1736323 INFO (jetty-launcher-11327-thread-2) [n:127.0.0.1:34345_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HDFSCollectionsAPITest_C2DFCCA168D328D7-001/tempDir-001/node2/.
[junit4] 2> 1736325 INFO (zkConnectionManagerCallback-11356-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1736326 INFO (jetty-launcher-11327-thread-2) [n:127.0.0.1:34345_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1736326 INFO (jetty-launcher-11327-thread-2) [n:127.0.0.1:34345_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:34001/solr ready
[junit4] 2> 1736405 INFO (jetty-launcher-11327-thread-1) [n:127.0.0.1:35105_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35105.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5436eb9f
[junit4] 2> 1736410 INFO (jetty-launcher-11327-thread-1) [n:127.0.0.1:35105_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35105.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5436eb9f
[junit4] 2> 1736410 INFO (jetty-launcher-11327-thread-1) [n:127.0.0.1:35105_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35105.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5436eb9f
[junit4] 2> 1736410 INFO (jetty-launcher-11327-thread-1) [n:127.0.0.1:35105_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HDFSCollectionsAPITest_C2DFCCA168D328D7-001/tempDir-001/node1/.
[junit4] 2> 1736423 INFO (zkConnectionManagerCallback-11358-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 1> Formatting using clusterid: testClusterID
[junit4] 2> 1736520 WARN (SUITE-HDFSCollectionsAPITest-seed#[C2DFCCA168D328D7]-worker) [ ] o.a.h.m.i.MetricsConfig Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
[junit4] 2> 1736524 WARN (SUITE-HDFSCollectionsAPITest-seed#[C2DFCCA168D328D7]-worker) [ ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
[junit4] 2> 1736525 INFO (SUITE-HDFSCollectionsAPITest-seed#[C2DFCCA168D328D7]-worker) [ ] o.m.log jetty-6.1.x
[junit4] 2> 1736530 INFO (SUITE-HDFSCollectionsAPITest-seed#[C2DFCCA168D328D7]-worker) [ ] o.m.log Extract jar:file:/home/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.7.4-tests.jar!/webapps/hdfs to ./temp/Jetty_localhost_localdomain_33197_hdfs____2akfpl/webapp
[junit4] 2> 1736592 INFO (SUITE-HDFSCollectionsAPITest-seed#[C2DFCCA168D328D7]-worker) [ ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost.localdomain:33197
[junit4] 2> 1736652 WARN (SUITE-HDFSCollectionsAPITest-seed#[C2DFCCA168D328D7]-worker) [ ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
[junit4] 2> 1736653 INFO (SUITE-HDFSCollectionsAPITest-seed#[C2DFCCA168D328D7]-worker) [ ] o.m.log jetty-6.1.x
[junit4] 2> 1736656 INFO (SUITE-HDFSCollectionsAPITest-seed#[C2DFCCA168D328D7]-worker) [ ] o.m.log Extract jar:file:/home/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.7.4-tests.jar!/webapps/datanode to ./temp/Jetty_localhost_39975_datanode____.entn8o/webapp
[junit4] 2> 1736722 INFO (SUITE-HDFSCollectionsAPITest-seed#[C2DFCCA168D328D7]-worker) [ ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:39975
[junit4] 2> 1736760 WARN (SUITE-HDFSCollectionsAPITest-seed#[C2DFCCA168D328D7]-worker) [ ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
[junit4] 2> 1736761 INFO (SUITE-HDFSCollectionsAPITest-seed#[C2DFCCA168D328D7]-worker) [ ] o.m.log jetty-6.1.x
[junit4] 2> 1736775 INFO (SUITE-HDFSCollectionsAPITest-seed#[C2DFCCA168D328D7]-worker) [ ] o.m.log Extract jar:file:/home/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.7.4-tests.jar!/webapps/datanode to ./temp/Jetty_localhost_37393_datanode____.cbnd2o/webapp
[junit4] 2> 1736835 ERROR (DataNode: [[[DISK]file:/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HDFSCollectionsAPITest_C2DFCCA168D328D7-001/tempDir-002/hdfsBaseDir/data/data1/, [DISK]file:/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HDFSCollectionsAPITest_C2DFCCA168D328D7-001/tempDir-002/hdfsBaseDir/data/data2/]] heartbeating to localhost.localdomain/127.0.0.1:38129) [ ] o.a.h.h.s.d.DirectoryScanner dfs.datanode.directoryscan.throttle.limit.ms.per.sec set to value below 1 ms/sec. Assuming default value of 1000
[junit4] 2> 1736839 INFO (Block report processor) [ ] BlockStateChange BLOCK* processReport 0x80c37bb5608d: from storage DS-1c89fde8-0808-47f4-a472-b8bac6df1b32 node DatanodeRegistration(127.0.0.1:36185, datanodeUuid=4a52578d-1e18-4c8f-bb8b-3b732b5a282d, infoPort=43305, infoSecurePort=0, ipcPort=36229, storageInfo=lv=-56;cid=testClusterID;nsid=2011659549;c=0), blocks: 0, hasStaleStorage: true, processing time: 0 msecs
[junit4] 2> 1736839 INFO (Block report processor) [ ] BlockStateChange BLOCK* processReport 0x80c37bb5608d: from storage DS-1376ce70-4b00-42c7-92ca-9e1ee7e0439d node DatanodeRegistration(127.0.0.1:36185, datanodeUuid=4a52578d-1e18-4c8f-bb8b-3b732b5a282d, infoPort=43305, infoSecurePort=0, ipcPort=36229, storageInfo=lv=-56;cid=testClusterID;nsid=2011659549;c=0), blocks: 0, hasStaleStorage: false, processing time: 0 msecs
[junit4] 2> 1736852 INFO (SUITE-HDFSCollectionsAPITest-seed#[C2DFCCA168D328D7]-worker) [ ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:37393
[junit4] 2> 1736947 ERROR (DataNode: [[[DISK]file:/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HDFSCollectionsAPITest_C2DFCCA168D328D7-001/tempDir-002/hdfsBaseDir/data/data3/, [DISK]file:/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HDFSCollectionsAPITest_C2DFCCA168D328D7-001/tempDir-002/hdfsBaseDir/data/data4/]] heartbeating to localhost.localdomain/127.0.0.1:38129) [ ] o.a.h.h.s.d.DirectoryScanner dfs.datanode.directoryscan.throttle.limit.ms.per.sec set to value below 1 ms/sec. Assuming default value of 1000
[junit4] 2> 1736952 INFO (Block report processor) [ ] BlockStateChange BLOCK* processReport 0x80c3826d0a09: from storage DS-f3acaa70-6655-418d-878a-e17aef9f84ad node DatanodeRegistration(127.0.0.1:42385, datanodeUuid=c2fdaa7d-60a6-4dc6-99e2-be4da8239958, infoPort=40545, infoSecurePort=0, ipcPort=34463, storageInfo=lv=-56;cid=testClusterID;nsid=2011659549;c=0), blocks: 0, hasStaleStorage: true, processing time: 0 msecs
[junit4] 2> 1736952 INFO (Block report processor) [ ] BlockStateChange BLOCK* processReport 0x80c3826d0a09: from storage DS-725e97ad-e26c-487d-9f86-dc5c8cbf685c node DatanodeRegistration(127.0.0.1:42385, datanodeUuid=c2fdaa7d-60a6-4dc6-99e2-be4da8239958, infoPort=40545, infoSecurePort=0, ipcPort=34463, storageInfo=lv=-56;cid=testClusterID;nsid=2011659549;c=0), blocks: 0, hasStaleStorage: false, processing time: 0 msecs
[junit4] 2> 1736974 INFO (zkConnectionManagerCallback-11362-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1736974 INFO (SUITE-HDFSCollectionsAPITest-seed#[C2DFCCA168D328D7]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1736975 INFO (SUITE-HDFSCollectionsAPITest-seed#[C2DFCCA168D328D7]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:34001/solr ready
[junit4] 2> 1737007 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testDataDirIsNotReused
[junit4] 2> 1737017 INFO (qtp1522650580-31683) [n:127.0.0.1:35105_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=conf1&name=test&nrtReplicas=1&action=CREATE&numShards=1&createNodeSet=127.0.0.1:34345_solr&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1737018 INFO (OverseerThreadFactory-8937-thread-1) [ ] o.a.s.c.a.c.CreateCollectionCmd Create collection test
[junit4] 2> 1737122 INFO (OverseerStateUpdate-72066872382455813-127.0.0.1:35105_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"test",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"test_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:34345/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 1737334 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf1&newCollection=true&name=test_shard1_replica_n1&action=CREATE&numShards=1&collection=test&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 1737334 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 1737437 INFO (zkCallback-11345-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test/state.json] for collection [test] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1737437 INFO (zkCallback-11345-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test/state.json] for collection [test] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1738341 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.4.0
[junit4] 2> 1738344 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.s.IndexSchema [test_shard1_replica_n1] Schema name=minimal
[junit4] 2> 1738345 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1738345 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'test_shard1_replica_n1' using configuration from collection test, trusted=true
[junit4] 2> 1738346 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_34345.solr.core.test.shard1.replica_n1' (registry 'solr.core.test.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5436eb9f
[junit4] 2> 1738346 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://localhost.localdomain:38129/data
[junit4] 2> 1738346 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
[junit4] 2> 1738346 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1738346 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.c.SolrCore [[test_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HDFSCollectionsAPITest_C2DFCCA168D328D7-001/tempDir-001/node2/test_shard1_replica_n1], dataDir=[hdfs://localhost.localdomain:38129/data/test/core_node2/data/]
[junit4] 2> 1738347 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://localhost.localdomain:38129/data/test/core_node2/data/snapshot_metadata
[junit4] 2> 1738354 WARN (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.s.h.HdfsDirectory The NameNode is in SafeMode - Solr will wait 5 seconds and try again.
[junit4] 2> 1743364 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://localhost.localdomain:38129/data/test/core_node2/data
[junit4] 2> 1743376 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://localhost.localdomain:38129/data/test/core_node2/data/index
[junit4] 2> 1743397 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:42385 is added to blk_1073741825_1001{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-1376ce70-4b00-42c7-92ca-9e1ee7e0439d:NORMAL:127.0.0.1:36185|RBW], ReplicaUC[[DISK]DS-f3acaa70-6655-418d-878a-e17aef9f84ad:NORMAL:127.0.0.1:42385|RBW]]} size 0
[junit4] 2> 1743398 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:36185 is added to blk_1073741825_1001 size 69
[junit4] 2> 1743898 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.HdfsUpdateLog
[junit4] 2> 1743898 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1743898 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.u.HdfsUpdateLog Initializing HdfsUpdateLog: tlogDfsReplication=3
[junit4] 2> 1743907 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1743907 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1743918 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5f1491f[test_shard1_replica_n1] main]
[junit4] 2> 1743918 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1743919 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1743919 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 1743920 INFO (searcherExecutor-8942-thread-1-processing-n:127.0.0.1:34345_solr x:test_shard1_replica_n1 c:test s:shard1 r:core_node2) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.c.SolrCore [test_shard1_replica_n1] Registered new searcher Searcher@5f1491f[test_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1743920 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1596586940110471168
[junit4] 2> 1743923 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.c.ZkShardTerms Successful update of terms at /collections/test/terms/shard1 to Terms{values={core_node2=0}, version=0}
[junit4] 2> 1743924 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 1743924 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 1743924 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:34345/solr/test_shard1_replica_n1/
[junit4] 2> 1743924 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 1743924 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.c.SyncStrategy https://127.0.0.1:34345/solr/test_shard1_replica_n1/ has no replicas
[junit4] 2> 1743924 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 1743925 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:34345/solr/test_shard1_replica_n1/ shard1
[junit4] 2> 1743926 INFO (zkCallback-11345-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test/state.json] for collection [test] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1743926 INFO (zkCallback-11345-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test/state.json] for collection [test] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1743975 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 1744011 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf1&newCollection=true&name=test_shard1_replica_n1&action=CREATE&numShards=1&collection=test&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=6677
[junit4] 2> 1744013 INFO (qtp1522650580-31683) [n:127.0.0.1:35105_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas
[junit4] 2> 1744078 INFO (zkCallback-11345-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test/state.json] for collection [test] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1744078 INFO (zkCallback-11345-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test/state.json] for collection [test] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1745015 INFO (qtp1522650580-31683) [n:127.0.0.1:35105_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=conf1&name=test&nrtReplicas=1&action=CREATE&numShards=1&createNodeSet=127.0.0.1:34345_solr&wt=javabin&version=2} status=0 QTime=7997
[junit4] 2> 1745020 INFO (OverseerCollectionConfigSetProcessor-72066872382455813-127.0.0.1:35105_solr-n_0000000000) [ ] 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> 1745021 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.c.ZkShardTerms Successful update of terms at /collections/test/terms/shard1 to Terms{values={core_node2=1}, version=1}
[junit4] 2> 1745030 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [test_shard1_replica_n1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1 (1596586941261807616)]} 0 12
[junit4] 2> 1745033 INFO (qtp1947424336-31684) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [test_shard1_replica_n1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2 (1596586941275439104)]} 0 1
[junit4] 2> 1745033 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1596586941277536256,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1745033 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@4fd2ec05 commitCommandVersion:1596586941277536256
[junit4] 2> 1745042 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:36185 is added to blk_1073741827_1003{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-f3acaa70-6655-418d-878a-e17aef9f84ad:NORMAL:127.0.0.1:42385|RBW], ReplicaUC[[DISK]DS-1c89fde8-0808-47f4-a472-b8bac6df1b32:NORMAL:127.0.0.1:36185|FINALIZED]]} size 0
[junit4] 2> 1745042 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:42385 is added to blk_1073741827_1003 size 200
[junit4] 2> 1745049 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:36185 is added to blk_1073741828_1004{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-725e97ad-e26c-487d-9f86-dc5c8cbf685c:NORMAL:127.0.0.1:42385|RBW], ReplicaUC[[DISK]DS-1376ce70-4b00-42c7-92ca-9e1ee7e0439d:NORMAL:127.0.0.1:36185|FINALIZED]]} size 0
[junit4] 2> 1745049 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:42385 is added to blk_1073741828_1004 size 69
[junit4] 2> 1745059 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:42385 is added to blk_1073741829_1005{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-1c89fde8-0808-47f4-a472-b8bac6df1b32:NORMAL:127.0.0.1:36185|RBW], ReplicaUC[[DISK]DS-f3acaa70-6655-418d-878a-e17aef9f84ad:NORMAL:127.0.0.1:42385|RBW]]} size 0
[junit4] 2> 1745059 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:36185 is added to blk_1073741829_1005 size 424
[junit4] 2> 1745069 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:42385 is added to blk_1073741830_1006{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-1c89fde8-0808-47f4-a472-b8bac6df1b32:NORMAL:127.0.0.1:36185|RBW], ReplicaUC[[DISK]DS-725e97ad-e26c-487d-9f86-dc5c8cbf685c:NORMAL:127.0.0.1:42385|FINALIZED]]} size 0
[junit4] 2> 1745069 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:36185 is added to blk_1073741830_1006 size 59
[junit4] 2> 1745075 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:42385 is added to blk_1073741831_1007{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-1c89fde8-0808-47f4-a472-b8bac6df1b32:NORMAL:127.0.0.1:36185|RBW], ReplicaUC[[DISK]DS-f3acaa70-6655-418d-878a-e17aef9f84ad:NORMAL:127.0.0.1:42385|FINALIZED]]} size 0
[junit4] 2> 1745075 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:36185 is added to blk_1073741831_1007 size 83
[junit4] 2> 1745082 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:36185 is added to blk_1073741832_1008{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-725e97ad-e26c-487d-9f86-dc5c8cbf685c:NORMAL:127.0.0.1:42385|RBW], ReplicaUC[[DISK]DS-1376ce70-4b00-42c7-92ca-9e1ee7e0439d:NORMAL:127.0.0.1:36185|FINALIZED]]} size 0
[junit4] 2> 1745082 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:42385 is added to blk_1073741832_1008 size 101
[junit4] 2> 1745088 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:42385 is added to blk_1073741833_1009{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-1c89fde8-0808-47f4-a472-b8bac6df1b32:NORMAL:127.0.0.1:36185|RBW], ReplicaUC[[DISK]DS-f3acaa70-6655-418d-878a-e17aef9f84ad:NORMAL:127.0.0.1:42385|FINALIZED]]} size 0
[junit4] 2> 1745088 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:36185 is added to blk_1073741833_1009{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-1c89fde8-0808-47f4-a472-b8bac6df1b32:NORMAL:127.0.0.1:36185|RBW], ReplicaUC[[DISK]DS-f3acaa70-6655-418d-878a-e17aef9f84ad:NORMAL:127.0.0.1:42385|FINALIZED]]} size 0
[junit4] 2> 1745096 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:42385 is added to blk_1073741834_1010{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-1376ce70-4b00-42c7-92ca-9e1ee7e0439d:NORMAL:127.0.0.1:36185|RBW], ReplicaUC[[DISK]DS-725e97ad-e26c-487d-9f86-dc5c8cbf685c:NORMAL:127.0.0.1:42385|FINALIZED]]} size 0
[junit4] 2> 1745097 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:36185 is added to blk_1073741834_1010 size 111
[junit4] 2> 1745097 WARN (DataStreamer for file /data/test/core_node2/data/index/_0.fdt block BP-1541870851-88.99.242.108-1522623951219:blk_1073741834_1010) [ ] o.a.h.h.DFSClient Caught exception
[junit4] 2> java.lang.InterruptedException: null
[junit4] 2> at java.lang.Object.wait(Native Method) ~[?:?]
[junit4] 2> at java.lang.Thread.join(Thread.java:1353) ~[?:?]
[junit4] 2> at java.lang.Thread.join(Thread.java:1427) ~[?:?]
[junit4] 2> at org.apache.hadoop.hdfs.DFSOutputStream$DataStreamer.closeResponder(DFSOutputStream.java:716) [hadoop-hdfs-2.7.4.jar:?]
[junit4] 2> at org.apache.hadoop.hdfs.DFSOutputStream$DataStreamer.closeInternal(DFSOutputStream.java:684) [hadoop-hdfs-2.7.4.jar:?]
[junit4] 2> at org.apache.hadoop.hdfs.DFSOutputStream$DataStreamer.run(DFSOutputStream.java:680) [hadoop-hdfs-2.7.4.jar:?]
[junit4] 2> 1745107 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:42385 is added to blk_1073741835_1011{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-1376ce70-4b00-42c7-92ca-9e1ee7e0439d:NORMAL:127.0.0.1:36185|RBW], ReplicaUC[[DISK]DS-f3acaa70-6655-418d-878a-e17aef9f84ad:NORMAL:127.0.0.1:42385|FINALIZED]]} size 0
[junit4] 2> 1745109 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:36185 is added to blk_1073741835_1011{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-f3acaa70-6655-418d-878a-e17aef9f84ad:NORMAL:127.0.0.1:42385|FINALIZED], ReplicaUC[[DISK]DS-1c89fde8-0808-47f4-a472-b8bac6df1b32:NORMAL:127.0.0.1:36185|FINALIZED]]} size 0
[junit4] 2> 1745119 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:36185 is added to blk_1073741836_1012{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-f3acaa70-6655-418d-878a-e17aef9f84ad:NORMAL:127.0.0.1:42385|RBW], ReplicaUC[[DISK]DS-1376ce70-4b00-42c7-92ca-9e1ee7e0439d:NORMAL:127.0.0.1:36185|FINALIZED]]} size 0
[junit4] 2> 1745119 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:42385 is added to blk_1073741836_1012 size 172
[junit4] 2> 1745139 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@60b4f29d[test_shard1_replica_n1] main]
[junit4] 2> 1745140 INFO (searcherExecutor-8942-thread-1-processing-n:127.0.0.1:34345_solr x:test_shard1_replica_n1 c:test s:shard1 r:core_node2) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.c.SolrCore [test_shard1_replica_n1] Registered new searcher Searcher@60b4f29d[test_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.4.0):C2)))}
[junit4] 2> 1745142 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:36185 is added to blk_1073741826_1002{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-725e97ad-e26c-487d-9f86-dc5c8cbf685c:NORMAL:127.0.0.1:42385|RBW], ReplicaUC[[DISK]DS-1376ce70-4b00-42c7-92ca-9e1ee7e0439d:NORMAL:127.0.0.1:36185|RBW]]} size 75
[junit4] 2> 1745142 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:42385 is added to blk_1073741826_1002 size 139
[junit4] 2> 1745142 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1745142 INFO (qtp1947424336-31681) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [test_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=test:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 109
[junit4] 2> 1745154 INFO (qtp1947424336-31684) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [test_shard1_replica_n1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[3 (1596586941392879616)]} 0 10
[junit4] 2> 1745155 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@1abbecd3{SSL,[ssl, http/1.1]}{127.0.0.1:0}
[junit4] 2> 1745155 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=164539855
[junit4] 2> 1745155 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 1745155 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@3bc6b011: rootName = solr_34345, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@1f7dcc23
[junit4] 2> 1745160 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 1745160 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@73cba932: rootName = solr_34345, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@34e60a53
[junit4] 2> 1745163 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 1745163 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@2d5c44f3: rootName = solr_34345, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@2cc19187
[junit4] 2> 1745164 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:34345_solr
[junit4] 2> 1745164 INFO (zkCallback-11355-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 1745164 INFO (zkCallback-11351-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 1745164 INFO (zkCallback-11345-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 1745164 INFO (zkCallback-11343-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 1745164 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 1745164 INFO (zkCallback-11361-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 1745165 INFO (coreCloseExecutor-8947-thread-1) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.c.SolrCore [test_shard1_replica_n1] CLOSING SolrCore org.apache.solr.core.SolrCore@3eb44963
[junit4] 2> 1745165 INFO (coreCloseExecutor-8947-thread-1) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.test.shard1.replica_n1, tag=1052002659
[junit4] 2> 1745165 INFO (coreCloseExecutor-8947-thread-1) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@6e2815da: rootName = solr_34345, domain = solr.core.test.shard1.replica_n1, service url = null, agent id = null] for registry solr.core.test.shard1.replica_n1 / com.codahale.metrics.MetricRegistry@3be5678
[junit4] 2> 1745170 INFO (coreCloseExecutor-8947-thread-1) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.test.shard1.leader, tag=1052002659
[junit4] 2> 1745175 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:36185 is added to blk_1073741837_1013{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-f3acaa70-6655-418d-878a-e17aef9f84ad:NORMAL:127.0.0.1:42385|RBW], ReplicaUC[[DISK]DS-1c89fde8-0808-47f4-a472-b8bac6df1b32:NORMAL:127.0.0.1:36185|RBW]]} size 75
[junit4] 2> 1745175 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:42385 is added to blk_1073741837_1013{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-f3acaa70-6655-418d-878a-e17aef9f84ad:NORMAL:127.0.0.1:42385|RBW], ReplicaUC[[DISK]DS-1c89fde8-0808-47f4-a472-b8bac6df1b32:NORMAL:127.0.0.1:36185|RBW]]} size 75
[junit4] 2> 1745176 INFO (coreCloseExecutor-8947-thread-1) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.s.h.HdfsDirectory Closing hdfs directory hdfs://localhost.localdomain:38129/data/test/core_node2/data/snapshot_metadata
[junit4] 2> 1745176 INFO (coreCloseExecutor-8947-thread-1) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.s.h.HdfsDirectory Closing hdfs directory hdfs://localhost.localdomain:38129/data/test/core_node2/data
[junit4] 2> 1745176 INFO (coreCloseExecutor-8947-thread-1) [n:127.0.0.1:34345_solr c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.s.h.HdfsDirectory Closing hdfs directory hdfs://localhost.localdomain:38129/data/test/core_node2/data/index
[junit4] 2> 1745177 ERROR (OldIndexDirectoryCleanupThreadForCore-test_shard1_replica_n1) [ ] o.a.s.c.HdfsDirectoryFactory Error checking for old index directories to clean-up.
[junit4] 2> java.io.IOException: Filesystem closed
[junit4] 2> at org.apache.hadoop.hdfs.DFSClient.checkOpen(DFSClient.java:808) ~[hadoop-hdfs-2.7.4.jar:?]
[junit4] 2> at org.apache.hadoop.hdfs.DFSClient.listPaths(DFSClient.java:2083) ~[hadoop-hdfs-2.7.4.jar:?]
[junit4] 2> at org.apache.hadoop.hdfs.DFSClient.listPaths(DFSClient.java:2069) ~[hadoop-hdfs-2.7.4.jar:?]
[junit4] 2> at org.apache.hadoop.hdfs.DistributedFileSystem.listStatusInternal(DistributedFileSystem.java:791) ~[hadoop-hdfs-2.7.4.jar:?]
[junit4] 2> at org.apache.hadoop.hdfs.DistributedFileSystem.access$700(DistributedFileSystem.java:106) ~[hadoop-hdfs-2.7.4.jar:?]
[junit4] 2> at org.apache.hadoop.hdfs.DistributedFileSystem$18.doCall(DistributedFileSystem.java:853) ~[hadoop-hdfs-2.7.4.jar:?]
[junit4] 2> at org.apache.hadoop.hdfs.DistributedFileSystem$18.doCall(DistributedFileSystem.java:849) ~[hadoop-hdfs-2.7.4.jar:?]
[junit4] 2> at org.apache.hadoop.fs.FileSystemLinkResolver.resolve(FileSystemLinkResolver.java:81) ~[hadoop-common-2.7.4.jar:?]
[junit4] 2> at org.apache.hadoop.hdfs.DistributedFileSystem.listStatus(DistributedFileSystem.java:860) ~[hadoop-hdfs-2.7.4.jar:?]
[junit4] 2> at org.apache.hadoop.fs.FileSystem.listStatus(FileSystem.java:1517) ~[hadoop-common-2.7.4.jar:?]
[junit4] 2> at org.apache.hadoop.fs.FileSystem.listStatus(FileSystem.java:1557) ~[hadoop-common-2.7.4.jar:?]
[junit4] 2> at org.apache.solr.core.HdfsDirectoryFactory.cleanupOldIndexDirectories(HdfsDirectoryFactory.java:529) [java/:?]
[junit4] 2> at org.apache.solr.core.SolrCore.lambda$cleanupOldIndexDirectories$21(SolrCore.java:3037) [java/:?]
[junit4] 2> at java.lang.Thread.run(Thread.java:844) [?:?]
[junit4] 2> 1745178 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@5d24d7d8{/solr,null,UNAVAILABLE}
[junit4] 2> 1745178 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 1745265 INFO (zkCallback-11361-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test/state.json] for collection [test] has occurred - updating... (live nodes size: [1])
[junit4] 2> 1745265 INFO (zkCallback-11361-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test/state.json] for collection [test] has occurred - updating... (live nodes size: [1])
[junit4] 2> 1745265 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=test&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1745266 INFO (OverseerThreadFactory-8937-thread-2) [ ] o.a.s.c.a.c.OverseerCollectionMessageHandler Executing Collection Cmd=action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true, asyncId=null
[junit4] 2> 1745972 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=test&action=DELETE&wt=javabin&version=2} status=0 QTime=706
[junit4] 2> 1745973 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-22T08:27:37+11:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 1745973 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1745973 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1745973 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [ ] o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 1745974 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@2b21ac18{/solr,null,AVAILABLE}
[junit4] 2> 1745974 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@645c1423{SSL,[ssl, http/1.1]}{127.0.0.1:34345}
[junit4] 2> 1745974 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [ ] o.e.j.s.Server Started @1746014ms
[junit4] 2> 1745974 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=34345}
[junit4] 2> 1745974 ERROR (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1745974 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 1745974 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.4.0
[junit4] 2> 1745974 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1745974 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1745974 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-04-01T23:06:00.747821Z
[junit4] 2> 1745975 INFO (zkConnectionManagerCallback-11364-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1745975 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1745980 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34001/solr
[junit4] 2> 1745980 INFO (zkConnectionManagerCallback-11368-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1745982 INFO (zkConnectionManagerCallback-11370-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1745985 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [n:127.0.0.1:34345_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1745985 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [n:127.0.0.1:34345_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1745987 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [n:127.0.0.1:34345_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 1745987 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [n:127.0.0.1:34345_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34345_solr
[junit4] 2> 1745988 INFO (zkCallback-11343-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1745988 INFO (zkCallback-11361-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1745988 INFO (zkCallback-11351-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1745992 INFO (zkCallback-11369-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1746082 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [n:127.0.0.1:34345_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_34345.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5436eb9f
[junit4] 2> 1746089 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [n:127.0.0.1:34345_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_34345.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5436eb9f
[junit4] 2> 1746089 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [n:127.0.0.1:34345_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_34345.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5436eb9f
[junit4] 2> 1746090 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [n:127.0.0.1:34345_solr ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HDFSCollectionsAPITest_C2DFCCA168D328D7-001/tempDir-001/node2/.
[junit4] 2> 1746090 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [n:127.0.0.1:34345_solr ] o.a.s.c.CorePropertiesLocator Cores are: [test_shard1_replica_n1]
[junit4] 2> 1746092 INFO (zkConnectionManagerCallback-11375-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1746092 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [n:127.0.0.1:34345_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1746092 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [n:127.0.0.1:34345_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:34001/solr ready
[junit4] 2> 1747267 INFO (OverseerCollectionConfigSetProcessor-72066872382455813-127.0.0.1:35105_solr-n_0000000000) [ ] 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> 1756092 ERROR (coreContainerWorkExecutor-8950-thread-1-processing-n:127.0.0.1:34345_solr) [n:127.0.0.1:34345_solr ] o.a.s.c.CoreContainer Error waiting for SolrCore to be loaded on startup
[junit4] 2> org.apache.solr.cloud.ZkController$NotInClusterStateException: coreNodeName core_node2 does not exist in shard shard1, ignore the exception if the replica was deleted
[junit4] 2> at org.apache.solr.cloud.ZkController.checkStateInZk(ZkController.java:1739) ~[java/:?]
[junit4] 2> at org.apache.solr.cloud.ZkController.preRegister(ZkController.java:1637) ~[java/:?]
[junit4] 2> at org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1033) ~[java/:?]
[junit4] 2> at org.apache.solr.core.CoreContainer.lambda$load$13(CoreContainer.java:640) ~[java/:?]
[junit4] 2> at com.codahale.metrics.InstrumentedExecutorService$InstrumentedCallable.call(InstrumentedExecutorService.java:197) ~[metrics-core-3.2.2.jar:3.2.2]
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:192) [java/:?]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167) [?:?]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641) [?:?]
[junit4] 2> at java.lang.Thread.run(Thread.java:844) [?:?]
[junit4] 2> 1756100 INFO (qtp1660765665-32038) [n:127.0.0.1:34345_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=conf1&name=test&nrtReplicas=1&action=CREATE&numShards=1&createNodeSet=127.0.0.1:35105_solr&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1756102 INFO (OverseerThreadFactory-8937-thread-3) [ ] o.a.s.c.a.c.CreateCollectionCmd Create collection test
[junit4] 2> 1756206 INFO (OverseerStateUpdate-72066872382455813-127.0.0.1:35105_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"test",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"test_shard1_replica_n3",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:35105/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 1756409 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf1&newCollection=true&name=test_shard1_replica_n3&action=CREATE&numShards=1&collection=test&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 1756511 INFO (zkCallback-11343-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test/state.json] for collection [test] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1756511 INFO (zkCallback-11343-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test/state.json] for collection [test] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1757423 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.4.0
[junit4] 2> 1757428 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.s.IndexSchema [test_shard1_replica_n3] Schema name=minimal
[junit4] 2> 1757429 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1757429 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.c.CoreContainer Creating SolrCore 'test_shard1_replica_n3' using configuration from collection test, trusted=true
[junit4] 2> 1757429 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35105.solr.core.test.shard1.replica_n3' (registry 'solr.core.test.shard1.replica_n3') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5436eb9f
[junit4] 2> 1757430 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://localhost.localdomain:38129/data
[junit4] 2> 1757430 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
[junit4] 2> 1757430 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1757430 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.c.SolrCore [[test_shard1_replica_n3] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HDFSCollectionsAPITest_C2DFCCA168D328D7-001/tempDir-001/node1/test_shard1_replica_n3], dataDir=[hdfs://localhost.localdomain:38129/data/test/core_node4/data/]
[junit4] 2> 1757431 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://localhost.localdomain:38129/data/test/core_node4/data/snapshot_metadata
[junit4] 2> 1757443 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://localhost.localdomain:38129/data/test/core_node4/data
[junit4] 2> 1757458 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://localhost.localdomain:38129/data/test/core_node4/data/index
[junit4] 2> 1757479 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:42385 is added to blk_1073741838_1014{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-1376ce70-4b00-42c7-92ca-9e1ee7e0439d:NORMAL:127.0.0.1:36185|RBW], ReplicaUC[[DISK]DS-725e97ad-e26c-487d-9f86-dc5c8cbf685c:NORMAL:127.0.0.1:42385|RBW]]} size 0
[junit4] 2> 1757479 INFO (Block report processor) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:36185 is added to blk_1073741838_1014{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-1376ce70-4b00-42c7-92ca-9e1ee7e0439d:NORMAL:127.0.0.1:36185|RBW], ReplicaUC[[DISK]DS-725e97ad-e26c-487d-9f86-dc5c8cbf685c:NORMAL:127.0.0.1:42385|RBW]]} size 0
[junit4] 2> 1757512 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.HdfsUpdateLog
[junit4] 2> 1757512 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1757512 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.u.HdfsUpdateLog Initializing HdfsUpdateLog: tlogDfsReplication=3
[junit4] 2> 1757519 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1757519 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1757528 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.s.SolrIndexSearcher Opening [Searcher@678a5f52[test_shard1_replica_n3] main]
[junit4] 2> 1757529 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1757529 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1757530 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 1757531 INFO (searcherExecutor-8955-thread-1-processing-n:127.0.0.1:35105_solr x:test_shard1_replica_n3 c:test s:shard1 r:core_node4) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.c.SolrCore [test_shard1_replica_n3] Registered new searcher Searcher@678a5f52[test_shard1_replica_n3] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1757531 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1596586954382639104
[junit4] 2> 1757534 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.c.ZkShardTerms Successful update of terms at /collections/test/terms/shard1 to Terms{values={core_node4=0}, version=0}
[junit4] 2> 1757535 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 1757535 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 1757535 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:35105/solr/test_shard1_replica_n3/
[junit4] 2> 1757535 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 1757535 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.c.SyncStrategy https://127.0.0.1:35105/solr/test_shard1_replica_n3/ has no replicas
[junit4] 2> 1757535 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 1757536 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:35105/solr/test_shard1_replica_n3/ shard1
[junit4] 2> 1757637 INFO (zkCallback-11343-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test/state.json] for collection [test] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1757637 INFO (zkCallback-11343-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test/state.json] for collection [test] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1757686 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 1757692 INFO (qtp1522650580-31680) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf1&newCollection=true&name=test_shard1_replica_n3&action=CREATE&numShards=1&collection=test&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1283
[junit4] 2> 1757693 INFO (qtp1660765665-32038) [n:127.0.0.1:34345_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas
[junit4] 2> 1757788 INFO (zkCallback-11343-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test/state.json] for collection [test] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1757788 INFO (zkCallback-11343-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test/state.json] for collection [test] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1758103 INFO (OverseerCollectionConfigSetProcessor-72066872382455813-127.0.0.1:35105_solr-n_0000000000) [ ] 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> 1758695 INFO (qtp1660765665-32038) [n:127.0.0.1:34345_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=conf1&name=test&nrtReplicas=1&action=CREATE&numShards=1&createNodeSet=127.0.0.1:35105_solr&wt=javabin&version=2} status=0 QTime=2594
[junit4] 2> 1848696 INFO (TEST-HDFSCollectionsAPITest.testDataDirIsNotReused-seed#[C2DFCCA168D328D7]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testDataDirIsNotReused
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=HDFSCollectionsAPITest -Dtests.method=testDataDirIsNotReused -Dtests.seed=C2DFCCA168D328D7 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=mn-MN -Dtests.timezone=Asia/Yangon -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] FAILURE 112s J0 | HDFSCollectionsAPITest.testDataDirIsNotReused <<<
[junit4] > Throwable #1: java.lang.AssertionError:
[junit4] > null
[junit4] > Live Nodes: [127.0.0.1:34345_solr, 127.0.0.1:35105_solr]
[junit4] > Last available state: DocCollection(test//collections/test/state.json/5)={
[junit4] > "pullReplicas":"0",
[junit4] > "replicationFactor":"1",
[junit4] > "shards":{"shard1":{
[junit4] > "range":"80000000-7fffffff",
[junit4] > "state":"active",
[junit4] > "replicas":{"core_node2":{
[junit4] > "dataDir":"hdfs://localhost.localdomain:38129/data/test/core_node2/data/",
[junit4] > "base_url":"https://127.0.0.1:34345/solr",
[junit4] > "node_name":"127.0.0.1:34345_solr",
[junit4] > "type":"NRT",
[junit4] > "ulogDir":"hdfs://localhost.localdomain:38129/data/test/core_node2/data/tlog",
[junit4] > "core":"test_shard1_replica_n1",
[junit4] > "shared_storage":"true",
[junit4] > "state":"down",
[junit4] > "leader":"true"}}}},
[junit4] > "router":{"name":"compositeId"},
[junit4] > "maxShardsPerNode":"1",
[junit4] > "autoAddReplicas":"false",
[junit4] > "nrtReplicas":"1",
[junit4] > "tlogReplicas":"0"}
[junit4] > at __randomizedtesting.SeedInfo.seed([C2DFCCA168D328D7:DAC08ED57B8A8A70]:0)
[junit4] > at org.apache.solr.cloud.SolrCloudTestCase.waitForState(SolrCloudTestCase.java:269)
[junit4] > at org.apache.solr.cloud.hdfs.HDFSCollectionsAPITest.testDataDirIsNotReused(HDFSCollectionsAPITest.java:90)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] > at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] > at java.base/java.lang.reflect.Method.invoke(Method.java:564)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 1848717 INFO (jetty-closer-11328-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@645c1423{SSL,[ssl, http/1.1]}{127.0.0.1:34345}
[junit4] 2> 1848733 INFO (jetty-closer-11328-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=209651689
[junit4] 2> 1848733 INFO (jetty-closer-11328-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 1848733 INFO (jetty-closer-11328-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@67848890: rootName = solr_34345, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@fe6d26a
[junit4] 2> 1848733 INFO (jetty-closer-11328-thread-2) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@284ec831{SSL,[ssl, http/1.1]}{127.0.0.1:0}
[junit4] 2> 1848734 INFO (jetty-closer-11328-thread-2) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1064615061
[junit4] 2> 1848734 INFO (jetty-closer-11328-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 1848734 INFO (jetty-closer-11328-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@5a60bd53: rootName = solr_35105, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@4c173e6f
[junit4] 2> 1848765 INFO (jetty-closer-11328-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 1848765 INFO (jetty-closer-11328-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@164b84f4: rootName = solr_35105, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@34e60a53
[junit4] 2> 1848775 INFO (jetty-closer-11328-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 1848775 INFO (jetty-closer-11328-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@2cc34186: rootName = solr_34345, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@34e60a53
[junit4] 2> 1848777 INFO (jetty-closer-11328-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 1848777 INFO (jetty-closer-11328-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@6f1ffac0: rootName = solr_35105, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@2cc19187
[junit4] 2> 1848781 INFO (jetty-closer-11328-thread-2) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:35105_solr
[junit4] 2> 1848782 INFO (jetty-closer-11328-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 1848785 INFO (jetty-closer-11328-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 1848785 INFO (jetty-closer-11328-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@2171c67e: rootName = solr_34345, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@2cc19187
[junit4] 2> 1848785 INFO (zkCallback-11343-thread-4) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test/state.json] for collection [test] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1848786 INFO (zkCallback-11343-thread-6) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test/state.json] for collection [test] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1848786 INFO (jetty-closer-11328-thread-1) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:34345_solr
[junit4] 2> 1848786 INFO (jetty-closer-11328-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 1848793 INFO (zkCallback-11374-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (0)
[junit4] 2> 1848800 INFO (zkCallback-11351-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (0)
[junit4] 2> 1848806 INFO (zkCallback-11369-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (0)
[junit4] 2> 1848808 INFO (coreCloseExecutor-8960-thread-1) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.c.SolrCore [test_shard1_replica_n3] CLOSING SolrCore org.apache.solr.core.SolrCore@37c690bc
[junit4] 2> 1848808 INFO (coreCloseExecutor-8960-thread-1) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.test.shard1.replica_n3, tag=935760060
[junit4] 2> 1848808 INFO (coreCloseExecutor-8960-thread-1) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@33e09920: rootName = solr_35105, domain = solr.core.test.shard1.replica_n3, service url = null, agent id = null] for registry solr.core.test.shard1.replica_n3 / com.codahale.metrics.MetricRegistry@42516343
[junit4] 2> 1848816 INFO (coreCloseExecutor-8960-thread-1) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.test.shard1.leader, tag=935760060
[junit4] 2> 1848826 INFO (jetty-closer-11328-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@2b21ac18{/solr,null,UNAVAILABLE}
[junit4] 2> 1848827 INFO (jetty-closer-11328-thread-1) [ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 1848828 INFO (zkCallback-11343-thread-7) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (0)
[junit4] 2> 1848879 INFO (coreCloseExecutor-8960-thread-1) [n:127.0.0.1:35105_solr c:test s:shard1 r:core_node4 x:test_shard1_replica_n3] o.a.s.s.h.HdfsDirectory Closing hdfs direct
[...truncated too long message...]
ionsAPITest-seed#[C2DFCCA168D328D7]-worker) [ ] o.m.log Stopped HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:0
[junit4] 2> 1849890 WARN (DataNode: [[[DISK]file:/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HDFSCollectionsAPITest_C2DFCCA168D328D7-001/tempDir-002/hdfsBaseDir/data/data1/, [DISK]file:/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HDFSCollectionsAPITest_C2DFCCA168D328D7-001/tempDir-002/hdfsBaseDir/data/data2/]] heartbeating to localhost.localdomain/127.0.0.1:38129) [ ] o.a.h.h.s.d.IncrementalBlockReportManager IncrementalBlockReportManager interrupted
[junit4] 2> 1849890 WARN (DataNode: [[[DISK]file:/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HDFSCollectionsAPITest_C2DFCCA168D328D7-001/tempDir-002/hdfsBaseDir/data/data1/, [DISK]file:/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HDFSCollectionsAPITest_C2DFCCA168D328D7-001/tempDir-002/hdfsBaseDir/data/data2/]] heartbeating to localhost.localdomain/127.0.0.1:38129) [ ] o.a.h.h.s.d.DataNode Ending block pool service for: Block pool BP-1541870851-88.99.242.108-1522623951219 (Datanode Uuid 4a52578d-1e18-4c8f-bb8b-3b732b5a282d) service to localhost.localdomain/127.0.0.1:38129
[junit4] 2> 1849894 INFO (SUITE-HDFSCollectionsAPITest-seed#[C2DFCCA168D328D7]-worker) [ ] o.m.log Stopped HttpServer2$SelectChannelConnectorWithSafeStartup@localhost.localdomain:0
[junit4] 2> 1850011 INFO (SUITE-HDFSCollectionsAPITest-seed#[C2DFCCA168D328D7]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:34001 34001
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HDFSCollectionsAPITest_C2DFCCA168D328D7-001
[junit4] 2> Apr 01, 2018 11:07:44 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 66 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {id=PostingsFormat(name=Memory)}, docValues:{}, maxPointsInLeafNode=1077, maxMBSortInHeap=6.307783938874064, sim=RandomSimilarity(queryNorm=true): {}, locale=mn-MN, timezone=Asia/Yangon
[junit4] 2> NOTE: Linux 4.13.0-37-generic amd64/Oracle Corporation 9.0.4 (64-bit)/cpus=8,threads=1,free=279656072,total=516947968
[junit4] 2> NOTE: All tests run in this JVM: [FullSolrCloudDistribCmdsTest, SearchRateTriggerTest, TestJsonFacetRefinement, TestMinMaxOnMultiValuedField, DistributedFacetPivotWhiteBoxTest, DistributedExpandComponentTest, TestConfigSetsAPIZkFailure, SuggesterWFSTTest, TestUseDocValuesAsStored2, TestIndexSearcher, TestSQLHandler, DistributedFacetPivotLongTailTest, TestMultiValuedNumericRangeQuery, TestIndexingPerformance, TestCloudPseudoReturnFields, SolrCoreCheckLockOnStartupTest, StatsComponentTest, TestCSVResponseWriter, TestNumericTokenStream, TestSolrCloudSnapshots, TestDistribIDF, SynonymTokenizerTest, TestRetrieveFieldsOptimizer, TestSimpleTextCodec, DirectUpdateHandlerTest, TestNamedUpdateProcessors, TestCollectionsAPIViaSolrCloudCluster, TestCoreAdminApis, HLLSerializationTest, CollectionStateFormat2Test, TriLevelCompositeIdRoutingTest, TestRebalanceLeaders, MetricUtilsTest, NodeMarkersRegistrationTest, TestGroupingSearch, V2StandaloneTest, MetricsConfigTest, TestSubQueryTransformer, BlockCacheTest, SolrIndexMetricsTest, ChaosMonkeyNothingIsSafeTest, BlockJoinFacetSimpleTest, DeleteStatusTest, CollectionTooManyReplicasTest, TestUninvertingReader, TestSolrConfigHandlerConcurrent, SecurityConfHandlerTest, TestManagedResource, TestIBSimilarityFactory, TestCloudInspectUtil, TestManagedSchemaThreadSafety, AtomicUpdateProcessorFactoryTest, HttpPartitionTest, ZkShardTermsTest, TestRandomFaceting, TestStandardQParsers, TestWriterPerf, MoveReplicaTest, HdfsSyncSliceTest, TestIntervalFaceting, TestFieldCache, CdcrBidirectionalTest, TestJsonRequest, OpenExchangeRatesOrgProviderTest, UUIDFieldTest, TestSort, TestRuleBasedAuthorizationPlugin, TestBinaryField, ClassificationUpdateProcessorIntegrationTest, ResponseBuilderTest, TestReplicationHandlerBackup, BooleanFieldTest, TestGeoJSONResponseWriter, TestOnReconnectListenerSupport, TestRemoteStreaming, TestStressLucene, TestLegacyFieldCache, ZkSolrClientTest, TestUnifiedSolrHighlighter, NodeAddedTriggerTest, CursorPagingTest, TestDistributedSearch, TestImpersonationWithHadoopAuth, ShardRoutingTest, InfoHandlerTest, WrapperMergePolicyFactoryTest, EchoParamsTest, SolrCLIZkUtilsTest, ChaosMonkeyNothingIsSafeWithPullReplicasTest, CreateRoutedAliasTest, TestOmitPositions, TestManagedSynonymFilterFactory, MergeStrategyTest, TestNestedDocsSort, TestFieldTypeCollectionResource, ConfigSetsAPITest, TestLeaderInitiatedRecoveryThread, TestSolr4Spatial2, TestLRUStatsCache, TestExtendedDismaxParser, OverseerTaskQueueTest, TestDocSet, SolrPluginUtilsTest, TestSerializedLuceneMatchVersion, TestAddFieldRealTimeGet, TriggerCooldownIntegrationTest, CoreAdminOperationTest, ExitableDirectoryReaderTest, TestOverriddenPrefixQueryForCustomFieldType, SolrGraphiteReporterTest, TestCustomStream, SolrIndexConfigTest, ExecutePlanActionTest, TestSchemalessBufferedUpdates, HdfsRecoverLeaseTest, TestReRankQParserPlugin, TestJoin, BitVectorTest, TestCrossCoreJoin, TestTolerantUpdateProcessorRandomCloud, PreAnalyzedUpdateProcessorTest, TestHalfAndHalfDocValues, SpellCheckCollatorWithCollapseTest, ConnectionReuseTest, ZkNodePropsTest, DocumentAnalysisRequestHandlerTest, TestClusterStateProvider, DocExpirationUpdateProcessorFactoryTest, TestBulkSchemaAPI, ChaosMonkeySafeLeaderTest, UnloadDistributedZkTest, OpenCloseCoreStressTest, OverseerTest, TestFaceting, TestHashPartitioner, DistributedSpellCheckComponentTest, TestRealTimeGet, DistributedTermsComponentTest, TestCoreContainer, SimpleFacetsTest, SolrCoreTest, BadIndexSchemaTest, TestLazyCores, TestBadConfig, HighlighterTest, ShowFileRequestHandlerTest, DistributedQueryElevationComponentTest, TestCoreDiscovery, SolrRequestParserTest, TestTrie, TestCSVLoader, NoCacheHeaderTest, FieldMutatingUpdateProcessorTest, QueryEqualityTest, SortByFunctionTest, DocValuesMultiTest, TestSolrDeletionPolicy1, DebugComponentTest, CacheHeaderTest, LukeRequestHandlerTest, TestReversedWildcardFilterFactory, FileBasedSpellCheckerTest, XmlUpdateRequestHandlerTest, RequestHandlersTest, DocumentBuilderTest, TermVectorComponentTest, FieldAnalysisRequestHandlerTest, IndexSchemaRuntimeFieldTest, TestJmxIntegration, BinaryUpdateRequestHandlerTest, TestPHPSerializedResponseWriter, CSVRequestHandlerTest, TestComponentsName, HighlighterConfigTest, SOLR749Test, UpdateParamsTest, AlternateDirectoryTest, TestSolrIndexConfig, TestQuerySenderNoQuery, ResponseLogComponentTest, TestMergePolicyConfig, SampleTest, MinimalSchemaTest, TestElisionMultitermQuery, TestConfig, OutputWriterTest, TestFuzzyAnalyzedSuggestions, ExternalFileFieldSortTest, TestPostingsSolrHighlighter, DirectSolrConnectionTest, TestLuceneMatchVersion, TestPhraseSuggestions, TestXIncludeConfig, TestLMDirichletSimilarityFactory, TestLMJelinekMercerSimilarityFactory, TestBM25SimilarityFactory, TestFastWriter, TimeZoneUtilsTest, ResourceLoaderTest, TestFastOutputStream, ScriptEngineTest, URLClassifyProcessorTest, PluginInfoTest, TestFastLRUCache, DateMathParserTest, TestSystemIdResolver, TestSuggestSpellingConverter, SpellingQueryConverterTest, RAMDirectoryFactoryTest, TestSolrJ, TestUtils, TestDocumentBuilder, SystemInfoHandlerTest, FileUtilsTest, SolrTestCaseJ4Test, TestHighlightDedupGrouping, TestEmbeddedSolrServerAdminHandler, TestEmbeddedSolrServerConstructors, TestEmbeddedSolrServerSchemaAPI, TestJettySolrRunner, ActionThrottleTest, AddReplicaTest, CleanupOldIndexTest, DeleteNodeTest, DeleteShardTest, DistribCursorPagingTest, DistribJoinFromCollectionTest, DocValuesNotIndexedTest, ForceLeaderTest, HttpPartitionOnCommitTest, LeaderVoteWaitTimeoutTest, MissingSegmentRecoveryTest, MoveReplicaHDFSFailoverTest, PeerSyncReplicationTest, RemoteQueryErrorTest, TestCloudDeleteByQuery, TestCloudRecovery, TestPullReplica, TestSSLRandomization, TestSizeLimitedDistributedMap, TestSkipOverseerOperations, TestStressLiveNodes, TestTolerantUpdateProcessorCloud, VMParamsZkACLAndCredentialsProvidersTest, ConcurrentDeleteAndCreateCollectionTest, ShardSplitTest, AutoAddReplicasPlanActionTest, AutoScalingHandlerTest, NodeAddedTriggerIntegrationTest, ScheduledTriggerIntegrationTest, SearchRateTriggerIntegrationTest, SystemLogListenerTest, HDFSCollectionsAPITest]
[junit4] Completed [689/794 (1!)] on J0 in 123.05s, 1 test, 1 failure <<< FAILURES!
[...truncated 43153 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Linux/1631/consoleText
[repro] Revision: a2fcb8c9ed4a8e7fd0c23829c089573558a987f0
[repro] Ant options: "-Dargs=-XX:+UseCompressedOops -XX:+UseParallelGC"
[repro] Repro line: ant test -Dtestcase=HDFSCollectionsAPITest -Dtests.method=testDataDirIsNotReused -Dtests.seed=C2DFCCA168D328D7 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=mn-MN -Dtests.timezone=Asia/Yangon -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[repro] ant clean
[...truncated 6 lines...]
[repro] Test suites by module:
[repro] solr/core
[repro] HDFSCollectionsAPITest
[repro] ant compile-test
[...truncated 3319 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.HDFSCollectionsAPITest" -Dtests.showOutput=onerror "-Dargs=-XX:+UseCompressedOops -XX:+UseParallelGC" -Dtests.seed=C2DFCCA168D328D7 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=mn-MN -Dtests.timezone=Asia/Yangon -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[...truncated 76 lines...]
[repro] Failures:
[repro] 0/5 failed: org.apache.solr.cloud.hdfs.HDFSCollectionsAPITest
[repro] Exiting with code 0
[...truncated 40 lines...]