Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-6.6/1/

2 tests failed.
FAILED:  org.apache.lucene.search.TestInetAddressRangeQueries.testRandomBig

Error Message:
Java heap space

Stack Trace:
java.lang.OutOfMemoryError: Java heap space
        at 
__randomizedtesting.SeedInfo.seed([EFC3920735F90CD1:6894EF88A4A07051]:0)
        at 
org.apache.lucene.util.bkd.HeapPointWriter.writePackedValue(HeapPointWriter.java:107)
        at 
org.apache.lucene.util.bkd.HeapPointWriter.append(HeapPointWriter.java:128)
        at org.apache.lucene.util.bkd.PointReader.split(PointReader.java:74)
        at 
org.apache.lucene.util.bkd.OfflinePointReader.split(OfflinePointReader.java:169)
        at org.apache.lucene.util.bkd.BKDWriter.build(BKDWriter.java:1791)
        at org.apache.lucene.util.bkd.BKDWriter.build(BKDWriter.java:1805)
        at org.apache.lucene.util.bkd.BKDWriter.build(BKDWriter.java:1805)
        at org.apache.lucene.util.bkd.BKDWriter.build(BKDWriter.java:1818)
        at org.apache.lucene.util.bkd.BKDWriter.finish(BKDWriter.java:1008)
        at 
org.apache.lucene.codecs.lucene60.Lucene60PointsWriter.writeField(Lucene60PointsWriter.java:128)
        at 
org.apache.lucene.codecs.PointsWriter.mergeOneField(PointsWriter.java:58)
        at org.apache.lucene.codecs.PointsWriter.merge(PointsWriter.java:173)
        at 
org.apache.lucene.codecs.lucene60.Lucene60PointsWriter.merge(Lucene60PointsWriter.java:142)
        at 
org.apache.lucene.codecs.asserting.AssertingPointsFormat$AssertingPointsWriter.merge(AssertingPointsFormat.java:274)
        at 
org.apache.lucene.index.SegmentMerger.mergePoints(SegmentMerger.java:173)
        at org.apache.lucene.index.SegmentMerger.merge(SegmentMerger.java:122)
        at 
org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4356)
        at org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:3931)
        at 
org.apache.lucene.index.SerialMergeScheduler.merge(SerialMergeScheduler.java:40)
        at org.apache.lucene.index.IndexWriter.maybeMerge(IndexWriter.java:2083)
        at 
org.apache.lucene.index.IndexWriter.doAfterSegmentFlushed(IndexWriter.java:5005)
        at 
org.apache.lucene.index.DocumentsWriter$MergePendingEvent.process(DocumentsWriter.java:731)
        at 
org.apache.lucene.index.IndexWriter.processEvents(IndexWriter.java:5043)
        at 
org.apache.lucene.index.IndexWriter.processEvents(IndexWriter.java:5034)
        at 
org.apache.lucene.index.IndexWriter.updateDocument(IndexWriter.java:1574)
        at 
org.apache.lucene.index.IndexWriter.addDocument(IndexWriter.java:1316)
        at 
org.apache.lucene.search.BaseRangeFieldQueryTestCase.verify(BaseRangeFieldQueryTestCase.java:188)
        at 
org.apache.lucene.search.BaseRangeFieldQueryTestCase.doTestRandom(BaseRangeFieldQueryTestCase.java:158)
        at 
org.apache.lucene.search.BaseRangeFieldQueryTestCase.testRandomBig(BaseRangeFieldQueryTestCase.java:73)
        at 
org.apache.lucene.search.TestInetAddressRangeQueries.testRandomBig(TestInetAddressRangeQueries.java:69)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at 
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)


FAILED:  org.apache.solr.cloud.hdfs.HdfsUnloadDistributedZkTest.test

Error Message:
Error from server at http://127.0.0.1:49964/_l/el: Error CREATEing SolrCore 
'test_unload_shard_and_collection_2': Unable to create core 
[test_unload_shard_and_collection_2] Caused by: Direct buffer memory

Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error 
from server at http://127.0.0.1:49964/_l/el: Error CREATEing SolrCore 
'test_unload_shard_and_collection_2': Unable to create core 
[test_unload_shard_and_collection_2] Caused by: Direct buffer memory
        at 
__randomizedtesting.SeedInfo.seed([D7F66C5188A04917:5FA2538B265C24EF]:0)
        at 
org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:610)
        at 
org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:279)
        at 
org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:268)
        at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1219)
        at 
org.apache.solr.cloud.UnloadDistributedZkTest.testUnloadShardAndCollection(UnloadDistributedZkTest.java:133)
        at 
org.apache.solr.cloud.UnloadDistributedZkTest.test(UnloadDistributedZkTest.java:70)
        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:1713)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
        at 
org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:992)
        at 
org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:967)
        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:916)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
        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:745)




Build Log:
[...truncated 8265 lines...]
   [junit4] Suite: org.apache.lucene.search.TestInetAddressRangeQueries
   [junit4]   2> NOTE: download the large Jenkins line-docs file by running 
'ant get-jenkins-line-docs' in the lucene directory.
   [junit4]   2> NOTE: reproduce with: ant test  
-Dtestcase=TestInetAddressRangeQueries -Dtests.method=testRandomBig 
-Dtests.seed=EFC3920735F90CD1 -Dtests.multiplier=2 -Dtests.nightly=true 
-Dtests.slow=true 
-Dtests.linedocsfile=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/test-data/enwiki.random.lines.txt
 -Dtests.locale=es-CL -Dtests.timezone=Africa/Juba -Dtests.asserts=true 
-Dtests.file.encoding=ISO-8859-1
   [junit4] ERROR    172s J1 | TestInetAddressRangeQueries.testRandomBig <<<
   [junit4]    > Throwable #1: java.lang.OutOfMemoryError: Java heap space
   [junit4]    >        at 
__randomizedtesting.SeedInfo.seed([EFC3920735F90CD1:6894EF88A4A07051]:0)
   [junit4]    >        at 
org.apache.lucene.util.bkd.HeapPointWriter.writePackedValue(HeapPointWriter.java:107)
   [junit4]    >        at 
org.apache.lucene.util.bkd.HeapPointWriter.append(HeapPointWriter.java:128)
   [junit4]    >        at 
org.apache.lucene.util.bkd.PointReader.split(PointReader.java:74)
   [junit4]    >        at 
org.apache.lucene.util.bkd.OfflinePointReader.split(OfflinePointReader.java:169)
   [junit4]    >        at 
org.apache.lucene.util.bkd.BKDWriter.build(BKDWriter.java:1791)
   [junit4]    >        at 
org.apache.lucene.util.bkd.BKDWriter.build(BKDWriter.java:1805)
   [junit4]    >        at 
org.apache.lucene.util.bkd.BKDWriter.build(BKDWriter.java:1805)
   [junit4]    >        at 
org.apache.lucene.util.bkd.BKDWriter.build(BKDWriter.java:1818)
   [junit4]    >        at 
org.apache.lucene.util.bkd.BKDWriter.finish(BKDWriter.java:1008)
   [junit4]    >        at 
org.apache.lucene.codecs.lucene60.Lucene60PointsWriter.writeField(Lucene60PointsWriter.java:128)
   [junit4]    >        at 
org.apache.lucene.codecs.PointsWriter.mergeOneField(PointsWriter.java:58)
   [junit4]    >        at 
org.apache.lucene.codecs.PointsWriter.merge(PointsWriter.java:173)
   [junit4]    >        at 
org.apache.lucene.codecs.lucene60.Lucene60PointsWriter.merge(Lucene60PointsWriter.java:142)
   [junit4]    >        at 
org.apache.lucene.codecs.asserting.AssertingPointsFormat$AssertingPointsWriter.merge(AssertingPointsFormat.java:274)
   [junit4]    >        at 
org.apache.lucene.index.SegmentMerger.mergePoints(SegmentMerger.java:173)
   [junit4]    >        at 
org.apache.lucene.index.SegmentMerger.merge(SegmentMerger.java:122)
   [junit4]    >        at 
org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4356)
   [junit4]    >        at 
org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:3931)
   [junit4]    >        at 
org.apache.lucene.index.SerialMergeScheduler.merge(SerialMergeScheduler.java:40)
   [junit4]    >        at 
org.apache.lucene.index.IndexWriter.maybeMerge(IndexWriter.java:2083)
   [junit4]    >        at 
org.apache.lucene.index.IndexWriter.doAfterSegmentFlushed(IndexWriter.java:5005)
   [junit4]    >        at 
