Build: https://builds.apache.org/job/Lucene-Solr-Tests-master/2307/

3 tests failed.
FAILED:  
org.apache.solr.cloud.autoscaling.HdfsAutoAddReplicasIntegrationTest.testSimple

Error Message:
Waiting for collection testSimple1 null Live Nodes: [127.0.0.1:36009_solr, 
127.0.0.1:44350_solr] Last available state: 
DocCollection(testSimple1//collections/testSimple1/state.json/17)={   
"pullReplicas":"0",   "replicationFactor":"2",   "shards":{     "shard1":{      
 "range":"80000000-ffffffff",       "state":"active",       "replicas":{        
 "core_node2":{           
"dataDir":"hdfs://localhost:36294/data/testSimple1/core_node2/data/",           
"base_url":"http://127.0.0.1:44350/solr";,           
"node_name":"127.0.0.1:44350_solr",           "type":"NRT",           
"ulogDir":"hdfs://localhost:36294/data/testSimple1/core_node2/data/tlog",       
    "core":"testSimple1_shard1_replica_n1",           "shared_storage":"true",  
         "state":"active"},         "core_node6":{           
"dataDir":"hdfs://localhost:36294/data/testSimple1/core_node6/data/",           
"base_url":"http://127.0.0.1:44350/solr";,           
"node_name":"127.0.0.1:44350_solr",           "type":"NRT",           
"ulogDir":"hdfs://localhost:36294/data/testSimple1/core_node6/data/tlog",       
    "core":"testSimple1_shard1_replica_n3",           "shared_storage":"true",  
         "state":"active",           "leader":"true"}}},     "shard2":{       
"range":"0-7fffffff",       "state":"active",       "replicas":{         
"core_node7":{           
"dataDir":"hdfs://localhost:36294/data/testSimple1/core_node7/data/",           
"base_url":"http://127.0.0.1:33278/solr";,           
"node_name":"127.0.0.1:33278_solr",           "type":"NRT",           
"ulogDir":"hdfs://localhost:36294/data/testSimple1/core_node7/data/tlog",       
    "core":"testSimple1_shard2_replica_n4",           "shared_storage":"true",  
         "state":"down"},         "core_node8":{           
"dataDir":"hdfs://localhost:36294/data/testSimple1/core_node8/data/",           
"base_url":"http://127.0.0.1:44350/solr";,           
"node_name":"127.0.0.1:44350_solr",           "type":"NRT",           
"ulogDir":"hdfs://localhost:36294/data/testSimple1/core_node8/data/tlog",       
    "core":"testSimple1_shard2_replica_n5",           "shared_storage":"true",  
         "state":"active",           "leader":"true"}}}},   
"router":{"name":"compositeId"},   "maxShardsPerNode":"2",   
"autoAddReplicas":"true",   "nrtReplicas":"2",   "tlogReplicas":"0"}

Stack Trace:
java.lang.AssertionError: Waiting for collection testSimple1
null
Live Nodes: [127.0.0.1:36009_solr, 127.0.0.1:44350_solr]
Last available state: 
DocCollection(testSimple1//collections/testSimple1/state.json/17)={
  "pullReplicas":"0",
  "replicationFactor":"2",
  "shards":{
    "shard1":{
      "range":"80000000-ffffffff",
      "state":"active",
      "replicas":{
        "core_node2":{
          "dataDir":"hdfs://localhost:36294/data/testSimple1/core_node2/data/",
          "base_url":"http://127.0.0.1:44350/solr";,
          "node_name":"127.0.0.1:44350_solr",
          "type":"NRT",
          
"ulogDir":"hdfs://localhost:36294/data/testSimple1/core_node2/data/tlog",
          "core":"testSimple1_shard1_replica_n1",
          "shared_storage":"true",
          "state":"active"},
        "core_node6":{
          "dataDir":"hdfs://localhost:36294/data/testSimple1/core_node6/data/",
          "base_url":"http://127.0.0.1:44350/solr";,
          "node_name":"127.0.0.1:44350_solr",
          "type":"NRT",
          
"ulogDir":"hdfs://localhost:36294/data/testSimple1/core_node6/data/tlog",
          "core":"testSimple1_shard1_replica_n3",
          "shared_storage":"true",
          "state":"active",
          "leader":"true"}}},
    "shard2":{
      "range":"0-7fffffff",
      "state":"active",
      "replicas":{
        "core_node7":{
          "dataDir":"hdfs://localhost:36294/data/testSimple1/core_node7/data/",
          "base_url":"http://127.0.0.1:33278/solr";,
          "node_name":"127.0.0.1:33278_solr",
          "type":"NRT",
          
"ulogDir":"hdfs://localhost:36294/data/testSimple1/core_node7/data/tlog",
          "core":"testSimple1_shard2_replica_n4",
          "shared_storage":"true",
          "state":"down"},
        "core_node8":{
          "dataDir":"hdfs://localhost:36294/data/testSimple1/core_node8/data/",
          "base_url":"http://127.0.0.1:44350/solr";,
          "node_name":"127.0.0.1:44350_solr",
          "type":"NRT",
          
"ulogDir":"hdfs://localhost:36294/data/testSimple1/core_node8/data/tlog",
          "core":"testSimple1_shard2_replica_n5",
          "shared_storage":"true",
          "state":"active",
          "leader":"true"}}}},
  "router":{"name":"compositeId"},
  "maxShardsPerNode":"2",
  "autoAddReplicas":"true",
  "nrtReplicas":"2",
  "tlogReplicas":"0"}
        at 
__randomizedtesting.SeedInfo.seed([B2B0A5BDC44833E9:8A038143E3BBE738]:0)
        at org.junit.Assert.fail(Assert.java:93)
        at 
org.apache.solr.cloud.SolrCloudTestCase.waitForState(SolrCloudTestCase.java:269)
        at 
org.apache.solr.cloud.autoscaling.AutoAddReplicasIntegrationTest.testSimple(AutoAddReplicasIntegrationTest.java:103)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at 
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        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 
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.lang.Thread.run(Thread.java:748)


FAILED:  org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testCooldown

Error Message:


Stack Trace:
java.lang.AssertionError
        at 
__randomizedtesting.SeedInfo.seed([B2B0A5BDC44833E9:830EC859BAE2461B]:0)
        at org.junit.Assert.fail(Assert.java:92)
        at org.junit.Assert.assertTrue(Assert.java:43)
        at org.junit.Assert.assertTrue(Assert.java:54)
        at 
org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testCooldown(TriggerIntegrationTest.java:1177)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at 
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        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 
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.lang.Thread.run(Thread.java:748)


FAILED:  org.apache.solr.handler.admin.AutoscalingHistoryHandlerTest.testHistory

Error Message:
expected:<5> but was:<0>

Stack Trace:
java.lang.AssertionError: expected:<5> but was:<0>
        at 
__randomizedtesting.SeedInfo.seed([B2B0A5BDC44833E9:DF4C01407E00CCEE]:0)
        at org.junit.Assert.fail(Assert.java:93)
        at org.junit.Assert.failNotEquals(Assert.java:647)
        at org.junit.Assert.assertEquals(Assert.java:128)
        at org.junit.Assert.assertEquals(Assert.java:472)
        at org.junit.Assert.assertEquals(Assert.java:456)
        at 
org.apache.solr.handler.admin.AutoscalingHistoryHandlerTest.testHistory(AutoscalingHistoryHandlerTest.java:244)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at 
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        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 
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.lang.Thread.run(Thread.java:748)




Build Log:
[...truncated 12165 lines...]
   [junit4] Suite: 
org.apache.solr.cloud.autoscaling.HdfsAutoAddReplicasIntegrationTest
   [junit4]   2> Creating dataDir: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.HdfsAutoAddReplicasIntegrationTest_B2B0A5BDC44833E9-001/init-core-data-001
   [junit4]   2> 2781 WARN  
(SUITE-HdfsAutoAddReplicasIntegrationTest-seed#[B2B0A5BDC44833E9]-worker) [    
] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=1 numCloses=1
   [junit4]   2> 2782 INFO  
(SUITE-HdfsAutoAddReplicasIntegrationTest-seed#[B2B0A5BDC44833E9]-worker) [    
] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) 
w/NUMERIC_DOCVALUES_SYSPROP=false
   [junit4]   2> 2784 INFO  
(SUITE-HdfsAutoAddReplicasIntegrationTest-seed#[B2B0A5BDC44833E9]-worker) [    
] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: 
@org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
   [junit4]   2> 2785 INFO  
(SUITE-HdfsAutoAddReplicasIntegrationTest-seed#[B2B0A5BDC44833E9]-worker) [    
] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: 
test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> 2791 INFO  
(SUITE-HdfsAutoAddReplicasIntegrationTest-seed#[B2B0A5BDC44833E9]-worker) [    
] o.a.s.c.MiniSolrCloudCluster Starting cluster of 3 servers in 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.HdfsAutoAddReplicasIntegrationTest_B2B0A5BDC44833E9-001/tempDir-001
   [junit4]   2> 2799 INFO  
(SUITE-HdfsAutoAddReplicasIntegrationTest-seed#[B2B0A5BDC44833E9]-worker) [    
] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 2801 INFO  (Thread-2) [    ] o.a.s.c.ZkTestServer client 
port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 2802 INFO  (Thread-2) [    ] o.a.s.c.ZkTestServer Starting 
server
   [junit4]   2> 2900 INFO  
(SUITE-HdfsAutoAddReplicasIntegrationTest-seed#[B2B0A5BDC44833E9]-worker) [    
] o.a.s.c.ZkTestServer start zk server on port:37934
   [junit4]   2> 2971 WARN  (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [    ] 
o.a.z.s.NIOServerCnxn Exception causing close of session 0x0: ZooKeeperServer 
not running
   [junit4]   2> 3027 ERROR (Thread-2) [    ] 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> 4728 INFO  (zkConnectionManagerCallback-12-thread-1) [    ] 
o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 4943 INFO  (jetty-launcher-9-thread-2) [    ] o.e.j.s.Server 
jetty-9.4.8.v20171121, build timestamp: 2017-11-21T19:27:37-02:00, git hash: 
82b8fb23f757335bb3329d540ce37a2a2615f0a8
   [junit4]   2> 4943 INFO  (jetty-launcher-9-thread-1) [    ] o.e.j.s.Server 
jetty-9.4.8.v20171121, build timestamp: 2017-11-21T19:27:37-02:00, git hash: 
82b8fb23f757335bb3329d540ce37a2a2615f0a8
   [junit4]   2> 4943 INFO  (jetty-launcher-9-thread-3) [    ] o.e.j.s.Server 
jetty-9.4.8.v20171121, build timestamp: 2017-11-21T19:27:37-02:00, git hash: 
82b8fb23f757335bb3329d540ce37a2a2615f0a8
   [junit4]   2> 4964 INFO  (jetty-launcher-9-thread-3) [    ] o.e.j.s.session 
DefaultSessionIdManager workerName=node0
   [junit4]   2> 4964 INFO  (jetty-launcher-9-thread-3) [    ] o.e.j.s.session 
No SessionScavenger set, using defaults
   [junit4]   2> 4968 INFO  (jetty-launcher-9-thread-3) [    ] o.e.j.s.session 
Scavenging every 660000ms
   [junit4]   2> 4984 INFO  (jetty-launcher-9-thread-1) [    ] o.e.j.s.session 
DefaultSessionIdManager workerName=node0
   [junit4]   2> 4992 INFO  (jetty-launcher-9-thread-1) [    ] o.e.j.s.session 
No SessionScavenger set, using defaults
   [junit4]   2> 4992 INFO  (jetty-launcher-9-thread-1) [    ] o.e.j.s.session 
Scavenging every 600000ms
   [junit4]   2> 4998 INFO  (jetty-launcher-9-thread-2) [    ] o.e.j.s.session 
DefaultSessionIdManager workerName=node0
   [junit4]   2> 4998 INFO  (jetty-launcher-9-thread-2) [    ] o.e.j.s.session 
No SessionScavenger set, using defaults
   [junit4]   2> 4998 INFO  (jetty-launcher-9-thread-2) [    ] o.e.j.s.session 
Scavenging every 600000ms
   [junit4]   2> 5001 INFO  (jetty-launcher-9-thread-1) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@4dcda159{/solr,null,AVAILABLE}
   [junit4]   2> 5005 INFO  (jetty-launcher-9-thread-2) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@199637d2{/solr,null,AVAILABLE}
   [junit4]   2> 5002 INFO  (jetty-launcher-9-thread-3) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@79e365d7{/solr,null,AVAILABLE}
   [junit4]   2> 5025 INFO  (jetty-launcher-9-thread-1) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@1765a595{HTTP/1.1,[http/1.1]}{127.0.0.1:33278}
   [junit4]   2> 5025 INFO  (jetty-launcher-9-thread-1) [    ] o.e.j.s.Server 
Started @7224ms
   [junit4]   2> 5026 INFO  (jetty-launcher-9-thread-2) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@3ae0f1d6{HTTP/1.1,[http/1.1]}{127.0.0.1:44350}
   [junit4]   2> 5026 INFO  (jetty-launcher-9-thread-2) [    ] o.e.j.s.Server 
Started @7225ms
   [junit4]   2> 5026 INFO  (jetty-launcher-9-thread-2) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=44350}
   [junit4]   2> 5026 INFO  (jetty-launcher-9-thread-1) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=33278}
   [junit4]   2> 5025 INFO  (jetty-launcher-9-thread-3) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@7f6ea03d{HTTP/1.1,[http/1.1]}{127.0.0.1:36009}
   [junit4]   2> 5027 INFO  (jetty-launcher-9-thread-3) [    ] o.e.j.s.Server 