org.apache.lucene.index.DocumentsWriter$MergePendingEvent.process(DocumentsWriter.java:731)
   [junit4]    >        at 
org.apache.lucene.index.IndexWriter.processEvents(IndexWriter.java:5043)
   [junit4]    >        at 
org.apache.lucene.index.IndexWriter.processEvents(IndexWriter.java:5034)
   [junit4]    >        at 
org.apache.lucene.index.IndexWriter.updateDocument(IndexWriter.java:1574)
   [junit4]    >        at 
org.apache.lucene.index.IndexWriter.addDocument(IndexWriter.java:1316)
   [junit4]    >        at 
org.apache.lucene.search.BaseRangeFieldQueryTestCase.verify(BaseRangeFieldQueryTestCase.java:188)
   [junit4]    >        at 
org.apache.lucene.search.BaseRangeFieldQueryTestCase.doTestRandom(BaseRangeFieldQueryTestCase.java:158)
   [junit4]    >        at 
org.apache.lucene.search.BaseRangeFieldQueryTestCase.testRandomBig(BaseRangeFieldQueryTestCase.java:73)
   [junit4]    >        at 
org.apache.lucene.search.TestInetAddressRangeQueries.testRandomBig(TestInetAddressRangeQueries.java:69)
   [junit4]   2> NOTE: leaving temporary files on disk at: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/lucene/build/misc/test/J1/temp/lucene.search.TestInetAddressRangeQueries_EFC3920735F90CD1-001
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene62), 
sim=RandomSimilarity(queryNorm=false,coord=no): {}, locale=es-CL, 
timezone=Africa/Juba
   [junit4]   2> NOTE: Linux 3.13.0-88-generic amd64/Oracle Corporation 
1.8.0_121 (64-bit)/cpus=4,threads=1,free=210295960,total=290455552
   [junit4]   2> NOTE: All tests run in this JVM: [TestFieldCacheReopen, 
TestRAFDirectory, TestDocValuesStatsCollector, TestUninvertingReader, 
TestLegacyFieldCache, TestIndexSplitter, TestMultiPassIndexSplitter, 
TestHighFreqTerms, SweetSpotSimilarityTest, TestInetAddressPoint, 
TestLazyDocument, TestDiversifiedTopDocsCollector, TestInetAddressRangeQueries]
   [junit4] Completed [26/26 (1!)] on J1 in 176.79s, 4 tests, 1 error <<< 
FAILURES!

[...truncated 1 lines...]
   [junit4] JVM J1: stdout was not empty, see: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/lucene/build/misc/test/temp/junit4-J1-20170512_054800_3002652058257186444258.sysout
   [junit4] >>> JVM J1 emitted unexpected output (verbatim) ----
   [junit4] java.lang.OutOfMemoryError: Java heap space
   [junit4] Dumping heap to 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/heapdumps/java_pid15565.hprof
 ...
   [junit4] Heap dump file created [563682855 bytes in 3.631 secs]
   [junit4] <<< JVM J1: EOF ----

[...truncated 5062 lines...]
   [junit4] Suite: org.apache.solr.cloud.hdfs.HdfsUnloadDistributedZkTest
   [junit4]   2> Creating dataDir: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsUnloadDistributedZkTest_D7F66C5188A04917-001/init-core-data-001
   [junit4]   2> 3535262 WARN  