Started @7226ms
   [junit4]   2> 5035 INFO  (jetty-launcher-9-thread-3) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=36009}
   [junit4]   2> 5044 ERROR (jetty-launcher-9-thread-1) [    ] 
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 5044 INFO  (jetty-launcher-9-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 
8.0.0
   [junit4]   2> 5044 INFO  (jetty-launcher-9-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 5044 INFO  (jetty-launcher-9-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 5046 ERROR (jetty-launcher-9-thread-3) [    ] 
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 5046 INFO  (jetty-launcher-9-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 
8.0.0
   [junit4]   2> 5054 INFO  (jetty-launcher-9-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 5054 INFO  (jetty-launcher-9-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 5054 ERROR (jetty-launcher-9-thread-2) [    ] 
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 5054 INFO  (jetty-launcher-9-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 
8.0.0
   [junit4]   2> 5055 INFO  (jetty-launcher-9-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 5055 INFO  (jetty-launcher-9-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 5059 INFO  (jetty-launcher-9-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2018-02-10T20:34:35.265Z
   [junit4]   2> 5060 INFO  (jetty-launcher-9-thread-3) [    ] 
o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find 
system property or JNDI)
   [junit4]   2> 5060 INFO  (jetty-launcher-9-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2018-02-10T20:34:35.266Z
   [junit4]   2> 5061 INFO  (jetty-launcher-9-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2018-02-10T20:34:35.257Z
   [junit4]   2> 5076 INFO  (zkConnectionManagerCallback-14-thread-1) [    ] 
o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 5086 INFO  (zkConnectionManagerCallback-16-thread-1) [    ] 
o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 5104 INFO  (jetty-launcher-9-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 5105 INFO  (jetty-launcher-9-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 5119 INFO  (zkConnectionManagerCallback-18-thread-1) [    ] 
o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 5134 INFO  (jetty-launcher-9-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 5182 INFO  (jetty-launcher-9-thread-2) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37934/solr
   [junit4]   2> 5198 INFO  (jetty-launcher-9-thread-1) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37934/solr
   [junit4]   2> 5210 INFO  (zkConnectionManagerCallback-22-thread-1) [    ] 
o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 5222 INFO  (jetty-launcher-9-thread-3) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37934/solr
   [junit4]   2> 5220 INFO  (zkConnectionManagerCallback-26-thread-1) [    ] 
o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 5246 INFO  (zkConnectionManagerCallback-30-thread-1) [    ] 
o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 5282 INFO  
(zkConnectionManagerCallback-32-thread-1-processing-n:127.0.0.1:33278_solr) 
[n:127.0.0.1:33278_solr    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 5282 INFO  
(zkConnectionManagerCallback-34-thread-1-processing-n:127.0.0.1:44350_solr) 
[n:127.0.0.1:44350_solr    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 5293 INFO  
(zkConnectionManagerCallback-36-thread-1-processing-n:127.0.0.1:36009_solr) 
[n:127.0.0.1:36009_solr    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 5642 INFO  (jetty-launcher-9-thread-2) [n:127.0.0.1:44350_solr 
   ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 5642 INFO  (jetty-launcher-9-thread-1) [n:127.0.0.1:33278_solr 
   ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 5649 INFO  (jetty-launcher-9-thread-3) [n:127.0.0.1:36009_solr 
   ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 5649 INFO  (jetty-launcher-9-thread-1) [n:127.0.0.1:33278_solr 
   ] o.a.s.c.OverseerElectionContext I am going to be the leader 
127.0.0.1:33278_solr
   [junit4]   2> 5656 INFO  (jetty-launcher-9-thread-2) [n:127.0.0.1:44350_solr 
   ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:44350_solr
   [junit4]   2> 5658 INFO  (jetty-launcher-9-thread-3) [n:127.0.0.1:36009_solr 
   ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:36009_solr
   [junit4]   2> 5666 INFO  (jetty-launcher-9-thread-1) [n:127.0.0.1:33278_solr 
   ] o.a.s.c.Overseer Overseer 
(id=73273076056260615-127.0.0.1:33278_solr-n_0000000000) starting
   [junit4]   2> 5739 INFO  
(zkCallback-31-thread-1-processing-n:127.0.0.1:33278_solr) 
[n:127.0.0.1:33278_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (2)
   [junit4]   2> 5746 INFO  
(zkCallback-35-thread-1-processing-n:127.0.0.1:36009_solr) 
[n:127.0.0.1:36009_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (2)
   [junit4]   2> 5746 INFO  
(zkCallback-33-thread-1-processing-n:127.0.0.1:44350_solr) 
[n:127.0.0.1:44350_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (2)
   [junit4]   2> 5852 INFO  (jetty-launcher-9-thread-1) [n:127.0.0.1:33278_solr 
   ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:33278_solr
   [junit4]   2> 5855 INFO  
(zkCallback-35-thread-1-processing-n:127.0.0.1:36009_solr) 
[n:127.0.0.1:36009_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 5855 INFO  
(zkCallback-33-thread-1-processing-n:127.0.0.1:44350_solr) 
[n:127.0.0.1:44350_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 5855 INFO  
(zkCallback-31-thread-1-processing-n:127.0.0.1:33278_solr) 
[n:127.0.0.1:33278_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 6042 DEBUG 
(OverseerAutoScalingTriggerThread-73273076056260615-127.0.0.1:33278_solr-n_0000000000)
 [n:127.0.0.1:33278_solr    ] o.a.s.c.a.OverseerTriggerThread Adding 
.autoAddReplicas trigger
   [junit4]   2> 6054 DEBUG 
(OverseerAutoScalingTriggerThread-73273076056260615-127.0.0.1:33278_solr-n_0000000000)
 [n:127.0.0.1:33278_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 1
   [junit4]   2> 6097 DEBUG 
(OverseerAutoScalingTriggerThread-73273076056260615-127.0.0.1:33278_solr-n_0000000000)
 [n:127.0.0.1:33278_solr    ] o.a.s.c.a.NodeLostTrigger Initial livenodes: 
[127.0.0.1:33278_solr, 127.0.0.1:36009_solr, 127.0.0.1:44350_solr]
   [junit4]   2> 6097 DEBUG 
(OverseerAutoScalingTriggerThread-73273076056260615-127.0.0.1:33278_solr-n_0000000000)
 [n:127.0.0.1:33278_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 1, lastZnodeVersion -1
   [junit4]   2> 6097 DEBUG 
(OverseerAutoScalingTriggerThread-73273076056260615-127.0.0.1:33278_solr-n_0000000000)
 [n:127.0.0.1:33278_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 1
   [junit4]   2> 6100 INFO  (jetty-launcher-9-thread-3) [n:127.0.0.1:36009_solr 
   ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36009.solr.node' 
(registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@5cc83a41
   [junit4]   2> 6101 INFO  (jetty-launcher-9-thread-3) [n:127.0.0.1:36009_solr 
   ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36009.solr.jvm' 
(registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@5cc83a41
   [junit4]   2> 6101 INFO  (jetty-launcher-9-thread-3) [n:127.0.0.1:36009_solr 
   ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36009.solr.jetty' 
(registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@5cc83a41
   [junit4]   2> 6102 INFO  (jetty-launcher-9-thread-2) [n:127.0.0.1:44350_solr 
   ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44350.solr.node' 
(registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@5cc83a41
   [junit4]   2> 6103 INFO  (jetty-launcher-9-thread-2) [n:127.0.0.1:44350_solr 
   ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44350.solr.jvm' 
(registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@5cc83a41
   [junit4]   2> 6103 INFO  (jetty-launcher-9-thread-2) [n:127.0.0.1:44350_solr 
   ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44350.solr.jetty' 
(registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@5cc83a41
   [junit4]   2> 6105 DEBUG 
(OverseerAutoScalingTriggerThread-73273076056260615-127.0.0.1:33278_solr-n_0000000000)
 [n:127.0.0.1:33278_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeAdded markers
   [junit4]   2> 6106 DEBUG 
(OverseerAutoScalingTriggerThread-73273076056260615-127.0.0.1:33278_solr-n_0000000000)
 [n:127.0.0.1:33278_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 1, lastZnodeVersion 1
   [junit4]   2> 6107 DEBUG (ScheduledTrigger-26-thread-1) 
[n:127.0.0.1:33278_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
.auto_add_replicas with currently live nodes: 3
   [junit4]   2> 6126 INFO  (jetty-launcher-9-thread-1) [n:127.0.0.1:33278_solr 
   ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_33278.solr.node' 
(registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@5cc83a41
   [junit4]   2> 6126 INFO  (jetty-launcher-9-thread-1) [n:127.0.0.1:33278_solr 
   ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_33278.solr.jvm' 
(registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@5cc83a41
   [junit4]   2> 6126 INFO  (jetty-launcher-9-thread-1) [n:127.0.0.1:33278_solr 
   ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_33278.solr.jetty' 
(registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@5cc83a41
   [junit4]   2> 6129 INFO  (jetty-launcher-9-thread-2) [n:127.0.0.1:44350_solr 
   ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.HdfsAutoAddReplicasIntegrationTest_B2B0A5BDC44833E9-001/tempDir-001/node2/.
   [junit4]   2> 6143 INFO  (jetty-launcher-9-thread-3) [n:127.0.0.1:36009_solr 
   ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.HdfsAutoAddReplicasIntegrationTest_B2B0A5BDC44833E9-001/tempDir-001/node3/.
   [junit4]   2> 6144 INFO  (jetty-launcher-9-thread-1) [n:127.0.0.1:33278_solr 
   ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.HdfsAutoAddReplicasIntegrationTest_B2B0A5BDC44833E9-001/tempDir-001/node1/.
   [junit4]   2> 6317 INFO  (zkConnectionManagerCallback-44-thread-1) [    ] 
o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 6327 INFO  (zkConnectionManagerCallback-48-thread-1) [    ] 
o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 6330 INFO  
(SUITE-HdfsAutoAddReplicasIntegrationTest-seed#[B2B0A5BDC44833E9]-worker) [    
] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
   [junit4]   2> 6332 INFO  
(SUITE-HdfsAutoAddReplicasIntegrationTest-seed#[B2B0A5BDC44833E9]-worker) [    
] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:37934/solr ready
   [junit4]   2> 6801 WARN  
(SUITE-HdfsAutoAddReplicasIntegrationTest-seed#[B2B0A5BDC44833E9]-worker) [    
] o.a.h.u.NativeCodeLoader Unable to load native-hadoop library for your 
platform... using builtin-java classes where applicable
   [junit4]   1> Formatting using clusterid: testClusterID
   [junit4]   2> 7122 DEBUG (ScheduledTrigger-26-thread-1) 
[n:127.0.0.1:33278_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
.auto_add_replicas with currently live nodes: 3
   [junit4]   2> 7441 WARN  
(SUITE-HdfsAutoAddReplicasIntegrationTest-seed#[B2B0A5BDC44833E9]-worker) [    
] o.a.h.m.i.MetricsConfig Cannot locate configuration: tried 
hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
   [junit4]   2> 7578 INFO  
(SUITE-HdfsAutoAddReplicasIntegrationTest-seed#[B2B0A5BDC44833E9]-worker) [    
] o.m.log Logging to org.slf4j.impl.Log4jLoggerAdapter(org.mortbay.log) via 
org.mortbay.log.Slf4jLog
   [junit4]   2> 7598 WARN  
(SUITE-HdfsAutoAddReplicasIntegrationTest-seed#[B2B0A5BDC44833E9]-worker) [    
] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
   [junit4]   2> 7861 INFO  
(SUITE-HdfsAutoAddReplicasIntegrationTest-seed#[B2B0A5BDC44833E9]-worker) [    
] o.m.log jetty-6.1.26
   [junit4]   2> 7895 INFO  
(SUITE-HdfsAutoAddReplicasIntegrationTest-seed#[B2B0A5BDC44833E9]-worker) [    
] o.m.log Extract 
jar:file:/x1/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.7.4-tests.jar!/webapps/hdfs
 to ./temp/Jetty_localhost_34958_hdfs____wb837p/webapp
   [junit4]   2> 8123 DEBUG (ScheduledTrigger-26-thread-2) 
[n:127.0.0.1:33278_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
.auto_add_replicas with currently live nodes: 3
   [junit4]   2> 8957 INFO  
(SUITE-HdfsAutoAddReplicasIntegrationTest-seed#[B2B0A5BDC44833E9]-worker) [    
] o.m.log Started 
HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:34958
   [junit4]   2> 9123 DEBUG (ScheduledTrigger-26-thread-1) 
[n:127.0.0.1:33278_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
.auto_add_replicas with currently live nodes: 3
   [junit4]   2> 9659 WARN  
(SUITE-HdfsAutoAddReplicasIntegrationTest-seed#[B2B0A5BDC44833E9]-worker) [    
] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
   [junit4]   2> 9663 INFO  
(SUITE-HdfsAutoAddReplicasIntegrationTest-seed#[B2B0A5BDC44833E9]-worker) [    
] o.m.log jetty-6.1.26
   [junit4]   2> 9672 INFO  
(SUITE-HdfsAutoAddReplicasIntegrationTest-seed#[B2B0A5BDC44833E9]-worker) [    
] o.m.log Extract 
jar:file:/x1/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.7.4-tests.jar!/webapps/datanode
 to ./temp/Jetty_localhost_33621_datanode____mez858/webapp
   [junit4]   2> 10075 INFO  
(SUITE-HdfsAutoAddReplicasIntegrationTest-seed#[B2B0A5BDC44833E9]-worker) [    
] o.m.log Started 
HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:33621
   [junit4]   2> 10123 DEBUG (ScheduledTrigger-26-thread-1) 
[n:127.0.0.1:33278_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
.auto_add_replicas with currently live nodes: 3
   [junit4]   2> 10423 WARN  
(SUITE-HdfsAutoAddReplicasIntegrationTest-seed#[B2B0A5BDC44833E9]-worker) [    
] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
   [junit4]   2> 10425 INFO  
(SUITE-HdfsAutoAddReplicasIntegrationTest-seed#[B2B0A5BDC44833E9]-worker) [    
] o.m.log jetty-6.1.26
   [junit4]   2> 10447 INFO  
(SUITE-HdfsAutoAddReplicasIntegrationTest-seed#[B2B0A5BDC44833E9]-worker) [    
] o.m.log Extract 
jar:file:/x1/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.7.4-tests.jar!/webapps/datanode
 to ./temp/Jetty_localhost_33040_datanode____30jtpv/webapp
   [junit4]   2> 10950 INFO  
(SUITE-HdfsAutoAddReplicasIntegrationTest-seed#[B2B0A5BDC44833E9]-worker) [    
] o.m.log Started 
HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:33040
   [junit4]   2> 11108 ERROR (DataNode: 
[[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.HdfsAutoAddReplicasIntegrationTest_B2B0A5BDC44833E9-001/tempDir-002/hdfsBaseDir/data/data1/,
 
[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.HdfsAutoAddReplicasIntegrationTest_B2B0A5BDC44833E9-001/tempDir-002/hdfsBaseDir/data/data2/]]
  heartbeating to localhost/127.0.0.1:36294) [    ] 
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> 11126 DEBUG (ScheduledTrigger-26-thread-1) 
[n:127.0.0.1:33278_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
.auto_add_replicas with currently live nodes: 3
   [junit4]   2> 11276 ERROR (DataNode: 
[[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.HdfsAutoAddReplicasIntegrationTest_B2B0A5BDC44833E9-001/tempDir-002/hdfsBaseDir/data/data3/,
 
[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.HdfsAutoAddReplicasIntegrationTest_B2B0A5BDC44833E9-001/tempDir-002/hdfsBaseDir/data/data4/]]
  heartbeating to localhost/127.0.0.1:36294) [    ] 
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> 11329 INFO  (Block report processor) [    ] BlockStateChange 
BLOCK* processReport 0x41e435903f41b0: from storage 
DS-bd9cf523-437c-4727-9ef2-c6d37f7dd53b node 
DatanodeRegistration(127.0.0.1:38150, 
datanodeUuid=8061efb5-9d6b-4956-b945-f0a1abdd9b26, infoPort=34095, 
infoSecurePort=0, ipcPort=33135, 
storageInfo=lv=-56;cid=testClusterID;nsid=897729064;c=0), blocks: 0, 
hasStaleStorage: true, processing time: 2 msecs
   [junit4]   2> 11330 INFO  (Block report processor) [    ] BlockStateChange 
BLOCK* processReport 0x41e435903f4192: from storage 
DS-5c96832f-dda4-4b6e-888e-5726ec4a6272 node 
DatanodeRegistration(127.0.0.1:35828, 
datanodeUuid=f52b348a-ddb2-44e2-8bfd-34587be89595, infoPort=36094, 
infoSecurePort=0, ipcPort=60746, 
storageInfo=lv=-56;cid=testClusterID;nsid=897729064;c=0), blocks: 0, 
hasStaleStorage: true, processing time: 1 msecs
   [junit4]   2> 11330 INFO  (Block report processor) [    ] BlockStateChange 
BLOCK* processReport 0x41e435903f41b0: from storage 
DS-c4e53337-e2a4-442d-988a-cec3c0754a21 node 
DatanodeRegistration(127.0.0.1:38150, 
datanodeUuid=8061efb5-9d6b-4956-b945-f0a1abdd9b26, infoPort=34095, 
infoSecurePort=0, ipcPort=33135, 
storageInfo=lv=-56;cid=testClusterID;nsid=897729064;c=0), blocks: 0, 
hasStaleStorage: false, processing time: 0 msecs
   [junit4]   2> 11330 INFO  (Block report processor) [    ] BlockStateChange 
BLOCK* processReport 0x41e435903f4192: from storage 
DS-7ed81f3f-67c4-44cb-acf9-6541cb4555d9 node 
DatanodeRegistration(127.0.0.1:35828, 
datanodeUuid=f52b348a-ddb2-44e2-8bfd-34587be89595, infoPort=36094, 
infoSecurePort=0, ipcPort=60746, 
storageInfo=lv=-56;cid=testClusterID;nsid=897729064;c=0), blocks: 0, 
hasStaleStorage: false, processing time: 0 msecs
   [junit4]   2> 12126 DEBUG (ScheduledTrigger-26-thread-1) 
[n:127.0.0.1:33278_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
.auto_add_replicas with currently live nodes: 3
   [junit4]   2> 12366 INFO  
(TEST-HdfsAutoAddReplicasIntegrationTest.testSimple-seed#[B2B0A5BDC44833E9]) [  
  ] o.a.s.SolrTestCaseJ4 ###Starting testSimple
   [junit4]   2> 12679 INFO  (qtp1774229243-38) [n:127.0.0.1:36009_solr    ] 
o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params 
replicationFactor=2&collection.configName=conf&maxShardsPerNode=2&autoAddReplicas=true&name=testSimple1&nrtReplicas=2&action=CREATE&numShards=2&createNodeSet=127.0.0.1:36009_solr,127.0.0.1:44350_solr&wt=javabin&version=2
 and sendToOCPQueue=true
   [junit4]   2> 12705 INFO  
(OverseerThreadFactory-29-thread-1-processing-n:127.0.0.1:33278_solr) 
[n:127.0.0.1:33278_solr    ] o.a.s.c.a.c.CreateCollectionCmd Create collection 
testSimple1
   [junit4]   2> 12861 INFO  
(OverseerStateUpdate-73273076056260615-127.0.0.1:33278_solr-n_0000000000) 
[n:127.0.0.1:33278_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"testSimple1",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"testSimple1_shard1_replica_n1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"http://127.0.0.1:36009/solr";,
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 12886 INFO  
(OverseerStateUpdate-73273076056260615-127.0.0.1:33278_solr-n_0000000000) 
[n:127.0.0.1:33278_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"testSimple1",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"testSimple1_shard1_replica_n3",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"http://127.0.0.1:44350/solr";,
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 12889 INFO  
(OverseerStateUpdate-73273076056260615-127.0.0.1:33278_solr-n_0000000000) 
[n:127.0.0.1:33278_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"testSimple1",
   [junit4]   2>   "shard":"shard2",
   [junit4]   2>   "core":"testSimple1_shard2_replica_n4",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"http://127.0.0.1:36009/solr";,
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 12894 INFO  
(OverseerStateUpdate-73273076056260615-127.0.0.1:33278_solr-n_0000000000) 
[n:127.0.0.1:33278_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"testSimple1",
   [junit4]   2>   "shard":"shard2",
   [junit4]   2>   "core":"testSimple1_shard2_replica_n5",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"http://127.0.0.1:44350/solr";,
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 13105 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr    ] 
o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&coreNodeName=core_node6&collection.configName=conf&newCollection=true&name=testSimple1_shard1_replica_n3&action=CREATE&numShards=2&collection=testSimple1&shard=shard1&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 13107 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr    ] 
o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&coreNodeName=core_node7&collection.configName=conf&newCollection=true&name=testSimple1_shard2_replica_n4&action=CREATE&numShards=2&collection=testSimple1&shard=shard2&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 13110 INFO  (qtp1774229243-44) [n:127.0.0.1:36009_solr    ] 
o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf&newCollection=true&name=testSimple1_shard1_replica_n1&action=CREATE&numShards=2&collection=testSimple1&shard=shard1&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 13111 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr    ] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 
transient cores
   [junit4]   2> 13122 INFO  (qtp1774229243-44) [n:127.0.0.1:36009_solr    ] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 
transient cores
   [junit4]   2> 13124 INFO  (qtp1856904637-43) [n:127.0.0.1:44350_solr    ] 
o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&coreNodeName=core_node8&collection.configName=conf&newCollection=true&name=testSimple1_shard2_replica_n5&action=CREATE&numShards=2&collection=testSimple1&shard=shard2&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 13126 DEBUG (ScheduledTrigger-26-thread-1) 
[n:127.0.0.1:33278_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
.auto_add_replicas with currently live nodes: 3
   [junit4]   2> 13273 INFO  
(zkCallback-33-thread-1-processing-n:127.0.0.1:44350_solr) 
[n:127.0.0.1:44350_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/testSimple1/state.json] for collection [testSimple1] has 
occurred - updating... (live nodes size: [3])
   [junit4]   2> 13277 INFO  
(zkCallback-35-thread-1-processing-n:127.0.0.1:36009_solr) 
[n:127.0.0.1:36009_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/testSimple1/state.json] for collection [testSimple1] has 
occurred - updating... (live nodes size: [3])
   [junit4]   2> 14127 DEBUG (ScheduledTrigger-26-thread-1) 
[n:127.0.0.1:33278_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
.auto_add_replicas with currently live nodes: 3
   [junit4]   2> 14173 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
   [junit4]   2> 14183 INFO  (qtp1774229243-44) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard1 r:core_node2 x:testSimple1_shard1_replica_n1] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
   [junit4]   2> 14190 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard1 r:core_node6 x:testSimple1_shard1_replica_n3] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
   [junit4]   2> 14239 INFO  (qtp1856904637-43) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard2 r:core_node8 x:testSimple1_shard2_replica_n5] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
   [junit4]   2> 14272 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard1 r:core_node6 x:testSimple1_shard1_replica_n3] 
o.a.s.s.IndexSchema [testSimple1_shard1_replica_n3] Schema name=minimal
   [junit4]   2> 14285 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.s.IndexSchema [testSimple1_shard2_replica_n4] Schema name=minimal
   [junit4]   2> 14289 INFO  (qtp1856904637-43) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard2 r:core_node8 x:testSimple1_shard2_replica_n5] 
o.a.s.s.IndexSchema [testSimple1_shard2_replica_n5] Schema name=minimal
   [junit4]   2> 14307 INFO  (qtp1774229243-44) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard1 r:core_node2 x:testSimple1_shard1_replica_n1] 
o.a.s.s.IndexSchema [testSimple1_shard1_replica_n1] Schema name=minimal
   [junit4]   2> 14320 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 14320 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.c.CoreContainer Creating SolrCore 'testSimple1_shard2_replica_n4' using 
configuration from collection testSimple1, trusted=true
   [junit4]   2> 14321 INFO  (qtp1774229243-44) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard1 r:core_node2 x:testSimple1_shard1_replica_n1] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 14321 INFO  (qtp1774229243-44) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard1 r:core_node2 x:testSimple1_shard1_replica_n1] 
o.a.s.c.CoreContainer Creating SolrCore 'testSimple1_shard1_replica_n1' using 
configuration from collection testSimple1, trusted=true
   [junit4]   2> 14338 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_36009.solr.core.testSimple1.shard2.replica_n4' (registry 
'solr.core.testSimple1.shard2.replica_n4') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@5cc83a41
   [junit4]   2> 14346 INFO  (qtp1774229243-44) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard1 r:core_node2 x:testSimple1_shard1_replica_n1] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_36009.solr.core.testSimple1.shard1.replica_n1' (registry 
'solr.core.testSimple1.shard1.replica_n1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@5cc83a41
   [junit4]   2> 14347 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard1 r:core_node6 x:testSimple1_shard1_replica_n3] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 14347 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard1 r:core_node6 x:testSimple1_shard1_replica_n3] 
o.a.s.c.CoreContainer Creating SolrCore 'testSimple1_shard1_replica_n3' using 
configuration from collection testSimple1, trusted=true
   [junit4]   2> 14350 INFO  (qtp1856904637-43) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard2 r:core_node8 x:testSimple1_shard2_replica_n5] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 14350 INFO  (qtp1856904637-43) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard2 r:core_node8 x:testSimple1_shard2_replica_n5] 
o.a.s.c.CoreContainer Creating SolrCore 'testSimple1_shard2_replica_n5' using 
configuration from collection testSimple1, trusted=true
   [junit4]   2> 14351 INFO  (qtp1856904637-43) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard2 r:core_node8 x:testSimple1_shard2_replica_n5] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_44350.solr.core.testSimple1.shard2.replica_n5' (registry 
'solr.core.testSimple1.shard2.replica_n5') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@5cc83a41
   [junit4]   2> 14354 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard1 r:core_node6 x:testSimple1_shard1_replica_n3] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_44350.solr.core.testSimple1.shard1.replica_n3' (registry 
'solr.core.testSimple1.shard1.replica_n3') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@5cc83a41
   [junit4]   2> 14354 INFO  (qtp1856904637-43) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard2 r:core_node8 x:testSimple1_shard2_replica_n5] 
o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://localhost:36294/data
   [junit4]   2> 14354 INFO  (qtp1856904637-43) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard2 r:core_node8 x:testSimple1_shard2_replica_n5] 
o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
   [junit4]   2> 14354 INFO  (qtp1856904637-43) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard2 r:core_node8 x:testSimple1_shard2_replica_n5] 
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 14355 INFO  (qtp1856904637-43) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard2 r:core_node8 x:testSimple1_shard2_replica_n5] 
o.a.s.c.SolrCore [[testSimple1_shard2_replica_n5] ] Opening new SolrCore at 
[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.HdfsAutoAddReplicasIntegrationTest_B2B0A5BDC44833E9-001/tempDir-001/node2/testSimple1_shard2_replica_n5],
 dataDir=[hdfs://localhost:36294/data/testSimple1/core_node8/data/]
   [junit4]   2> 14359 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard1 r:core_node6 x:testSimple1_shard1_replica_n3] 
o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://localhost:36294/data
   [junit4]   2> 14365 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard1 r:core_node6 x:testSimple1_shard1_replica_n3] 
o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
   [junit4]   2> 14365 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard1 r:core_node6 x:testSimple1_shard1_replica_n3] 
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 14365 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard1 r:core_node6 x:testSimple1_shard1_replica_n3] 
o.a.s.c.SolrCore [[testSimple1_shard1_replica_n3] ] Opening new SolrCore at 
[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.HdfsAutoAddReplicasIntegrationTest_B2B0A5BDC44833E9-001/tempDir-001/node2/testSimple1_shard1_replica_n3],
 dataDir=[hdfs://localhost:36294/data/testSimple1/core_node6/data/]
   [junit4]   2> 14369 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard1 r:core_node6 x:testSimple1_shard1_replica_n3] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:36294/data/testSimple1/core_node6/data/snapshot_metadata
   [junit4]   2> 14370 INFO  (qtp1774229243-44) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard1 r:core_node2 x:testSimple1_shard1_replica_n1] 
o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://localhost:36294/data
   [junit4]   2> 14370 INFO  (qtp1774229243-44) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard1 r:core_node2 x:testSimple1_shard1_replica_n1] 
o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
   [junit4]   2> 14370 INFO  (qtp1774229243-44) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard1 r:core_node2 x:testSimple1_shard1_replica_n1] 
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 14370 INFO  (qtp1774229243-44) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard1 r:core_node2 x:testSimple1_shard1_replica_n1] 
o.a.s.c.SolrCore [[testSimple1_shard1_replica_n1] ] Opening new SolrCore at 
[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.HdfsAutoAddReplicasIntegrationTest_B2B0A5BDC44833E9-001/tempDir-001/node3/testSimple1_shard1_replica_n1],
 dataDir=[hdfs://localhost:36294/data/testSimple1/core_node2/data/]
   [junit4]   2> 14371 INFO  (qtp1856904637-43) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard2 r:core_node8 x:testSimple1_shard2_replica_n5] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:36294/data/testSimple1/core_node8/data/snapshot_metadata
   [junit4]   2> 14372 INFO  (qtp1774229243-44) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard1 r:core_node2 x:testSimple1_shard1_replica_n1] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:36294/data/testSimple1/core_node2/data/snapshot_metadata
   [junit4]   2> 14378 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://localhost:36294/data
   [junit4]   2> 14378 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
   [junit4]   2> 14378 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 14378 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.c.SolrCore [[testSimple1_shard2_replica_n4] ] Opening new SolrCore at 
[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.HdfsAutoAddReplicasIntegrationTest_B2B0A5BDC44833E9-001/tempDir-001/node3/testSimple1_shard2_replica_n4],
 dataDir=[hdfs://localhost:36294/data/testSimple1/core_node7/data/]
   [junit4]   2> 14380 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:36294/data/testSimple1/core_node7/data/snapshot_metadata
   [junit4]   2> 14516 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:36294/data/testSimple1/core_node7/data
   [junit4]   2> 14518 INFO  (qtp1774229243-44) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard1 r:core_node2 x:testSimple1_shard1_replica_n1] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:36294/data/testSimple1/core_node2/data
   [junit4]   2> 14522 INFO  (qtp1856904637-43) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard2 r:core_node8 x:testSimple1_shard2_replica_n5] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:36294/data/testSimple1/core_node8/data
   [junit4]   2> 14522 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard1 r:core_node6 x:testSimple1_shard1_replica_n3] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:36294/data/testSimple1/core_node6/data
   [junit4]   2> 14651 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:36294/data/testSimple1/core_node7/data/index
   [junit4]   2> 14653 INFO  (qtp1856904637-43) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard2 r:core_node8 x:testSimple1_shard2_replica_n5] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:36294/data/testSimple1/core_node8/data/index
   [junit4]   2> 14658 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard1 r:core_node6 x:testSimple1_shard1_replica_n3] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:36294/data/testSimple1/core_node6/data/index
   [junit4]   2> 14662 INFO  (qtp1774229243-44) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard1 r:core_node2 x:testSimple1_shard1_replica_n1] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:36294/data/testSimple1/core_node2/data/index
   [junit4]   2> 15127 DEBUG (ScheduledTrigger-26-thread-1) 
[n:127.0.0.1:33278_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
.auto_add_replicas with currently live nodes: 3
   [junit4]   2> 15261 INFO  (Block report processor) [    ] BlockStateChange 
BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:35828 is added to 
blk_1073741827_1003{UCState=UNDER_CONSTRUCTION, truncateBlock=null, 
primaryNodeIndex=-1, 
replicas=[ReplicaUC[[DISK]DS-bd9cf523-437c-4727-9ef2-c6d37f7dd53b:NORMAL:127.0.0.1:38150|RBW],
 
ReplicaUC[[DISK]DS-7ed81f3f-67c4-44cb-acf9-6541cb4555d9:NORMAL:127.0.0.1:35828|RBW]]}
 size 0
   [junit4]   2> 15263 INFO  (Block report processor) [    ] BlockStateChange 
BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:38150 is added to 
blk_1073741828_1004{UCState=COMMITTED, truncateBlock=null, primaryNodeIndex=-1, 
replicas=[ReplicaUC[[DISK]DS-5c96832f-dda4-4b6e-888e-5726ec4a6272:NORMAL:127.0.0.1:35828|RBW],
 
ReplicaUC[[DISK]DS-c4e53337-e2a4-442d-988a-cec3c0754a21:NORMAL:127.0.0.1:38150|RBW]]}
 size 69
   [junit4]   2> 15263 INFO  (Block report processor) [    ] BlockStateChange 
BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:35828 is added to 
blk_1073741825_1001{UCState=COMMITTED, truncateBlock=null, primaryNodeIndex=-1, 
replicas=[ReplicaUC[[DISK]DS-5c96832f-dda4-4b6e-888e-5726ec4a6272:NORMAL:127.0.0.1:35828|RBW],
 
ReplicaUC[[DISK]DS-bd9cf523-437c-4727-9ef2-c6d37f7dd53b:NORMAL:127.0.0.1:38150|RBW]]}
 size 69
   [junit4]   2> 15263 INFO  (Block report processor) [    ] BlockStateChange 
BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:35828 is added to 
blk_1073741828_1004 size 69
   [junit4]   2> 15263 INFO  (Block report processor) [    ] BlockStateChange 
BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:35828 is added to 
blk_1073741826_1002{UCState=COMMITTED, truncateBlock=null, primaryNodeIndex=-1, 
replicas=[ReplicaUC[[DISK]DS-bd9cf523-437c-4727-9ef2-c6d37f7dd53b:NORMAL:127.0.0.1:38150|RBW],
 
ReplicaUC[[DISK]DS-7ed81f3f-67c4-44cb-acf9-6541cb4555d9:NORMAL:127.0.0.1:35828|RBW]]}
 size 69
   [junit4]   2> 15264 INFO  (Block report processor) [    ] BlockStateChange 
BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:38150 is added to 
blk_1073741825_1001 size 69
   [junit4]   2> 15264 INFO  (Block report processor) [    ] BlockStateChange 
BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:38150 is added to 
blk_1073741826_1002 size 69
   [junit4]   2> 15276 INFO  (Block report processor) [    ] BlockStateChange 
BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:38150 is added to 
blk_1073741827_1003 size 69
   [junit4]   2> 15384 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.HdfsUpdateLog
   [junit4]   2> 15385 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 15385 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.u.HdfsUpdateLog Initializing HdfsUpdateLog: tlogDfsReplication=3
   [junit4]   2> 15406 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 15408 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 15495 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@b478360[testSimple1_shard2_replica_n4] main]
   [junit4]   2> 15500 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf
   [junit4]   2> 15501 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 15504 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 15507 INFO  
(searcherExecutor-35-thread-1-processing-n:127.0.0.1:36009_solr 
x:testSimple1_shard2_replica_n4 s:shard2 c:testSimple1 r:core_node7) 
[n:127.0.0.1:36009_solr c:testSimple1 s:shard2 r:core_node7 
x:testSimple1_shard2_replica_n4] o.a.s.c.SolrCore 
[testSimple1_shard2_replica_n4] Registered new searcher 
Searcher@b478360[testSimple1_shard2_replica_n4] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 15511 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1592047578090831872
   [junit4]   2> 15568 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for 
shard shard2: total=2 found=1 timeoutin=9998ms
   [junit4]   2> 15570 INFO  
(zkCallback-33-thread-1-processing-n:127.0.0.1:44350_solr) 
[n:127.0.0.1:44350_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/testSimple1/state.json] for collection [testSimple1] has 
occurred - updating... (live nodes size: [3])
   [junit4]   2> 15571 INFO  
(zkCallback-35-thread-1-processing-n:127.0.0.1:36009_solr) 
[n:127.0.0.1:36009_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/testSimple1/state.json] for collection [testSimple1] has 
occurred - updating... (live nodes size: [3])
   [junit4]   2> 15826 INFO  (qtp1774229243-44) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard1 r:core_node2 x:testSimple1_shard1_replica_n1] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.HdfsUpdateLog
   [junit4]   2> 15826 INFO  (qtp1774229243-44) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard1 r:core_node2 x:testSimple1_shard1_replica_n1] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 15826 INFO  (qtp1774229243-44) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard1 r:core_node2 x:testSimple1_shard1_replica_n1] 
o.a.s.u.HdfsUpdateLog Initializing HdfsUpdateLog: tlogDfsReplication=3
   [junit4]   2> 15866 INFO  (qtp1774229243-44) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard1 r:core_node2 x:testSimple1_shard1_replica_n1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 15874 INFO  (qtp1774229243-44) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard1 r:core_node2 x:testSimple1_shard1_replica_n1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 15874 INFO  (qtp1856904637-43) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard2 r:core_node8 x:testSimple1_shard2_replica_n5] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.HdfsUpdateLog
   [junit4]   2> 15891 INFO  (qtp1856904637-43) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard2 r:core_node8 x:testSimple1_shard2_replica_n5] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 15887 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard1 r:core_node6 x:testSimple1_shard1_replica_n3] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.HdfsUpdateLog
   [junit4]   2> 15894 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard1 r:core_node6 x:testSimple1_shard1_replica_n3] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 15894 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard1 r:core_node6 x:testSimple1_shard1_replica_n3] 
o.a.s.u.HdfsUpdateLog Initializing HdfsUpdateLog: tlogDfsReplication=3
   [junit4]   2> 15892 INFO  (qtp1856904637-43) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard2 r:core_node8 x:testSimple1_shard2_replica_n5] 
o.a.s.u.HdfsUpdateLog Initializing HdfsUpdateLog: tlogDfsReplication=3
   [junit4]   2> 15916 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard1 r:core_node6 x:testSimple1_shard1_replica_n3] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 15916 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard1 r:core_node6 x:testSimple1_shard1_replica_n3] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 15926 INFO  (qtp1856904637-43) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard2 r:core_node8 x:testSimple1_shard2_replica_n5] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 15926 INFO  (qtp1856904637-43) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard2 r:core_node8 x:testSimple1_shard2_replica_n5] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 15969 INFO  (qtp1774229243-44) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard1 r:core_node2 x:testSimple1_shard1_replica_n1] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@5c9009c[testSimple1_shard1_replica_n1] main]
   [junit4]   2> 15975 INFO  (qtp1856904637-43) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard2 r:core_node8 x:testSimple1_shard2_replica_n5] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@bd462c0[testSimple1_shard2_replica_n5] main]
   [junit4]   2> 15972 INFO  (qtp1774229243-44) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard1 r:core_node2 x:testSimple1_shard1_replica_n1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf
   [junit4]   2> 15976 INFO  (qtp1856904637-43) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard2 r:core_node8 x:testSimple1_shard2_replica_n5] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf
   [junit4]   2> 15987 INFO  (qtp1856904637-43) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard2 r:core_node8 x:testSimple1_shard2_replica_n5] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 15989 INFO  (qtp1774229243-44) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard1 r:core_node2 x:testSimple1_shard1_replica_n1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 15988 INFO  (qtp1856904637-43) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard2 r:core_node8 x:testSimple1_shard2_replica_n5] 
o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 15990 INFO  (qtp1774229243-44) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard1 r:core_node2 x:testSimple1_shard1_replica_n1] 
o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 16000 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard1 r:core_node6 x:testSimple1_shard1_replica_n3] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@c4e27e9[testSimple1_shard1_replica_n3] main]
   [junit4]   2> 16002 INFO  
(searcherExecutor-36-thread-1-processing-n:127.0.0.1:36009_solr 
x:testSimple1_shard1_replica_n1 s:shard1 c:testSimple1 r:core_node2) 
[n:127.0.0.1:36009_solr c:testSimple1 s:shard1 r:core_node2 
x:testSimple1_shard1_replica_n1] o.a.s.c.SolrCore 
[testSimple1_shard1_replica_n1] Registered new searcher 
Searcher@5c9009c[testSimple1_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 16002 INFO  (qtp1774229243-44) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard1 r:core_node2 x:testSimple1_shard1_replica_n1] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1592047578605682688
   [junit4]   2> 16003 INFO  
(searcherExecutor-38-thread-1-processing-n:127.0.0.1:44350_solr 
x:testSimple1_shard2_replica_n5 s:shard2 c:testSimple1 r:core_node8) 
[n:127.0.0.1:44350_solr c:testSimple1 s:shard2 r:core_node8 
x:testSimple1_shard2_replica_n5] o.a.s.c.SolrCore 
[testSimple1_shard2_replica_n5] Registered new searcher 
Searcher@bd462c0[testSimple1_shard2_replica_n5] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 16003 INFO  (qtp1856904637-43) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard2 r:core_node8 x:testSimple1_shard2_replica_n5] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1592047578606731264
   [junit4]   2> 16010 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard1 r:core_node6 x:testSimple1_shard1_replica_n3] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf
   [junit4]   2> 16010 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard1 r:core_node6 x:testSimple1_shard1_replica_n3] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 16021 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard1 r:core_node6 x:testSimple1_shard1_replica_n3] 
o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 16022 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard1 r:core_node6 x:testSimple1_shard1_replica_n3] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1592047578626654208
   [junit4]   2> 16026 INFO  
(searcherExecutor-37-thread-1-processing-n:127.0.0.1:44350_solr 
x:testSimple1_shard1_replica_n3 s:shard1 c:testSimple1 r:core_node6) 
[n:127.0.0.1:44350_solr c:testSimple1 s:shard1 r:core_node6 
x:testSimple1_shard1_replica_n3] o.a.s.c.SolrCore 
[testSimple1_shard1_replica_n3] Registered new searcher 
Searcher@c4e27e9[testSimple1_shard1_replica_n3] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 16038 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard1 r:core_node6 x:testSimple1_shard1_replica_n3] 
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 16038 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard1 r:core_node6 x:testSimple1_shard1_replica_n3] 
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 16038 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard1 r:core_node6 x:testSimple1_shard1_replica_n3] 
o.a.s.c.SyncStrategy Sync replicas to 
http://127.0.0.1:44350/solr/testSimple1_shard1_replica_n3/
   [junit4]   2> 16043 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard1 r:core_node6 x:testSimple1_shard1_replica_n3] 