(SUITE-HdfsUnloadDistributedZkTest-seed#[D7F66C5188A04917]-worker) [    ] 
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=44 numCloses=44
   [junit4]   2> 3535263 INFO  
(SUITE-HdfsUnloadDistributedZkTest-seed#[D7F66C5188A04917]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Using TrieFields
   [junit4]   2> 3535264 INFO  
(SUITE-HdfsUnloadDistributedZkTest-seed#[D7F66C5188A04917]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: 
@org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl=https://issues.apache.org/jira/browse/SOLR-5776)
   [junit4]   2> 3535264 INFO  
(SUITE-HdfsUnloadDistributedZkTest-seed#[D7F66C5188A04917]-worker) [    ] 
o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /_l/el
   [junit4]   1> Formatting using clusterid: testClusterID
   [junit4]   2> 3535300 WARN  
(SUITE-HdfsUnloadDistributedZkTest-seed#[D7F66C5188A04917]-worker) [    ] 
o.a.h.m.i.MetricsConfig Cannot locate configuration: tried 
hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
   [junit4]   2> 3535305 WARN  
(SUITE-HdfsUnloadDistributedZkTest-seed#[D7F66C5188A04917]-worker) [    ] 
o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
   [junit4]   2> 3535306 INFO  
(SUITE-HdfsUnloadDistributedZkTest-seed#[D7F66C5188A04917]-worker) [    ] 
o.m.log jetty-6.1.26
   [junit4]   2> 3535319 INFO  
(SUITE-HdfsUnloadDistributedZkTest-seed#[D7F66C5188A04917]-worker) [    ] 
o.m.log Extract 
jar:file:/x1/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.7.2-tests.jar!/webapps/hdfs
 to ./temp/Jetty_localhost_59022_hdfs____.7d9yq2/webapp
   [junit4]   2> 3535708 INFO  
(SUITE-HdfsUnloadDistributedZkTest-seed#[D7F66C5188A04917]-worker) [    ] 
o.m.log Started 
HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:59022
   [junit4]   2> 3535757 WARN  
(SUITE-HdfsUnloadDistributedZkTest-seed#[D7F66C5188A04917]-worker) [    ] 
o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
   [junit4]   2> 3535758 INFO  
(SUITE-HdfsUnloadDistributedZkTest-seed#[D7F66C5188A04917]-worker) [    ] 
o.m.log jetty-6.1.26
   [junit4]   2> 3535770 INFO  
(SUITE-HdfsUnloadDistributedZkTest-seed#[D7F66C5188A04917]-worker) [    ] 
o.m.log Extract 
jar:file:/x1/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.7.2-tests.jar!/webapps/datanode
 to ./temp/Jetty_localhost_60318_datanode____ehkbd3/webapp
   [junit4]   2> 3536116 INFO  
(SUITE-HdfsUnloadDistributedZkTest-seed#[D7F66C5188A04917]-worker) [    ] 
o.m.log Started 
HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:60318
   [junit4]   2> 3536150 WARN  
(SUITE-HdfsUnloadDistributedZkTest-seed#[D7F66C5188A04917]-worker) [    ] 
o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
   [junit4]   2> 3536152 INFO  
(SUITE-HdfsUnloadDistributedZkTest-seed#[D7F66C5188A04917]-worker) [    ] 
o.m.log jetty-6.1.26
   [junit4]   2> 3536165 INFO  
(SUITE-HdfsUnloadDistributedZkTest-seed#[D7F66C5188A04917]-worker) [    ] 
o.m.log Extract 
jar:file:/x1/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.7.2-tests.jar!/webapps/datanode
 to ./temp/Jetty_localhost_39726_datanode____.rkn1ms/webapp
   [junit4]   2> 3536214 INFO  (IPC Server handler 2 on 60156) [    ] 
BlockStateChange BLOCK* processReport: from storage 
DS-f3949cb9-882e-4a03-9d28-cad2f5805fc0 node 
DatanodeRegistration(127.0.0.1:42137, 
datanodeUuid=87e0369f-bdd3-4708-941d-696ac931261d, infoPort=60419, 
infoSecurePort=0, ipcPort=59484, 
storageInfo=lv=-56;cid=testClusterID;nsid=787835320;c=0), blocks: 0, 
hasStaleStorage: true, processing time: 0 msecs
   [junit4]   2> 3536214 INFO  (IPC Server handler 2 on 60156) [    ] 
BlockStateChange BLOCK* processReport: from storage 
DS-dcce9e45-3fa8-4a13-9189-edf43e53290b node 
DatanodeRegistration(127.0.0.1:42137, 
datanodeUuid=87e0369f-bdd3-4708-941d-696ac931261d, infoPort=60419, 
infoSecurePort=0, ipcPort=59484, 
storageInfo=lv=-56;cid=testClusterID;nsid=787835320;c=0), blocks: 0, 
hasStaleStorage: false, processing time: 0 msecs
   [junit4]   2> 3536554 INFO  
(SUITE-HdfsUnloadDistributedZkTest-seed#[D7F66C5188A04917]-worker) [    ] 
o.m.log Started 
HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:39726
   [junit4]   2> 3536641 INFO  (IPC Server handler 8 on 60156) [    ] 
BlockStateChange BLOCK* processReport: from storage 
DS-282dc7a8-29ba-4ad9-8b31-06a2a07a9dac node 
DatanodeRegistration(127.0.0.1:46961, 
datanodeUuid=1e58d9d4-53a8-469b-8fe0-a2728eca1df3, infoPort=36371, 
infoSecurePort=0, ipcPort=39940, 
storageInfo=lv=-56;cid=testClusterID;nsid=787835320;c=0), blocks: 0, 
hasStaleStorage: true, processing time: 0 msecs
   [junit4]   2> 3536641 INFO  (IPC Server handler 8 on 60156) [    ] 
BlockStateChange BLOCK* processReport: from storage 
DS-c193ab86-c5e7-4bd2-91f4-cd1524650382 node 
DatanodeRegistration(127.0.0.1:46961, 
datanodeUuid=1e58d9d4-53a8-469b-8fe0-a2728eca1df3, infoPort=36371, 
infoSecurePort=0, ipcPort=39940, 
storageInfo=lv=-56;cid=testClusterID;nsid=787835320;c=0), blocks: 0, 
hasStaleStorage: false, processing time: 0 msecs
   [junit4]   2> 3536712 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 3536713 INFO  (Thread-77740) [    ] o.a.s.c.ZkTestServer 
client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 3536713 INFO  (Thread-77740) [    ] o.a.s.c.ZkTestServer 
Starting server
   [junit4]   2> 3536715 ERROR (Thread-77740) [    ] 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> 3536813 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.c.ZkTestServer start zk server on port:44177
   [junit4]   2> 3536825 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml
 to /configs/conf1/solrconfig.xml
   [junit4]   2> 3536827 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/core/src/test-files/solr/collection1/conf/schema.xml
 to /configs/conf1/schema.xml
   [junit4]   2> 3536829 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml
 to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 3536831 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/core/src/test-files/solr/collection1/conf/stopwords.txt
 to /configs/conf1/stopwords.txt
   [junit4]   2> 3536833 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/core/src/test-files/solr/collection1/conf/protwords.txt
 to /configs/conf1/protwords.txt
   [junit4]   2> 3536834 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/core/src/test-files/solr/collection1/conf/currency.xml
 to /configs/conf1/currency.xml
   [junit4]   2> 3536836 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml
 to /configs/conf1/enumsConfig.xml
   [junit4]   2> 3536837 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json
 to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 3536839 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt
 to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 3536841 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt
 to /configs/conf1/old_synonyms.txt
   [junit4]   2> 3536842 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/core/src/test-files/solr/collection1/conf/synonyms.txt
 to /configs/conf1/synonyms.txt
   [junit4]   2> 3536957 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.SolrTestCaseJ4 Writing core.properties file to 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsUnloadDistributedZkTest_D7F66C5188A04917-001/control-001/cores/collection1
   [junit4]   2> 3536959 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 3536960 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@4194a188{/_l/el,null,AVAILABLE}
   [junit4]   2> 3536961 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@7cb2b958{HTTP/1.1,[http/1.1]}{127.0.0.1:54521}
   [junit4]   2> 3536961 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.e.j.s.Server Started @3540118ms
   [junit4]   2> 3536961 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: 
{solr.data.dir=hdfs://localhost:60156/hdfs__localhost_60156__x1_jenkins_jenkins-slave_workspace_Lucene-Solr-NightlyTests-6.6_checkout_solr_build_solr-core_test_J0_temp_solr.cloud.hdfs.HdfsUnloadDistributedZkTest_D7F66C5188A04917-001_tempDir-002_control_data,
 hostContext=/_l/el, hostPort=54521, 
coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/build/solr-core/test/J0/../../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsUnloadDistributedZkTest_D7F66C5188A04917-001/control-001/cores}
   [junit4]   2> 3536961 ERROR 
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 3536962 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
6.6.0
   [junit4]   2> 3536962 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3536962 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3536962 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-05-12T08:04:40.260Z
   [junit4]   2> 3536964 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in 
ZooKeeper)
   [junit4]   2> 3536964 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.c.SolrXmlConfig Loading container configuration from 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsUnloadDistributedZkTest_D7F66C5188A04917-001/control-001/solr.xml
   [junit4]   2> 3536971 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: 
socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 3536972 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44177/solr
   [junit4]   2> 3536994 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) 
[n:127.0.0.1:54521__l%2Fel    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3536995 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) 
[n:127.0.0.1:54521__l%2Fel    ] o.a.s.c.OverseerElectionContext I am going to 
be the leader 127.0.0.1:54521__l%2Fel
   [junit4]   2> 3536996 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) 
[n:127.0.0.1:54521__l%2Fel    ] o.a.s.c.Overseer Overseer 
(id=97948551086866436-127.0.0.1:54521__l%2Fel-n_0000000000) starting
   [junit4]   2> 3537003 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) 
[n:127.0.0.1:54521__l%2Fel    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:54521__l%2Fel
   [junit4]   2> 3537005 INFO  
(zkCallback-26440-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 3537100 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) 
[n:127.0.0.1:54521__l%2Fel    ] o.a.s.c.CorePropertiesLocator Found 1 core 
definitions underneath 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/build/solr-core/test/J0/../../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsUnloadDistributedZkTest_D7F66C5188A04917-001/control-001/cores
   [junit4]   2> 3537100 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) 
[n:127.0.0.1:54521__l%2Fel    ] o.a.s.c.CorePropertiesLocator Cores are: 
[collection1]
   [junit4]   2> 3537101 INFO  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 
transient cores
   [junit4]   2> 3537106 INFO  
(OverseerStateUpdate-97948551086866436-127.0.0.1:54521__l%2Fel-n_0000000000) 
[n:127.0.0.1:54521__l%2Fel    ] o.a.s.c.o.ReplicaMutator Assigning new node to 
shard shard=shard1
   [junit4]   2> 3538124 WARN  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] o.a.s.c.Config 
Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> 
instead.
   [junit4]   2> 3538125 INFO  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.0
   [junit4]   2> 3538140 INFO  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 3538276 INFO  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 3538289 INFO  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from 
collection control_collection, trusted=true
   [junit4]   2> 3538289 INFO  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.c.HdfsDirectoryFactory 
solr.hdfs.home=hdfs://localhost:60156/solr_hdfs_home
   [junit4]   2> 3538289 INFO  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
   [junit4]   2> 3538289 INFO  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 3538290 INFO  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at 
[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsUnloadDistributedZkTest_D7F66C5188A04917-001/control-001/cores/collection1],
 
dataDir=[hdfs://localhost:60156/solr_hdfs_home/control_collection/core_node1/data/]
   [junit4]   2> 3538290 INFO  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX 
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2d78bdc1
   [junit4]   2> 3538290 INFO  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:60156/solr_hdfs_home/control_collection/core_node1/data/snapshot_metadata
   [junit4]   2> 3538298 INFO  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct 
memory allocation set to [true]
   [junit4]   2> 3538298 INFO  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.c.HdfsDirectoryFactory Block cache target memory usage, slab size of 
[8388608] will allocate [1] slabs and use ~[8388608] bytes
   [junit4]   2> 3538298 INFO  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.c.HdfsDirectoryFactory Creating new single instance HDFS BlockCache
   [junit4]   2> 3538304 INFO  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.s.b.BlockDirectory Block cache on write is disabled
   [junit4]   2> 3538304 INFO  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:60156/solr_hdfs_home/control_collection/core_node1/data
   [junit4]   2> 3538320 INFO  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:60156/solr_hdfs_home/control_collection/core_node1/data/index
   [junit4]   2> 3538326 INFO  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct 
memory allocation set to [true]
   [junit4]   2> 3538326 INFO  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.c.HdfsDirectoryFactory Block cache target memory usage, slab size of 
[8388608] will allocate [1] slabs and use ~[8388608] bytes
   [junit4]   2> 3538326 INFO  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.c.HdfsDirectoryFactory Creating new single instance HDFS BlockCache
   [junit4]   2> 3538331 INFO  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.s.b.BlockDirectory Block cache on write is disabled
   [junit4]   2> 3538332 INFO  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: 
minMergeSize=1000, mergeFactor=22, maxMergeSize=9223372036854775807, 
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, 
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=1.0]
   [junit4]   2> 3538346 INFO  (IPC Server handler 2 on 60156) [    ] 
BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:46961 is 
added to blk_1073741825_1001{UCState=UNDER_CONSTRUCTION, truncateBlock=null, 
primaryNodeIndex=-1, 
replicas=[ReplicaUC[[DISK]DS-f3949cb9-882e-4a03-9d28-cad2f5805fc0:NORMAL:127.0.0.1:42137|RBW],
 
ReplicaUC[[DISK]DS-c193ab86-c5e7-4bd2-91f4-cd1524650382:NORMAL:127.0.0.1:46961|RBW]]}
 size 0
   [junit4]   2> 3538347 INFO  (IPC Server handler 7 on 60156) [    ] 
BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:42137 is 
added to blk_1073741825_1001{UCState=UNDER_CONSTRUCTION, truncateBlock=null, 
primaryNodeIndex=-1, 
replicas=[ReplicaUC[[DISK]DS-c193ab86-c5e7-4bd2-91f4-cd1524650382:NORMAL:127.0.0.1:46961|RBW],
 
ReplicaUC[[DISK]DS-dcce9e45-3fa8-4a13-9189-edf43e53290b:NORMAL:127.0.0.1:42137|FINALIZED]]}
 size 0
   [junit4]   2> 3538355 WARN  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = 
requestHandler,name = /dump,class = DumpRequestHandler,attributes = 
{initParams=a, name=/dump, class=DumpRequestHandler},args = 
{defaults={a=A,b=B}}}
   [junit4]   2> 3538400 INFO  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.HdfsUpdateLog
   [junit4]   2> 3538400 INFO  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 3538400 INFO  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.u.HdfsUpdateLog Initializing HdfsUpdateLog: tlogDfsReplication=2
   [junit4]   2> 3538411 INFO  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 3538411 INFO  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 3538412 INFO  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: 
minMergeSize=0, mergeFactor=10, maxMergeSize=300639073, 
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, 
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.1]
   [junit4]   2> 3538416 INFO  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@47774100[collection1] main]
   [junit4]   2> 3538417 INFO  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf1
   [junit4]   2> 3538417 INFO  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 3538417 INFO  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 3538419 INFO  
(searcherExecutor-12186-thread-1-processing-n:127.0.0.1:54521__l%2Fel 
x:collection1 c:control_collection) [n:127.0.0.1:54521__l%2Fel 
c:control_collection   x:collection1] o.a.s.c.SolrCore [collection1] Registered 
new searcher Searcher@47774100[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 3538420 INFO  
(coreLoadExecutor-12185-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel c:control_collection   x:collection1] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1567176819178733568
   [junit4]   2> 3538427 INFO  
(coreZkRegister-12178-thread-1-processing-n:127.0.0.1:54521__l%2Fel 
x:collection1 c:control_collection) [n:127.0.0.1:54521__l%2Fel 
c:control_collection s:shard1 r:core_node1 x:collection1] 
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 3538427 INFO  
(coreZkRegister-12178-thread-1-processing-n:127.0.0.1:54521__l%2Fel 
x:collection1 c:control_collection) [n:127.0.0.1:54521__l%2Fel 
c:control_collection s:shard1 r:core_node1 x:collection1] 
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 3538427 INFO  
(coreZkRegister-12178-thread-1-processing-n:127.0.0.1:54521__l%2Fel 
x:collection1 c:control_collection) [n:127.0.0.1:54521__l%2Fel 
c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy 
Sync replicas to http://127.0.0.1:54521/_l/el/collection1/
   [junit4]   2> 3538427 INFO  
(coreZkRegister-12178-thread-1-processing-n:127.0.0.1:54521__l%2Fel 
x:collection1 c:control_collection) [n:127.0.0.1:54521__l%2Fel 
c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy 
Sync Success - now sync replicas to me
   [junit4]   2> 3538427 INFO  
(coreZkRegister-12178-thread-1-processing-n:127.0.0.1:54521__l%2Fel 
x:collection1 c:control_collection) [n:127.0.0.1:54521__l%2Fel 
c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy 
http://127.0.0.1:54521/_l/el/collection1/ has no replicas
   [junit4]   2> 3538427 INFO  
(coreZkRegister-12178-thread-1-processing-n:127.0.0.1:54521__l%2Fel 
x:collection1 c:control_collection) [n:127.0.0.1:54521__l%2Fel 
c:control_collection s:shard1 r:core_node1 x:collection1] 
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in 
election, clear LIR
   [junit4]   2> 3538431 INFO  
(coreZkRegister-12178-thread-1-processing-n:127.0.0.1:54521__l%2Fel 
x:collection1 c:control_collection) [n:127.0.0.1:54521__l%2Fel 
c:control_collection s:shard1 r:core_node1 x:collection1] 
o.a.s.c.ShardLeaderElectionContext I am the new leader: 
http://127.0.0.1:54521/_l/el/collection1/ shard1
   [junit4]   2> 3538581 INFO  
(coreZkRegister-12178-thread-1-processing-n:127.0.0.1:54521__l%2Fel 
x:collection1 c:control_collection) [n:127.0.0.1:54521__l%2Fel 
c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController 
I am the leader, no recovery necessary
   [junit4]   2> 3538612 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 3538613 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:44177/solr ready
   [junit4]   2> 3538613 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.c.ChaosMonkey monkey: init - expire sessions:false cause connection 
loss:false
   [junit4]   2> 3538613 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.c.AbstractFullDistribZkTestBase Creating collection1 with stateFormat=2
   [junit4]   2> 3538746 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.SolrTestCaseJ4 Writing core.properties file to 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsUnloadDistributedZkTest_D7F66C5188A04917-001/shard-1-001/cores/collection1
   [junit4]   2> 3538747 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.c.AbstractFullDistribZkTestBase create jetty 1 in directory 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsUnloadDistributedZkTest_D7F66C5188A04917-001/shard-1-001
   [junit4]   2> 3538747 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 3538749 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@7977e32a{/_l/el,null,AVAILABLE}
   [junit4]   2> 3538749 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@13c98bb1{HTTP/1.1,[http/1.1]}{127.0.0.1:49964}
   [junit4]   2> 3538749 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.e.j.s.Server Started @3541906ms
   [junit4]   2> 3538749 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: 
{solr.data.dir=hdfs://localhost:60156/hdfs__localhost_60156__x1_jenkins_jenkins-slave_workspace_Lucene-Solr-NightlyTests-6.6_checkout_solr_build_solr-core_test_J0_temp_solr.cloud.hdfs.HdfsUnloadDistributedZkTest_D7F66C5188A04917-001_tempDir-002_jetty1,
 solrconfig=solrconfig.xml, hostContext=/_l/el, hostPort=49964, 
coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsUnloadDistributedZkTest_D7F66C5188A04917-001/shard-1-001/cores}
   [junit4]   2> 3538750 ERROR 
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 3538750 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
6.6.0
   [junit4]   2> 3538750 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3538750 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3538750 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-05-12T08:04:42.048Z
   [junit4]   2> 3538752 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in 
ZooKeeper)
   [junit4]   2> 3538752 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.c.SolrXmlConfig Loading container configuration from 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsUnloadDistributedZkTest_D7F66C5188A04917-001/shard-1-001/solr.xml
   [junit4]   2> 3538759 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: 
socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 3538760 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44177/solr
   [junit4]   2> 3538769 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) 
[n:127.0.0.1:49964__l%2Fel    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 3538772 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) 
[n:127.0.0.1:49964__l%2Fel    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3538774 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) 
[n:127.0.0.1:49964__l%2Fel    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:49964__l%2Fel
   [junit4]   2> 3538775 INFO  (zkCallback-26444-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 3538775 INFO  
(zkCallback-26440-thread-1-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (2)
   [junit4]   2> 3538777 INFO  
(zkCallback-26450-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (2)
   [junit4]   2> 3538847 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) 
[n:127.0.0.1:49964__l%2Fel    ] o.a.s.c.CorePropertiesLocator Found 1 core 
definitions underneath 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsUnloadDistributedZkTest_D7F66C5188A04917-001/shard-1-001/cores
   [junit4]   2> 3538847 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) 
[n:127.0.0.1:49964__l%2Fel    ] o.a.s.c.CorePropertiesLocator Cores are: 
[collection1]
   [junit4]   2> 3538854 INFO  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 
transient cores
   [junit4]   2> 3538855 INFO  
(OverseerStateUpdate-97948551086866436-127.0.0.1:54521__l%2Fel-n_0000000000) 
[n:127.0.0.1:54521__l%2Fel    ] o.a.s.c.o.ReplicaMutator Assigning new node to 
shard shard=shard2
   [junit4]   2> 3538962 INFO  
(zkCallback-26450-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 3539867 WARN  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] o.a.s.c.Config 
Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> 
instead.
   [junit4]   2> 3539868 INFO  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] o.a.s.c.SolrConfig 
Using Lucene MatchVersion: 6.6.0
   [junit4]   2> 3539882 INFO  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] o.a.s.s.IndexSchema 
[collection1] Schema name=test
   [junit4]   2> 3540006 INFO  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] o.a.s.s.IndexSchema 
Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 3540018 INFO  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] o.a.s.c.CoreContainer 
Creating SolrCore 'collection1' using configuration from collection 
collection1, trusted=true
   [junit4]   2> 3540019 INFO  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] 
o.a.s.c.HdfsDirectoryFactory 
solr.hdfs.home=hdfs://localhost:60156/solr_hdfs_home
   [junit4]   2> 3540019 INFO  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] 
o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
   [junit4]   2> 3540019 INFO  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] o.a.s.c.SolrCore 
solr.RecoveryStrategy.Builder
   [junit4]   2> 3540019 INFO  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] o.a.s.c.SolrCore 
[[collection1] ] Opening new SolrCore at 
[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsUnloadDistributedZkTest_D7F66C5188A04917-001/shard-1-001/cores/collection1],
 dataDir=[hdfs://localhost:60156/solr_hdfs_home/collection1/core_node1/data/]
   [junit4]   2> 3540019 INFO  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] 
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX 
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2d78bdc1
   [junit4]   2> 3540020 INFO  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:60156/solr_hdfs_home/collection1/core_node1/data/snapshot_metadata
   [junit4]   2> 3540027 INFO  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] 
o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct 
memory allocation set to [true]
   [junit4]   2> 3540027 INFO  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] 
o.a.s.c.HdfsDirectoryFactory Block cache target memory usage, slab size of 
[8388608] will allocate [1] slabs and use ~[8388608] bytes
   [junit4]   2> 3540027 INFO  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] 
o.a.s.c.HdfsDirectoryFactory Creating new single instance HDFS BlockCache
   [junit4]   2> 3540031 INFO  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] 
o.a.s.s.b.BlockDirectory Block cache on write is disabled
   [junit4]   2> 3540032 INFO  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:60156/solr_hdfs_home/collection1/core_node1/data
   [junit4]   2> 3540047 INFO  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:60156/solr_hdfs_home/collection1/core_node1/data/index
   [junit4]   2> 3540054 INFO  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] 
o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct 
memory allocation set to [true]
   [junit4]   2> 3540054 INFO  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] 