o.a.s.u.PeerSync PeerSync: core=testSimple1_shard1_replica_n3 
url=http://127.0.0.1:44350/solr START 
replicas=[http://127.0.0.1:36009/solr/testSimple1_shard1_replica_n1/] 
nUpdates=100
   [junit4]   2> 16074 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 16074 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 16074 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.c.SyncStrategy Sync replicas to 
http://127.0.0.1:36009/solr/testSimple1_shard2_replica_n4/
   [junit4]   2> 16095 INFO  (qtp1774229243-45) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard1 r:core_node2 x:testSimple1_shard1_replica_n1] 
o.a.s.c.S.Request [testSimple1_shard1_replica_n1]  webapp=/solr path=/get 
params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2}
 status=0 QTime=39
   [junit4]   2> 16095 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.u.PeerSync PeerSync: core=testSimple1_shard2_replica_n4 
url=http://127.0.0.1:36009/solr START 
replicas=[http://127.0.0.1:44350/solr/testSimple1_shard2_replica_n5/] 
nUpdates=100
   [junit4]   2> 16127 DEBUG (ScheduledTrigger-26-thread-1) 
[n:127.0.0.1:33278_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
.auto_add_replicas with currently live nodes: 3
   [junit4]   2> 16147 INFO  (qtp1856904637-59) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard2 r:core_node8 x:testSimple1_shard2_replica_n5] 
o.a.s.c.S.Request [testSimple1_shard2_replica_n5]  webapp=/solr path=/get 
params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2}
 status=0 QTime=12
   [junit4]   2> 16154 INFO  
(zkCallback-35-thread-1-processing-n:127.0.0.1:36009_solr) 
[n:127.0.0.1:36009_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/testSimple1/state.json] for collection [testSimple1] has 
occurred - updating... (live nodes size: [3])
   [junit4]   2> 16154 INFO  
(zkCallback-33-thread-1-processing-n:127.0.0.1:44350_solr) 
[n:127.0.0.1:44350_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/testSimple1/state.json] for collection [testSimple1] has 
occurred - updating... (live nodes size: [3])
   [junit4]   2> 16350 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard1 r:core_node6 x:testSimple1_shard1_replica_n3] 
o.a.s.u.PeerSync PeerSync: core=testSimple1_shard1_replica_n3 
url=http://127.0.0.1:44350/solr DONE.  We have no versions.  sync failed.
   [junit4]   2> 16351 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard1 r:core_node6 x:testSimple1_shard1_replica_n3] 
o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the 
next candidate
   [junit4]   2> 16352 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard1 r:core_node6 x:testSimple1_shard1_replica_n3] 
o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we 
can't sync in that case - we were active before, so become leader anyway
   [junit4]   2> 16352 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard1 r:core_node6 x:testSimple1_shard1_replica_n3] 
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in 
election, clear LIR
   [junit4]   2> 16362 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard1 r:core_node6 x:testSimple1_shard1_replica_n3] 