o.a.s.c.HdfsDirectoryFactory Block cache target memory usage, slab size of 
[8388608] will allocate [1] slabs and use ~[8388608] bytes
   [junit4]   2> 3540054 INFO  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] 
o.a.s.c.HdfsDirectoryFactory Creating new single instance HDFS BlockCache
   [junit4]   2> 3540057 INFO  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] 
o.a.s.s.b.BlockDirectory Block cache on write is disabled
   [junit4]   2> 3540058 INFO  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: 
minMergeSize=1000, mergeFactor=22, maxMergeSize=9223372036854775807, 
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, 
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=1.0]
   [junit4]   2> 3540069 INFO  (IPC Server handler 3 on 60156) [    ] 
BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:42137 is 
added to blk_1073741826_1002{UCState=UNDER_CONSTRUCTION, truncateBlock=null, 
primaryNodeIndex=-1, 
replicas=[ReplicaUC[[DISK]DS-c193ab86-c5e7-4bd2-91f4-cd1524650382:NORMAL:127.0.0.1:46961|RBW],
 
ReplicaUC[[DISK]DS-f3949cb9-882e-4a03-9d28-cad2f5805fc0:NORMAL:127.0.0.1:42137|FINALIZED]]}
 size 0
   [junit4]   2> 3540070 INFO  (IPC Server handler 1 on 60156) [    ] 
BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:46961 is 
added to blk_1073741826_1002{UCState=UNDER_CONSTRUCTION, truncateBlock=null, 
primaryNodeIndex=-1, 
replicas=[ReplicaUC[[DISK]DS-f3949cb9-882e-4a03-9d28-cad2f5805fc0:NORMAL:127.0.0.1:42137|FINALIZED],
 
ReplicaUC[[DISK]DS-282dc7a8-29ba-4ad9-8b31-06a2a07a9dac:NORMAL:127.0.0.1:46961|FINALIZED]]}
 size 0
   [junit4]   2> 3540078 WARN  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] 
o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = 
requestHandler,name = /dump,class = DumpRequestHandler,attributes = 
{initParams=a, name=/dump, class=DumpRequestHandler},args = 
{defaults={a=A,b=B}}}
   [junit4]   2> 3540127 INFO  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] o.a.s.u.UpdateHandler 
Using UpdateLog implementation: org.apache.solr.update.HdfsUpdateLog
   [junit4]   2> 3540127 INFO  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] o.a.s.u.UpdateLog 
Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 
maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 3540127 INFO  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] o.a.s.u.HdfsUpdateLog 
Initializing HdfsUpdateLog: tlogDfsReplication=2
   [junit4]   2> 3540138 INFO  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] o.a.s.u.CommitTracker 
Hard AutoCommit: disabled
   [junit4]   2> 3540138 INFO  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] o.a.s.u.CommitTracker 
Soft AutoCommit: disabled
   [junit4]   2> 3540140 INFO  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: 
minMergeSize=0, mergeFactor=10, maxMergeSize=300639073, 
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, 
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.1]
   [junit4]   2> 3540144 INFO  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@6cc4dc48[collection1] main]
   [junit4]   2> 3540145 INFO  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf1
   [junit4]   2> 3540145 INFO  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 3540145 INFO  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 3540147 INFO  
(searcherExecutor-12197-thread-1-processing-n:127.0.0.1:49964__l%2Fel 
x:collection1 c:collection1) [n:127.0.0.1:49964__l%2Fel c:collection1   
x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@6cc4dc48[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 3540149 INFO  
(coreLoadExecutor-12196-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel c:collection1   x:collection1] o.a.s.u.UpdateLog 
Could not find max version in index or recent updates, using new clock 
1567176820991721472
   [junit4]   2> 3540155 INFO  
(coreZkRegister-12191-thread-1-processing-n:127.0.0.1:49964__l%2Fel 
x:collection1 c:collection1) [n:127.0.0.1:49964__l%2Fel c:collection1 s:shard2 
r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas 
found to continue.
   [junit4]   2> 3540155 INFO  
(coreZkRegister-12191-thread-1-processing-n:127.0.0.1:49964__l%2Fel 
x:collection1 c:collection1) [n:127.0.0.1:49964__l%2Fel c:collection1 s:shard2 
r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I may be the new 
leader - try and sync
   [junit4]   2> 3540155 INFO  
(coreZkRegister-12191-thread-1-processing-n:127.0.0.1:49964__l%2Fel 
x:collection1 c:collection1) [n:127.0.0.1:49964__l%2Fel c:collection1 s:shard2 
r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync replicas to 
http://127.0.0.1:49964/_l/el/collection1/
   [junit4]   2> 3540155 INFO  
(coreZkRegister-12191-thread-1-processing-n:127.0.0.1:49964__l%2Fel 
x:collection1 c:collection1) [n:127.0.0.1:49964__l%2Fel c:collection1 s:shard2 
r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync 
replicas to me
   [junit4]   2> 3540155 INFO  
(coreZkRegister-12191-thread-1-processing-n:127.0.0.1:49964__l%2Fel 
x:collection1 c:collection1) [n:127.0.0.1:49964__l%2Fel c:collection1 s:shard2 
r:core_node1 x:collection1] o.a.s.c.SyncStrategy 
http://127.0.0.1:49964/_l/el/collection1/ has no replicas
   [junit4]   2> 3540155 INFO  
(coreZkRegister-12191-thread-1-processing-n:127.0.0.1:49964__l%2Fel 
x:collection1 c:collection1) [n:127.0.0.1:49964__l%2Fel c:collection1 s:shard2 
r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Found all 
replicas participating in election, clear LIR
   [junit4]   2> 3540159 INFO  
(coreZkRegister-12191-thread-1-processing-n:127.0.0.1:49964__l%2Fel 
x:collection1 c:collection1) [n:127.0.0.1:49964__l%2Fel c:collection1 s:shard2 
r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I am the new 
leader: http://127.0.0.1:49964/_l/el/collection1/ shard2
   [junit4]   2> 3540265 INFO  
(zkCallback-26450-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 3540310 INFO  
(coreZkRegister-12191-thread-1-processing-n:127.0.0.1:49964__l%2Fel 
x:collection1 c:collection1) [n:127.0.0.1:49964__l%2Fel c:collection1 s:shard2 
r:core_node1 x:collection1] o.a.s.c.ZkController I am the leader, no recovery 
necessary
   [junit4]   2> 3540414 INFO  
(zkCallback-26450-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 3540472 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.SolrTestCaseJ4 Writing core.properties file to 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsUnloadDistributedZkTest_D7F66C5188A04917-001/shard-2-001/cores/collection1
   [junit4]   2> 3540473 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.c.AbstractFullDistribZkTestBase create jetty 2 in directory 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsUnloadDistributedZkTest_D7F66C5188A04917-001/shard-2-001
   [junit4]   2> 3540474 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 3540475 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@6a0cba19{/_l/el,null,AVAILABLE}
   [junit4]   2> 3540476 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@442d4cdc{HTTP/1.1,[http/1.1]}{127.0.0.1:57248}
   [junit4]   2> 3540476 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.e.j.s.Server Started @3543633ms
   [junit4]   2> 3540476 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: 
{solr.data.dir=hdfs://localhost:60156/hdfs__localhost_60156__x1_jenkins_jenkins-slave_workspace_Lucene-Solr-NightlyTests-6.6_checkout_solr_build_solr-core_test_J0_temp_solr.cloud.hdfs.HdfsUnloadDistributedZkTest_D7F66C5188A04917-001_tempDir-002_jetty2,
 solrconfig=solrconfig.xml, hostContext=/_l/el, hostPort=57248, 
coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsUnloadDistributedZkTest_D7F66C5188A04917-001/shard-2-001/cores}
   [junit4]   2> 3540476 ERROR 
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 3540476 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
6.6.0
   [junit4]   2> 3540477 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3540477 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3540477 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-05-12T08:04:43.775Z
   [junit4]   2> 3540479 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in 
ZooKeeper)
   [junit4]   2> 3540479 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.c.SolrXmlConfig Loading container configuration from 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsUnloadDistributedZkTest_D7F66C5188A04917-001/shard-2-001/solr.xml
   [junit4]   2> 3540486 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: 
socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 3540487 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44177/solr
   [junit4]   2> 3540496 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) 
[n:127.0.0.1:57248__l%2Fel    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (2)
   [junit4]   2> 3540498 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) 
[n:127.0.0.1:57248__l%2Fel    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3540501 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) 
[n:127.0.0.1:57248__l%2Fel    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:57248__l%2Fel
   [junit4]   2> 3540502 INFO  (zkCallback-26444-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 3540502 INFO  
(zkCallback-26440-thread-2-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 3540502 INFO  
(zkCallback-26450-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 3540503 INFO  
(zkCallback-26456-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 3540590 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) 
[n:127.0.0.1:57248__l%2Fel    ] o.a.s.c.CorePropertiesLocator Found 1 core 
definitions underneath 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsUnloadDistributedZkTest_D7F66C5188A04917-001/shard-2-001/cores
   [junit4]   2> 3540590 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) 
[n:127.0.0.1:57248__l%2Fel    ] o.a.s.c.CorePropertiesLocator Cores are: 
[collection1]
   [junit4]   2> 3540591 INFO  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 
transient cores
   [junit4]   2> 3540592 INFO  
(OverseerStateUpdate-97948551086866436-127.0.0.1:54521__l%2Fel-n_0000000000) 
[n:127.0.0.1:54521__l%2Fel    ] o.a.s.c.o.ReplicaMutator Assigning new node to 
shard shard=shard1
   [junit4]   2> 3540698 INFO  
(zkCallback-26450-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [3])
   [junit4]   2> 3540698 INFO  
(zkCallback-26456-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [3])
   [junit4]   2> 3541605 WARN  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] o.a.s.c.Config 
Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> 
instead.
   [junit4]   2> 3541606 INFO  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] o.a.s.c.SolrConfig 
Using Lucene MatchVersion: 6.6.0
   [junit4]   2> 3541636 INFO  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] o.a.s.s.IndexSchema 
[collection1] Schema name=test
   [junit4]   2> 3541761 INFO  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] o.a.s.s.IndexSchema 
Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 3541776 INFO  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] o.a.s.c.CoreContainer 
Creating SolrCore 'collection1' using configuration from collection 
collection1, trusted=true
   [junit4]   2> 3541776 INFO  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] 
o.a.s.c.HdfsDirectoryFactory 
solr.hdfs.home=hdfs://localhost:60156/solr_hdfs_home
   [junit4]   2> 3541776 INFO  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] 
o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
   [junit4]   2> 3541776 INFO  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] o.a.s.c.SolrCore 
solr.RecoveryStrategy.Builder
   [junit4]   2> 3541776 INFO  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] o.a.s.c.SolrCore 
[[collection1] ] Opening new SolrCore at 
[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsUnloadDistributedZkTest_D7F66C5188A04917-001/shard-2-001/cores/collection1],
 dataDir=[hdfs://localhost:60156/solr_hdfs_home/collection1/core_node2/data/]
   [junit4]   2> 3541776 INFO  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] 
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX 
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2d78bdc1
   [junit4]   2> 3541777 INFO  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:60156/solr_hdfs_home/collection1/core_node2/data/snapshot_metadata
   [junit4]   2> 3541785 INFO  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] 
o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct 
memory allocation set to [true]
   [junit4]   2> 3541785 INFO  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] 
o.a.s.c.HdfsDirectoryFactory Block cache target memory usage, slab size of 
[8388608] will allocate [1] slabs and use ~[8388608] bytes
   [junit4]   2> 3541785 INFO  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] 
o.a.s.c.HdfsDirectoryFactory Creating new single instance HDFS BlockCache
   [junit4]   2> 3541790 INFO  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] 
o.a.s.s.b.BlockDirectory Block cache on write is disabled
   [junit4]   2> 3541791 INFO  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:60156/solr_hdfs_home/collection1/core_node2/data
   [junit4]   2> 3541807 INFO  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:60156/solr_hdfs_home/collection1/core_node2/data/index
   [junit4]   2> 3541814 INFO  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] 
o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct 
memory allocation set to [true]
   [junit4]   2> 3541814 INFO  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] 
o.a.s.c.HdfsDirectoryFactory Block cache target memory usage, slab size of 
[8388608] will allocate [1] slabs and use ~[8388608] bytes
   [junit4]   2> 3541814 INFO  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] 
o.a.s.c.HdfsDirectoryFactory Creating new single instance HDFS BlockCache
   [junit4]   2> 3541818 INFO  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] 
o.a.s.s.b.BlockDirectory Block cache on write is disabled
   [junit4]   2> 3541818 INFO  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: 
minMergeSize=1000, mergeFactor=22, maxMergeSize=9223372036854775807, 
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, 
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=1.0]
   [junit4]   2> 3541827 INFO  (IPC Server handler 0 on 60156) [    ] 
BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:42137 is 
added to blk_1073741827_1003{UCState=UNDER_CONSTRUCTION, truncateBlock=null, 
primaryNodeIndex=-1, 
replicas=[ReplicaUC[[DISK]DS-282dc7a8-29ba-4ad9-8b31-06a2a07a9dac:NORMAL:127.0.0.1:46961|RBW],
 
ReplicaUC[[DISK]DS-dcce9e45-3fa8-4a13-9189-edf43e53290b:NORMAL:127.0.0.1:42137|RBW]]}
 size 0
   [junit4]   2> 3541828 INFO  (IPC Server handler 1 on 60156) [    ] 
BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:46961 is 
added to blk_1073741827_1003 size 71
   [junit4]   2> 3541837 WARN  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] 
o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = 
requestHandler,name = /dump,class = DumpRequestHandler,attributes = 
{initParams=a, name=/dump, class=DumpRequestHandler},args = 
{defaults={a=A,b=B}}}
   [junit4]   2> 3541890 INFO  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] o.a.s.u.UpdateHandler 
Using UpdateLog implementation: org.apache.solr.update.HdfsUpdateLog
   [junit4]   2> 3541890 INFO  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] o.a.s.u.UpdateLog 
Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 
maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 3541890 INFO  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] o.a.s.u.HdfsUpdateLog 
Initializing HdfsUpdateLog: tlogDfsReplication=2
   [junit4]   2> 3541901 INFO  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] o.a.s.u.CommitTracker 
Hard AutoCommit: disabled
   [junit4]   2> 3541902 INFO  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] o.a.s.u.CommitTracker 
Soft AutoCommit: disabled
   [junit4]   2> 3541904 INFO  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: 