o.a.s.c.ShardLeaderElectionContext I am the new leader: 
http://127.0.0.1:44350/solr/testSimple1_shard1_replica_n3/ shard1
   [junit4]   2> 16426 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.u.PeerSync PeerSync: core=testSimple1_shard2_replica_n4 
url=http://127.0.0.1:36009/solr DONE.  We have no versions.  sync failed.
   [junit4]   2> 16426 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the 
next candidate
   [junit4]   2> 16426 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we 
can't sync in that case - we were active before, so become leader anyway
   [junit4]   2> 16426 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in 
election, clear LIR
   [junit4]   2> 16434 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.c.ShardLeaderElectionContext I am the new leader: 
http://127.0.0.1:36009/solr/testSimple1_shard2_replica_n4/ shard2
   [junit4]   2> 16541 INFO  
(zkCallback-33-thread-1-processing-n:127.0.0.1:44350_solr) 
[n:127.0.0.1:44350_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/testSimple1/state.json] for collection [testSimple1] has 
occurred - updating... (live nodes size: [3])
   [junit4]   2> 16541 INFO  
(zkCallback-35-thread-1-processing-n:127.0.0.1:36009_solr) 
[n:127.0.0.1:36009_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/testSimple1/state.json] for collection [testSimple1] has 
occurred - updating... (live nodes size: [3])
   [junit4]   2> 16566 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard1 r:core_node6 x:testSimple1_shard1_replica_n3] 