minMergeSize=0, mergeFactor=10, maxMergeSize=300639073, 
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, 
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.1]
   [junit4]   2> 3541908 INFO  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@402980be[collection1] main]
   [junit4]   2> 3541910 INFO  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf1
   [junit4]   2> 3541910 INFO  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 3541910 INFO  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 3541912 INFO  
(searcherExecutor-12208-thread-1-processing-n:127.0.0.1:57248__l%2Fel 
x:collection1 c:collection1) [n:127.0.0.1:57248__l%2Fel c:collection1   
x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@402980be[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 3541914 INFO  
(coreLoadExecutor-12207-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel c:collection1   x:collection1] o.a.s.u.UpdateLog 
Could not find max version in index or recent updates, using new clock 
1567176822842458112
   [junit4]   2> 3541922 INFO  
(coreZkRegister-12202-thread-1-processing-n:127.0.0.1:57248__l%2Fel 
x:collection1 c:collection1) [n:127.0.0.1:57248__l%2Fel c:collection1 s:shard1 
r:core_node2 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas 
found to continue.
   [junit4]   2> 3541922 INFO  
(coreZkRegister-12202-thread-1-processing-n:127.0.0.1:57248__l%2Fel 
x:collection1 c:collection1) [n:127.0.0.1:57248__l%2Fel c:collection1 s:shard1 
r:core_node2 x:collection1] o.a.s.c.ShardLeaderElectionContext I may be the new 
leader - try and sync
   [junit4]   2> 3541922 INFO  
(coreZkRegister-12202-thread-1-processing-n:127.0.0.1:57248__l%2Fel 
x:collection1 c:collection1) [n:127.0.0.1:57248__l%2Fel c:collection1 s:shard1 
r:core_node2 x:collection1] o.a.s.c.SyncStrategy Sync replicas to 
http://127.0.0.1:57248/_l/el/collection1/
   [junit4]   2> 3541922 INFO  
(coreZkRegister-12202-thread-1-processing-n:127.0.0.1:57248__l%2Fel 
x:collection1 c:collection1) [n:127.0.0.1:57248__l%2Fel c:collection1 s:shard1 
r:core_node2 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync 
replicas to me
   [junit4]   2> 3541922 INFO  
(coreZkRegister-12202-thread-1-processing-n:127.0.0.1:57248__l%2Fel 
x:collection1 c:collection1) [n:127.0.0.1:57248__l%2Fel c:collection1 s:shard1 
r:core_node2 x:collection1] o.a.s.c.SyncStrategy 
http://127.0.0.1:57248/_l/el/collection1/ has no replicas
   [junit4]   2> 3541922 INFO  
(coreZkRegister-12202-thread-1-processing-n:127.0.0.1:57248__l%2Fel 
x:collection1 c:collection1) [n:127.0.0.1:57248__l%2Fel c:collection1 s:shard1 
r:core_node2 x:collection1] o.a.s.c.ShardLeaderElectionContext Found all 
replicas participating in election, clear LIR
   [junit4]   2> 3541931 INFO  
(coreZkRegister-12202-thread-1-processing-n:127.0.0.1:57248__l%2Fel 
x:collection1 c:collection1) [n:127.0.0.1:57248__l%2Fel c:collection1 s:shard1 
r:core_node2 x:collection1] o.a.s.c.ShardLeaderElectionContext I am the new 
leader: http://127.0.0.1:57248/_l/el/collection1/ shard1
   [junit4]   2> 3542033 INFO  
(zkCallback-26456-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [3])
   [junit4]   2> 3542033 INFO  
(zkCallback-26450-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [3])
   [junit4]   2> 3542036 INFO  
(coreZkRegister-12202-thread-1-processing-n:127.0.0.1:57248__l%2Fel 
x:collection1 c:collection1) [n:127.0.0.1:57248__l%2Fel c:collection1 s:shard1 
r:core_node2 x:collection1] o.a.s.c.ZkController I am the leader, no recovery 
necessary
   [junit4]   2> 3542140 INFO  
(zkCallback-26456-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [3])
   [junit4]   2> 3542140 INFO  
(zkCallback-26450-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [3])
   [junit4]   2> 3542233 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.SolrTestCaseJ4 Writing core.properties file to 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsUnloadDistributedZkTest_D7F66C5188A04917-001/shard-3-001/cores/collection1
   [junit4]   2> 3542234 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.c.AbstractFullDistribZkTestBase create jetty 3 in directory 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsUnloadDistributedZkTest_D7F66C5188A04917-001/shard-3-001
   [junit4]   2> 3542235 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 3542236 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@7b5787da{/_l/el,null,AVAILABLE}
   [junit4]   2> 3542237 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@1c7b0645{HTTP/1.1,[http/1.1]}{127.0.0.1:50994}
   [junit4]   2> 3542237 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.e.j.s.Server Started @3545394ms
   [junit4]   2> 3542237 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: 
{solr.data.dir=hdfs://localhost:60156/hdfs__localhost_60156__x1_jenkins_jenkins-slave_workspace_Lucene-Solr-NightlyTests-6.6_checkout_solr_build_solr-core_test_J0_temp_solr.cloud.hdfs.HdfsUnloadDistributedZkTest_D7F66C5188A04917-001_tempDir-002_jetty3,
 solrconfig=solrconfig.xml, hostContext=/_l/el, hostPort=50994, 
coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsUnloadDistributedZkTest_D7F66C5188A04917-001/shard-3-001/cores}
   [junit4]   2> 3542237 ERROR 
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 3542237 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
6.6.0
   [junit4]   2> 3542237 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3542237 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3542237 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-05-12T08:04:45.535Z
   [junit4]   2> 3542240 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in 
ZooKeeper)
   [junit4]   2> 3542240 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.c.SolrXmlConfig Loading container configuration from 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsUnloadDistributedZkTest_D7F66C5188A04917-001/shard-3-001/solr.xml
   [junit4]   2> 3542247 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: 
socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 3542248 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44177/solr
   [junit4]   2> 3542257 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) 
[n:127.0.0.1:50994__l%2Fel    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (3)
   [junit4]   2> 3542260 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) 
[n:127.0.0.1:50994__l%2Fel    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3542262 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) 
[n:127.0.0.1:50994__l%2Fel    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:50994__l%2Fel
   [junit4]   2> 3542263 INFO  
(zkCallback-26456-thread-1-processing-n:127.0.0.1:57248__l%2Fel) 
[n:127.0.0.1:57248__l%2Fel    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 3542264 INFO  (zkCallback-26444-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3542264 INFO  
(zkCallback-26450-thread-1-processing-n:127.0.0.1:49964__l%2Fel) 
[n:127.0.0.1:49964__l%2Fel    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 3542264 INFO  
(zkCallback-26440-thread-2-processing-n:127.0.0.1:54521__l%2Fel) 
[n:127.0.0.1:54521__l%2Fel    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 3542265 INFO  
(zkCallback-26462-thread-1-processing-n:127.0.0.1:50994__l%2Fel) 
[n:127.0.0.1:50994__l%2Fel    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 3542365 INFO  
(TEST-HdfsUnloadDistributedZkTest.test-seed#[D7F66C5188A04917]) 
[n:127.0.0.1:50994__l%2Fel    ] o.a.s.c.CorePropertiesLocator Found 1 core 
definitions underneath 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsUnloadDistributedZkTest_D7F66C5188A04917-001/shard-3-001/cores
   [junit4]   2> 3542365 INFO  (TEST-HdfsUnl

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

java:1705)
   [junit4]   2>        at 
org.apache.solr.cloud.hdfs.HdfsTestUtil.teardownClass(HdfsTestUtil.java:203)
   [junit4]   2>        at 
org.apache.solr.cloud.hdfs.HdfsUnloadDistributedZkTest.teardownClass(HdfsUnloadDistributedZkTest.java:46)
   [junit4]   2>        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native 
Method)
   [junit4]   2>        at 
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
   [junit4]   2>        at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
   [junit4]   2>        at java.lang.reflect.Method.invoke(Method.java:498)
   [junit4]   2>        at 
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
   [junit4]   2>        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:870)
   [junit4]   2>        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2>        at 
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
   [junit4]   2>        at 
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
   [junit4]   2>        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2>        at 
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
   [junit4]   2>        at 
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
   [junit4]   2>        at 
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
   [junit4]   2>        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2>        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2>        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2>        at 
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
   [junit4]   2>        at 
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
   [junit4]   2>        at 
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
   [junit4]   2>        at 
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
   [junit4]   2>        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2>        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
   [junit4]   2>        at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> Caused by: java.lang.NullPointerException
   [junit4]   2>        at 
org.apache.hadoop.hdfs.server.blockmanagement.BlocksMap.size(BlocksMap.java:203)
   [junit4]   2>        at 
org.apache.hadoop.hdfs.server.blockmanagement.BlockManager.getTotalBlocks(BlockManager.java:3370)
   [junit4]   2>        at 
org.apache.hadoop.hdfs.server.namenode.FSNamesystem.getBlocksTotal(FSNamesystem.java:5729)
   [junit4]   2>        ... 53 more
   [junit4]   2> 3596814 INFO  
(SUITE-HdfsUnloadDistributedZkTest-seed#[D7F66C5188A04917]-worker) [    ] 
o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> NOTE: leaving temporary files on disk at: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsUnloadDistributedZkTest_D7F66C5188A04917-001
   [junit4]   2> May 12, 2017 8:05:40 AM 
com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
   [junit4]   2> WARNING: Will linger awaiting termination of 34 leaked 
thread(s).
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene62): 
{other_tl1=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))),
 range_facet_l_dv=FSTOrd50, multiDefault=PostingsFormat(name=LuceneFixedGap), 
a_t=PostingsFormat(name=LuceneFixedGap), 
intDefault=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))),
 a_i1=PostingsFormat(name=LuceneFixedGap), id=FSTOrd50, 
range_facet_i_dv=PostingsFormat(name=LuceneFixedGap), 
text=PostingsFormat(name=Memory doPackFST= true), 
range_facet_l=PostingsFormat(name=LuceneFixedGap), 
timestamp=PostingsFormat(name=LuceneFixedGap)}, 
docValues:{range_facet_l_dv=DocValuesFormat(name=Direct), 
_version_=DocValuesFormat(name=Lucene54), 
range_facet_i_dv=DocValuesFormat(name=Lucene54), 
intDvoDefault=DocValuesFormat(name=Direct), 
timestamp=DocValuesFormat(name=Lucene54)}, maxPointsInLeafNode=1399, 
maxMBSortInHeap=6.159579909635032, 
sim=RandomSimilarity(queryNorm=false,coord=crazy): {}, locale=th, 
timezone=America/Argentina/Salta
   [junit4]   2> NOTE: Linux 3.13.0-88-generic amd64/Oracle Corporation 
1.8.0_121 (64-bit)/cpus=4,threads=2,free=241712760,total=534249472
   [junit4]   2> NOTE: All tests run in this JVM: [TestDistributedSearch, 
HighlighterMaxOffsetTest, TestReplicationHandlerBackup, TestHdfsUpdateLog, 
DateFieldTest, SolrGraphiteReporterTest, CollectionsAPIAsyncDistributedZkTest, 
DistributedFacetExistsSmallTest, SolrIndexMetricsTest, 
DisMaxRequestHandlerTest, TestRandomDVFaceting, WrapperMergePolicyFactoryTest, 
PeerSyncTest, TestOmitPositions, DistributedQueryComponentCustomSortTest, 
ReturnFieldsTest, TestSolrConfigHandlerConcurrent, 
TestSolrCloudWithSecureImpersonation, TestStressLucene, ResourceLoaderTest, 
PolyFieldTest, CustomCollectionTest, TestDistribIDF, TestManagedSchemaAPI, 
ChaosMonkeyNothingIsSafeTest, ResponseHeaderTest, ZkNodePropsTest, 
TestValueSourceCache, LeaderInitiatedRecoveryOnCommitTest, 
SynonymTokenizerTest, TestInfoStreamLogging, TestHighlightDedupGrouping, 
ClassificationUpdateProcessorIntegrationTest, SolrMetricReporterTest, 
CursorPagingTest, TestDocumentBuilder, TestCSVLoader, 
TestBackupRepositoryFactory, TestFaceting, UpdateLogTest, 
TestConfigSetProperties, TestRTimerTree, SmileWriterTest, 
TestClusterStateMutator, TestOrdValues, DistribJoinFromCollectionTest, 
TestJsonFacetRefinement, DistributedFacetPivotSmallAdvancedTest, 
TestNoOpRegenerator, InfoHandlerTest, TestCustomDocTransformer, 
TlogReplayBufferedWhileIndexingTest, DistributedQueryElevationComponentTest, 
BasicDistributedZkTest, DocValuesMissingTest, TestJmxIntegration, 
TestFoldingMultitermQuery, TestNamedUpdateProcessors, TestFastWriter, 
DocumentAnalysisRequestHandlerTest, TestSolr4Spatial, 
UniqFieldsUpdateProcessorFactoryTest, 
TestPerFieldSimilarityWithDefaultOverride, CursorMarkTest, 
TestSolrDeletionPolicy2, CloudMLTQParserTest, MBeansHandlerTest, 
MetricUtilsTest, ShufflingReplicaListTransformerTest, 
DefaultValueUpdateProcessorTest, RecoveryAfterSoftCommitTest, 
TestPHPSerializedResponseWriter, OutputWriterTest, 
SignatureUpdateProcessorFactoryTest, TestSSLRandomization, 
TestSolrConfigHandler, TestAnalyzeInfixSuggestions, TestBinaryResponseWriter, 
ConfigureRecoveryStrategyTest, TestManagedStopFilterFactory, 
QueryElevationComponentTest, CacheHeaderTest, ExitableDirectoryReaderTest, 
BaseCdcrDistributedZkTest, TestFieldCollectionResource, BlockDirectoryTest, 
HdfsChaosMonkeySafeLeaderTest, TestSolrFieldCacheMBean, SuggestComponentTest, 
NodeMutatorTest, BasicZkTest, TestCloudManagedSchema, TestCustomStream, 
TestLocalFSCloudBackupRestore, GraphQueryTest, FileBasedSpellCheckerTest, 
DistributedSpellCheckComponentTest, HdfsBasicDistributedZk2Test, 
HighlighterConfigTest, DistanceUnitsTest, CdcrUpdateLogTest, TestSQLHandler, 
TestPayloadScoreQParserPlugin, TestChildDocTransformer, TestBadConfig, 
ExternalFileFieldSortTest, XsltUpdateRequestHandlerTest, 
TestScoreJoinQPNoScore, TestDFISimilarityFactory, TestCollationFieldDocValues, 
TestAtomicUpdateErrorCases, TestFunctionQuery, HLLSerializationTest, 
AnalysisAfterCoreReloadTest, TestLazyCores, TestComponentsName, 
TestPseudoReturnFields, ChaosMonkeySafeLeaderTest, UnloadDistributedZkTest, 
CollectionsAPIDistributedZkTest, SyncSliceTest, LeaderElectionIntegrationTest, 
FullSolrCloudDistribCmdsTest, TestReplicationHandler, DeleteStatusTest, 
ForceLeaderTest, SharedFSAutoReplicaFailoverTest, 
SharedFSAutoReplicaFailoverUtilsTest, SolrCLIZkUtilsTest, SolrCloudExampleTest, 
TestAuthenticationFramework, TestCloudDeleteByQuery, TestCloudInspectUtil, 
TestCloudJSONFacetJoinDomain, TestCloudPivotFacet, TestConfigSetsAPI, 
TestOnReconnectListenerSupport, TestReplicaProperties, 
TestSolrCloudWithDelegationTokens, TestSolrCloudWithKerberosAlt, 
TestStressLiveNodes, HdfsRecoverLeaseTest, HdfsSyncSliceTest, 
HdfsUnloadDistributedZkTest]
   [junit4] Completed [546/711 (1!)] on J0 in 71.47s, 1 test, 1 error <<< 
FAILURES!

[...truncated 510 lines...]
   [junit4] JVM J1: stdout was not empty, see: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/solr/build/solr-core/test/temp/junit4-J1-20170512_070540_0841407402591075266460.sysout
   [junit4] >>> JVM J1 emitted unexpected output (verbatim) ----
   [junit4] java.lang.OutOfMemoryError: Java heap space
   [junit4] Dumping heap to 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/heapdumps/java_pid4311.hprof
 ...
   [junit4] Heap dump file created [144462856 bytes in 0.916 secs]
   [junit4] <<< JVM J1: EOF ----

[...truncated 7465 lines...]
BUILD FAILED
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/build.xml:783:
 The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.6/checkout/build.xml:727:
 Some of the tests produced a heap dump, but did not fail. Maybe a suppressed 
OutOfMemoryError? Dumps created:
* java_pid15565.hprof
* java_pid4311.hprof

Total time: 250 minutes 15 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
No prior successful build to compare, so performing full copy of artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]

Reply via email to