o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 16570 INFO  (qtp1856904637-35) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard1 r:core_node6 x:testSimple1_shard1_replica_n3] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={qt=/admin/cores&coreNodeName=core_node6&collection.configName=conf&newCollection=true&name=testSimple1_shard1_replica_n3&action=CREATE&numShards=2&collection=testSimple1&shard=shard1&wt=javabin&version=2&replicaType=NRT}
 status=0 QTime=3467
   [junit4]   2> 16587 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 16590 INFO  (qtp1774229243-46) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard2 r:core_node7 x:testSimple1_shard2_replica_n4] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={qt=/admin/cores&coreNodeName=core_node7&collection.configName=conf&newCollection=true&name=testSimple1_shard2_replica_n4&action=CREATE&numShards=2&collection=testSimple1&shard=shard2&wt=javabin&version=2&replicaType=NRT}
 status=0 QTime=3482
   [junit4]   2> 16694 INFO  
(zkCallback-33-thread-1-processing-n:127.0.0.1:44350_solr) 
[n:127.0.0.1:44350_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/testSimple1/state.json] for collection [testSimple1] has 
occurred - updating... (live nodes size: [3])
   [junit4]   2> 16694 INFO  
(zkCallback-35-thread-1-processing-n:127.0.0.1:36009_solr) 
[n:127.0.0.1:36009_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/testSimple1/state.json] for collection [testSimple1] has 
occurred - updating... (live nodes size: [3])
   [junit4]   2> 17040 INFO  (qtp1856904637-43) [n:127.0.0.1:44350_solr 
c:testSimple1 s:shard2 r:core_node8 x:testSimple1_shard2_replica_n5] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={qt=/admin/cores&coreNodeName=core_node8&collection.configName=conf&newCollection=true&name=testSimple1_shard2_replica_n5&action=CREATE&numShards=2&collection=testSimple1&shard=shard2&wt=javabin&version=2&replicaType=NRT}
 status=0 QTime=3916
   [junit4]   2> 17049 INFO  (qtp1774229243-44) [n:127.0.0.1:36009_solr 
c:testSimple1 s:shard1 r:core_node2 x:testSimple1_shard1_replica_n1] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf&newCollection=true&name=testSimple1_shard1_replica_n1&action=CREATE&numShards=2&collection=testSimple1&shard=shard1&wt=javabin&version=2&replicaType=NRT}
 status=0 QTime=3947
   [junit4]   2> 17064 INFO  (qtp1774229243-38) [n:127.0.0.1:36009_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> 17128 DEBUG (ScheduledTrigger-26-thread-1) 
[n:127.0.0.1:33278_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
.auto_add_replicas with currently live nodes: 3
   [junit4]   2> 17146 INFO  
(zkCallback-35-thread-1-processing-n:127.0.0.1:36009_solr) 
[n:127.0.0.1:36009_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/testSimple1/state.json] for collection [testSimple1] has 
occurred - updating... (live nodes size: [3])
   [junit4]   2> 17146 INFO  
(zkCallback-33-thread-1-processing-n:127.0.0.1:44350_solr) 
[n:127.0.0.1:44350_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/testSimple1/state.json] for collection [testSimple1] has 
occurred - updating... (live nodes size: [3])
   [junit4]   2> 18064 INFO  (qtp1774229243-38) [n:127.0.0.1:36009_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections 
params={replicationFactor=2&collection.configName=conf&maxShardsPerNode=2&autoAddReplicas=true&name=testSimple1&nrtReplicas=2&action=CREATE&numShards=2&createNodeSet=127.0.0.1:36009_solr,127.0.0.1:44350_solr&wt=javabin&version=2}
 status=0 QTime=5390
   [junit4]   2> 18071 INFO  (qtp1774229243-42) [n:127.0.0.1:36009_solr    ] 
o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params 
replicationFactor=2&collection.configName=conf&maxShardsPerNode=2&autoAddReplicas=false&name=testSimple2&nrtReplicas=2&action=CREATE&numShards=2&createNodeSet=127.0.0.1:44350_solr,127.0.0.1:33278_solr&wt=javabin&version=2
 and sendToOCPQueue=true
   [junit4]   2> 18074 INFO  
(OverseerCollectionConfigSetProcessor-73273076056260615-127.0.0.1:33278_solr-n_0000000000)
 [n:127.0.0.1:33278_solr    ] o.a.s.c.OverseerTaskQueue Response ZK path: 
/overseer/collection-queue-work/qnr-0000000000 doesn't exist.  Requestor may 
have disconnected from ZooKeeper
   [junit4]   2> 18074 INFO  
(OverseerThreadFactory-29-thread-2-processing-n:127.0.0.1:33278_solr) 
[n:127.0.0.1:33278_solr    ] o.a.s.c.a.c.CreateCollectionCmd Create collection 
testSimple2
   [junit4]   2> 18128 DEBUG (ScheduledTrigger-26-thread-1) 
[n:127.0.0.1:33278_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
.auto_add_replicas with currently live nodes: 3
   [junit4]   2> 18293 INFO  
(OverseerStateUpdate-73273076056260615-127.0.0.1:33278_solr-n_0000000000) 
[n:127.0.0.1:33278_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"testSimple2",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"testSimple2_shard1_replica_n1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"http://127.0.0.1:33278/solr";,
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 18307 INFO  
(OverseerStateUpdate-73273076056260615-127.0.0.1:33278_solr-n_0000000000) 
[n:127.0.0.1:33278_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"testSimple2",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"testSimple2_shard1_replica_n2",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"http://127.0.0.1:44350/solr";,
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 18310 INFO  
(OverseerStateUpdate-73273076056260615-127.0.0.1:33278_solr-n_0000000000) 
[n:127.0.0.1:33278_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"testSimple2",
   [junit4]   2>   "shard":"shard2",
   [junit4]   2>   "core":"testSimple2_shard2_replica_n4",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"http://127.0.0.1:33278/solr";,
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 18314 INFO  
(OverseerStateUpdate-73273076056260615-127.0.0.1:33278_solr-n_0000000000) 
[n:127.0.0.1:33278_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"testSimple2",
   [junit4]   2>   "sh

[...truncated too long message...]

tricManager Closing metric reporters for 
registry=solr.collection.collection1.shard1.leader, tag=251125044
   [junit4]   2> 1170287 INFO  (coreCloseExecutor-5187-thread-1) 
[n:127.0.0.1:38855_solr c:collection1 s:shard1 r:core_node3 
x:collection1_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric 
reporters for registry=solr.collection.collection1.shard1.leader, tag=2027244051
   [junit4]   2> 1170289 INFO  (jetty-closer-6791-thread-5) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@66a48609{/solr,null,UNAVAILABLE}
   [junit4]   2> 1170289 INFO  (jetty-closer-6791-thread-5) [    ] 
o.e.j.s.session Stopped scavenging
   [junit4]   2> 1170290 INFO  (coreCloseExecutor-5188-thread-2) 
[n:127.0.0.1:36126_solr c:collection1 s:shard1 r:core_node12 
x:collection1_shard1_replica_n11] o.a.s.m.SolrMetricManager Closing metric 
reporters for registry=solr.core.collection1.shard1.replica_n11, tag=1059224996
   [junit4]   2> 1170290 INFO  (coreCloseExecutor-5188-thread-2) 
[n:127.0.0.1:36126_solr c:collection1 s:shard1 r:core_node12 
x:collection1_shard1_replica_n11] o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@105f8391: rootName = 
solr_36126, domain = solr.core.collection1.shard1.replica_n11, service url = 
null, agent id = null] for registry solr.core.collection1.shard1.replica_n11 / 
com.codahale.metrics.MetricRegistry@75da3c6b
   [junit4]   2> 1170295 INFO  
(zkCallback-6920-thread-1-processing-n:127.0.0.1:36126_solr) 
[n:127.0.0.1:36126_solr    ] o.a.s.c.OverseerElectionContext I am going to be 
the leader 127.0.0.1:36126_solr
   [junit4]   2> 1170296 INFO  (jetty-closer-6791-thread-2) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@49835aa4{/solr,null,UNAVAILABLE}
   [junit4]   2> 1170296 INFO  (jetty-closer-6791-thread-2) [    ] 
o.e.j.s.session Stopped scavenging
   [junit4]   2> 1170299 INFO  (coreCloseExecutor-5188-thread-2) 
[n:127.0.0.1:36126_solr c:collection1 s:shard1 r:core_node12 
x:collection1_shard1_replica_n11] o.a.s.m.SolrMetricManager Closing metric 
reporters for registry=solr.collection.collection1.shard1.leader, tag=1059224996
   [junit4]   2> 1170299 INFO  (coreCloseExecutor-5188-thread-1) 
[n:127.0.0.1:36126_solr c:collection1 s:shard1 r:core_node4 
x:collection1_shard1_replica_n2] o.a.s.m.SolrMetricManager Closing metric 
reporters for registry=solr.collection.collection1.shard1.leader, tag=466471056
   [junit4]   2> 1171661 WARN  
(zkCallback-6986-thread-1-processing-n:127.0.0.1:44420_solr) 
[n:127.0.0.1:44420_solr    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, 
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 1171662 WARN  
(zkCallback-6963-thread-2-processing-n:127.0.0.1:41970_solr) 
[n:127.0.0.1:41970_solr    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, 
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 1171662 INFO  (jetty-closer-6791-thread-10) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@762404c1{/solr,null,UNAVAILABLE}
   [junit4]   2> 1171662 INFO  (jetty-closer-6791-thread-8) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@4ba62347{/solr,null,UNAVAILABLE}
   [junit4]   2> 1171663 INFO  (jetty-closer-6791-thread-10) [    ] 
o.e.j.s.session Stopped scavenging
   [junit4]   2> 1171663 INFO  (jetty-closer-6791-thread-8) [    ] 
o.e.j.s.session Stopped scavenging
   [junit4]   2> 1171801 INFO  (jetty-closer-6791-thread-4) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@38f6a0a7{/solr,null,UNAVAILABLE}
   [junit4]   2> 1171801 INFO  (jetty-closer-6791-thread-4) [    ] 
o.e.j.s.session Stopped scavenging
   [junit4]   2> 1171802 ERROR 
(SUITE-TriggerIntegrationTest-seed#[B2B0A5BDC44833E9]-worker) [    ] 
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> 1171802 INFO  
(SUITE-TriggerIntegrationTest-seed#[B2B0A5BDC44833E9]-worker) [    ] 
o.a.s.c.ZkTestServer connecting to 127.0.0.1:34276 34276
   [junit4]   2> 1171967 INFO  (Thread-3846) [    ] o.a.s.c.ZkTestServer 
connecting to 127.0.0.1:34276 34276
   [junit4]   2> 1171968 WARN  (Thread-3846) [    ] o.a.s.c.ZkTestServer Watch 
limit violations: 
   [junit4]   2> Maximum concurrent create/delete watches above limit:
   [junit4]   2> 
   [junit4]   2>        41      /solr/collections/collection1/terms/shard1
   [junit4]   2>        19      /solr/clusterprops.json
   [junit4]   2>        19      /solr/aliases.json
   [junit4]   2>        18      /solr/security.json
   [junit4]   2>        11      /solr/configs/conf
   [junit4]   2>        9       /solr/collections/testMetricTrigger/terms/shard1
   [junit4]   2>        2       /solr/collections/testMetricTrigger/terms/shard2
   [junit4]   2> 
   [junit4]   2> Maximum concurrent data watches above limit:
   [junit4]   2> 
   [junit4]   2>        103     /solr/collections/collection1/state.json
   [junit4]   2>        42      /solr/collections/testMetricTrigger/state.json
   [junit4]   2>        19      /solr/clusterstate.json
   [junit4]   2>        6       /solr/autoscaling.json
   [junit4]   2>        3       
/solr/collections/collection1/leader_elect/shard1/election/73273139632996397-core_node6-n_0000000002
   [junit4]   2>        3       
/solr/overseer_elect/election/73273139632996375-127.0.0.1:36236_solr-n_0000000006
   [junit4]   2>        2       
/solr/collections/collection1/leader_elect/shard1/election/73273139632996391-core_node4-n_0000000001
   [junit4]   2>        2       
/solr/overseer_elect/election/73273139632996366-127.0.0.1:36255_solr-n_0000000003
   [junit4]   2>        2       
/solr/overseer_elect/election/73273139632996385-127.0.0.1:32890_solr-n_0000000009
   [junit4]   2>        2       
/solr/overseer_elect/election/73273139632996403-127.0.0.1:41970_solr-n_0000000015
   [junit4]   2> 
   [junit4]   2> Maximum concurrent children watches above limit:
   [junit4]   2> 
   [junit4]   2>        19      /solr/live_nodes
   [junit4]   2>        19      /solr/collections
   [junit4]   2>        6       /solr/overseer/queue-work
   [junit4]   2>        6       /solr/autoscaling/events/.auto_add_replicas
   [junit4]   2>        6       /solr/overseer/collection-queue-work
   [junit4]   2>        5       /solr/overseer/queue
   [junit4]   2>        2       /solr/autoscaling/events/node_lost_triggerMR
   [junit4]   2>        2       /solr/autoscaling/events/node_added_triggerCTOOR
   [junit4]   2> 
   [junit4]   2> NOTE: leaving temporary files on disk at: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.TriggerIntegrationTest_B2B0A5BDC44833E9-001
   [junit4]   2> Feb 10, 2018 8:54:02 PM 
com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
   [junit4]   2> WARNING: Will linger awaiting termination of 1 leaked 
thread(s).
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene70): 
{id=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))),
 x_s=PostingsFormat(name=Direct)}, docValues:{}, maxPointsInLeafNode=883, 
maxMBSortInHeap=6.882601939178405, 
sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@20c1ff37),
 locale=de-AT, timezone=Europe/Madrid
   [junit4]   2> NOTE: Linux 3.13.0-88-generic amd64/Oracle Corporation 
1.8.0_144 (64-bit)/cpus=4,threads=1,free=142518912,total=515375104
   [junit4]   2> NOTE: All tests run in this JVM: [TestSQLHandler, 
SaslZkACLProviderTest, NumberUtilsTest, AutoAddReplicasPlanActionTest, 
TestRangeQuery, TestCorePropertiesReload, TestLazyCores, TestRebalanceLeaders, 
TestZkAclsWithHadoopAuth, PingRequestHandlerTest, RegexBoostProcessorTest, 
CachingDirectoryFactoryTest, AddSchemaFieldsUpdateProcessorFactoryTest, 
MultiTermTest, TestScoreJoinQPScore, TestSortableTextField, 
CloneFieldUpdateProcessorFactoryTest, PeerSyncReplicationTest, 
TestCloudSearcherWarming, TestStressLiveNodes, 
ShufflingReplicaListTransformerTest, TestConfigReload, 
ClassificationUpdateProcessorFactoryTest, TestHttpShardHandlerFactory, 
TestRecoveryHdfs, SpellCheckComponentTest, JSONWriterTest, 
TestDefaultStatsCache, ChaosMonkeyNothingIsSafeWithPullReplicasTest, 
SegmentsInfoRequestHandlerTest, StressHdfsTest, 
TestExclusionRuleCollectionAccess, CleanupOldIndexTest, TestTolerantSearch, 
TestUniqueKeyFieldResource, DirectoryFactoryTest, RestartWhileUpdatingTest, 
SpatialRPTFieldTypeTest, TestCollectionAPIs, 
BigEndianAscendingWordSerializerTest, FacetPivotSmallTest, 
TestSolrQueryResponse, TestSegmentSorting, TestRandomCollapseQParserPlugin, 
TestQueryTypes, WordBreakSolrSpellCheckerTest, TestManagedSchema, 
DirectSolrSpellCheckerTest, AnalyticsMergeStrategyTest, SuggesterTSTTest, 
TestMultiWordSynonyms, TolerantUpdateProcessorTest, CursorMarkTest, 
HdfsTlogReplayBufferedWhileIndexingTest, TestOnReconnectListenerSupport, 
TestCodecSupport, DistributedQueryComponentCustomSortTest, TestNumericTerms64, 
TestReplicationHandlerBackup, ZkShardTermsTest, AnalysisErrorHandlingTest, 
ZkStateWriterTest, TestAtomicUpdateErrorCases, SuggestComponentTest, 
TestSuggestSpellingConverter, DateFieldTest, TestSolrDeletionPolicy2, 
CustomHighlightComponentTest, ForceLeaderTest, TestJmxIntegration, 
SearchHandlerTest, ResponseBuilderTest, ParsingFieldUpdateProcessorsTest, 
TestUpdate, ClusterStateTest, ShowFileRequestHandlerTest, 
TestStressUserVersions, TestSlowCompositeReaderWrapper, 
TestFieldCacheWithThreads, UtilsToolTest, ExecutePlanActionTest, 
BaseCdcrDistributedZkTest, TestRealTimeGet, TestDistribStateManager, 
NoCacheHeaderTest, MoreLikeThisHandlerTest, LeaderElectionIntegrationTest, 
BasicAuthStandaloneTest, TestBlendedInfixSuggestions, TestSimpleQParserPlugin, 
TestDistributedMissingSort, TestGraphMLResponseWriter, SolrCloudExampleTest, 
MetricsHandlerTest, FullHLLTest, NumericFieldsTest, 
TestPKIAuthenticationPlugin, TestSkipOverseerOperations, TestExactStatsCache, 
TestSolrConfigHandlerConcurrent, TestExceedMaxTermLength, TestFaceting, 
TestRawResponseWriter, DocValuesMultiTest, TriggerIntegrationTest]
   [junit4] Completed [358/776 (3!)] on J2 in 199.42s, 14 tests, 1 failure <<< 
FAILURES!

[...truncated 49519 lines...]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]

Reply via email to