[SOLR-8895] HdfsDirectoryTest.testEOF() failure: NPE - ASF JIRA

XML

Word

Printable

JSON

Details

Type: Bug
Status: Resolved
Priority: Major
Resolution: Duplicate
Affects Version/s: None
Fix Version/s: None
Component/s: None
Labels:
None

Description

My Jenkins found a reproducible seed on branch_6x:

   [junit4] Suite: org.apache.solr.store.hdfs.HdfsDirectoryTest
   [junit4]   2> Creating dataDir: /var/lib/jenkins/jobs/Lucene-Solr-tests-6.x/workspace/solr/build/solr-core/test/J5/temp/solr.store.hdfs.HdfsDirectoryTest_6BF936321AE9FC53-001/init-core-data-001
   [junit4]   2> 432246 INFO  (SUITE-HdfsDirectoryTest-seed#[6BF936321AE9FC53]-worker) [    ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true)
   [junit4]   1> Formatting using clusterid: testClusterID
   [junit4]   2> 432262 WARN  (SUITE-HdfsDirectoryTest-seed#[6BF936321AE9FC53]-worker) [    ] o.a.h.m.i.MetricsConfig Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
   [junit4]   2> 432267 WARN  (SUITE-HdfsDirectoryTest-seed#[6BF936321AE9FC53]-worker) [    ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
   [junit4]   2> 432269 INFO  (SUITE-HdfsDirectoryTest-seed#[6BF936321AE9FC53]-worker) [    ] o.m.log jetty-6.1.26
   [junit4]   2> 432276 INFO  (SUITE-HdfsDirectoryTest-seed#[6BF936321AE9FC53]-worker) [    ] o.m.log Extract jar:file:/var/lib/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.6.0-tests.jar!/webapps/hdfs to ./temp/Jetty_localhost_36931_hdfs____.vsqnuq/webapp
   [junit4]   2> 432337 INFO  (SUITE-HdfsDirectoryTest-seed#[6BF936321AE9FC53]-worker) [    ] o.m.log NO JSP Support for /, did not find org.apache.jasper.servlet.JspServlet
   [junit4]   2> 432703 INFO  (SUITE-HdfsDirectoryTest-seed#[6BF936321AE9FC53]-worker) [    ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:36931
   [junit4]   2> 432820 WARN  (SUITE-HdfsDirectoryTest-seed#[6BF936321AE9FC53]-worker) [    ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
   [junit4]   2> 432821 INFO  (SUITE-HdfsDirectoryTest-seed#[6BF936321AE9FC53]-worker) [    ] o.m.log jetty-6.1.26
   [junit4]   2> 432829 INFO  (SUITE-HdfsDirectoryTest-seed#[6BF936321AE9FC53]-worker) [    ] o.m.log Extract jar:file:/var/lib/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.6.0-tests.jar!/webapps/datanode to ./temp/Jetty_localhost_40567_datanode____.hd2j4v/webapp
   [junit4]   2> 432887 INFO  (SUITE-HdfsDirectoryTest-seed#[6BF936321AE9FC53]-worker) [    ] o.m.log NO JSP Support for /, did not find org.apache.jasper.servlet.JspServlet
   [junit4]   2> 433283 INFO  (SUITE-HdfsDirectoryTest-seed#[6BF936321AE9FC53]-worker) [    ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:40567
   [junit4]   2> 433304 WARN  (SUITE-HdfsDirectoryTest-seed#[6BF936321AE9FC53]-worker) [    ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
   [junit4]   2> 433305 INFO  (SUITE-HdfsDirectoryTest-seed#[6BF936321AE9FC53]-worker) [    ] o.m.log jetty-6.1.26
   [junit4]   2> 433315 INFO  (SUITE-HdfsDirectoryTest-seed#[6BF936321AE9FC53]-worker) [    ] o.m.log Extract jar:file:/var/lib/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.6.0-tests.jar!/webapps/datanode to ./temp/Jetty_localhost_54236_datanode____.2l2cxv/webapp
   [junit4]   2> 433331 INFO  (IPC Server handler 3 on 35443) [    ] BlockStateChange BLOCK* processReport: from storage DS-3362e969-6b1f-4f8b-90c2-519bfe11a4e3 node DatanodeRegistration(127.0.0.1, datanodeUuid=a1c6edfb-4bb8-4e12-a3d4-dc5308fd9199, infoPort=40567, ipcPort=34011, storageInfo=lv=-56;cid=testClusterID;nsid=1766496377;c=0), blocks: 0, hasStaleStorages: true, processing time: 1 msecs
   [junit4]   2> 433332 INFO  (IPC Server handler 3 on 35443) [    ] BlockStateChange BLOCK* processReport: from storage DS-35c6c048-304c-4d94-a2b2-47d07d42be08 node DatanodeRegistration(127.0.0.1, datanodeUuid=a1c6edfb-4bb8-4e12-a3d4-dc5308fd9199, infoPort=40567, ipcPort=34011, storageInfo=lv=-56;cid=testClusterID;nsid=1766496377;c=0), blocks: 0, hasStaleStorages: false, processing time: 0 msecs
   [junit4]   2> 433404 INFO  (SUITE-HdfsDirectoryTest-seed#[6BF936321AE9FC53]-worker) [    ] o.m.log NO JSP Support for /, did not find org.apache.jasper.servlet.JspServlet
   [junit4]   2> 433822 INFO  (SUITE-HdfsDirectoryTest-seed#[6BF936321AE9FC53]-worker) [    ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:54236
   [junit4]   2> 433851 INFO  (IPC Server handler 4 on 35443) [    ] BlockStateChange BLOCK* processReport: from storage DS-7e62f7ee-4893-43bb-a5af-ce3fd18691b7 node DatanodeRegistration(127.0.0.1, datanodeUuid=c48cef8e-d1c1-4fa3-90c9-c2e0461c78c1, infoPort=54236, ipcPort=56889, storageInfo=lv=-56;cid=testClusterID;nsid=1766496377;c=0), blocks: 0, hasStaleStorages: true, processing time: 1 msecs
   [junit4]   2> 433851 INFO  (IPC Server handler 4 on 35443) [    ] BlockStateChange BLOCK* processReport: from storage DS-a13f97e1-49f8-4a21-b4a8-57ce818addae node DatanodeRegistration(127.0.0.1, datanodeUuid=c48cef8e-d1c1-4fa3-90c9-c2e0461c78c1, infoPort=54236, ipcPort=56889, storageInfo=lv=-56;cid=testClusterID;nsid=1766496377;c=0), blocks: 0, hasStaleStorages: false, processing time: 0 msecs
   [junit4]   2> 433957 INFO  (TEST-HdfsDirectoryTest.testRename-seed#[6BF936321AE9FC53]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testRename
   [junit4]   2> 434007 INFO  (IPC Server handler 5 on 35443) [    ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:47329 is added to blk_1073741825_1001{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-a13f97e1-49f8-4a21-b4a8-57ce818addae:NORMAL:127.0.0.1:46171|RBW], ReplicaUnderConstruction[[DISK]DS-3362e969-6b1f-4f8b-90c2-519bfe11a4e3:NORMAL:127.0.0.1:47329|RBW]]} size 0
   [junit4]   2> 434009 INFO  (IPC Server handler 6 on 35443) [    ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:46171 is added to blk_1073741825_1001{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-a13f97e1-49f8-4a21-b4a8-57ce818addae:NORMAL:127.0.0.1:46171|RBW], ReplicaUnderConstruction[[DISK]DS-3362e969-6b1f-4f8b-90c2-519bfe11a4e3:NORMAL:127.0.0.1:47329|RBW]]} size 0
   [junit4]   2> 434057 INFO  (IPC Server handler 4 on 35443) [    ] BlockStateChange BLOCK* addToInvalidates: blk_1073741825_1001 127.0.0.1:46171 127.0.0.1:47329 
   [junit4]   2> 434060 INFO  (TEST-HdfsDirectoryTest.testRename-seed#[6BF936321AE9FC53]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testRename
   [junit4]   2> 434080 INFO  (TEST-HdfsDirectoryTest.testEOF-seed#[6BF936321AE9FC53]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testEOF
   [junit4]   2> 434161 INFO  (IPC Server handler 1 on 35443) [    ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:46171 is added to blk_1073741826_1002{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-3362e969-6b1f-4f8b-90c2-519bfe11a4e3:NORMAL:127.0.0.1:47329|RBW], ReplicaUnderConstruction[[DISK]DS-7e62f7ee-4893-43bb-a5af-ce3fd18691b7:NORMAL:127.0.0.1:46171|FINALIZED]]} size 0
   [junit4]   2> 434163 INFO  (IPC Server handler 3 on 35443) [    ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:47329 is added to blk_1073741826_1002 size 2238464
   [junit4]   2> 434166 INFO  (TEST-HdfsDirectoryTest.testEOF-seed#[6BF936321AE9FC53]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testEOF
   [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=HdfsDirectoryTest -Dtests.method=testEOF -Dtests.seed=6BF936321AE9FC53 -Dtests.slow=true -Dtests.linedocsfile=/home/jenkins/lucene-data/enwiki.random.lines.txt -Dtests.locale=hu -Dtests.timezone=America/Nipigon -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
   [junit4] ERROR   0.11s J5  | HdfsDirectoryTest.testEOF <<<
   [junit4]    > Throwable #1: java.lang.NullPointerException
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([6BF936321AE9FC53:FA92743A58CD5A2F]:0)
   [junit4]    > 	at org.apache.lucene.store.RAMInputStream.readByte(RAMInputStream.java:69)
   [junit4]    > 	at org.apache.solr.store.hdfs.HdfsDirectoryTest.testEof(HdfsDirectoryTest.java:159)
   [junit4]    > 	at org.apache.solr.store.hdfs.HdfsDirectoryTest.testEOF(HdfsDirectoryTest.java:151)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 434182 INFO  (TEST-HdfsDirectoryTest.testRandomAccessWrites-seed#[6BF936321AE9FC53]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testRandomAccessWrites
   [junit4]   1> Working on pass [0] contains [false]
   [junit4]   2> 434243 INFO  (IPC Server handler 0 on 35443) [    ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:47329 is added to blk_1073741827_1003{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-7e62f7ee-4893-43bb-a5af-ce3fd18691b7:NORMAL:127.0.0.1:46171|RBW], ReplicaUnderConstruction[[DISK]DS-3362e969-6b1f-4f8b-90c2-519bfe11a4e3:NORMAL:127.0.0.1:47329|FINALIZED]]} size 0
   [junit4]   2> 434243 INFO  (IPC Server handler 1 on 35443) [    ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:46171 is added to blk_1073741827_1003{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-3362e969-6b1f-4f8b-90c2-519bfe11a4e3:NORMAL:127.0.0.1:47329|FINALIZED], ReplicaUnderConstruction[[DISK]DS-a13f97e1-49f8-4a21-b4a8-57ce818addae:NORMAL:127.0.0.1:46171|FINALIZED]]} size 0
   [junit4]   1> Working on pass [1] contains [false]
   [junit4]   2> 435200 INFO  (IPC Server handler 0 on 35443) [    ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:47329 is added to blk_1073741828_1004{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-7e62f7ee-4893-43bb-a5af-ce3fd18691b7:NORMAL:127.0.0.1:46171|RBW], ReplicaUnderConstruction[[DISK]DS-35c6c048-304c-4d94-a2b2-47d07d42be08:NORMAL:127.0.0.1:47329|FINALIZED]]} size 0
   [junit4]   2> 435201 INFO  (IPC Server handler 1 on 35443) [    ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:46171 is added to blk_1073741828_1004{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-7e62f7ee-4893-43bb-a5af-ce3fd18691b7:NORMAL:127.0.0.1:46171|RBW], ReplicaUnderConstruction[[DISK]DS-35c6c048-304c-4d94-a2b2-47d07d42be08:NORMAL:127.0.0.1:47329|FINALIZED]]} size 0
   [junit4]   1> Working on pass [2] contains [false]
   [junit4]   2> 436147 INFO  (IPC Server handler 7 on 35443) [    ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:46171 is added to blk_1073741829_1005{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-35c6c048-304c-4d94-a2b2-47d07d42be08:NORMAL:127.0.0.1:47329|RBW], ReplicaUnderConstruction[[DISK]DS-a13f97e1-49f8-4a21-b4a8-57ce818addae:NORMAL:127.0.0.1:46171|RBW]]} size 0
   [junit4]   2> 436147 INFO  (IPC Server handler 8 on 35443) [    ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:47329 is added to blk_1073741829_1005{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-a13f97e1-49f8-4a21-b4a8-57ce818addae:NORMAL:127.0.0.1:46171|RBW], ReplicaUnderConstruction[[DISK]DS-3362e969-6b1f-4f8b-90c2-519bfe11a4e3:NORMAL:127.0.0.1:47329|FINALIZED]]} size 0
   [junit4]   1> Working on pass [3] contains [false]
   [junit4]   2> 436325 INFO  (IPC Server handler 7 on 35443) [    ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:47329 is added to blk_1073741830_1006{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-a13f97e1-49f8-4a21-b4a8-57ce818addae:NORMAL:127.0.0.1:46171|RBW], ReplicaUnderConstruction[[DISK]DS-35c6c048-304c-4d94-a2b2-47d07d42be08:NORMAL:127.0.0.1:47329|RBW]]} size 0
   [junit4]   2> 436325 INFO  (IPC Server handler 8 on 35443) [    ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:46171 is added to blk_1073741830_1006{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-35c6c048-304c-4d94-a2b2-47d07d42be08:NORMAL:127.0.0.1:47329|RBW], ReplicaUnderConstruction[[DISK]DS-7e62f7ee-4893-43bb-a5af-ce3fd18691b7:NORMAL:127.0.0.1:46171|FINALIZED]]} size 0
   [junit4]   1> Working on pass [4] contains [false]
   [junit4]   2> 438307 INFO  (IPC Server handler 7 on 35443) [    ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:47329 is added to blk_1073741831_1007{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-7e62f7ee-4893-43bb-a5af-ce3fd18691b7:NORMAL:127.0.0.1:46171|RBW], ReplicaUnderConstruction[[DISK]DS-3362e969-6b1f-4f8b-90c2-519bfe11a4e3:NORMAL:127.0.0.1:47329|RBW]]} size 0
   [junit4]   2> 438307 INFO  (IPC Server handler 8 on 35443) [    ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:46171 is added to blk_1073741831_1007{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-3362e969-6b1f-4f8b-90c2-519bfe11a4e3:NORMAL:127.0.0.1:47329|RBW], ReplicaUnderConstruction[[DISK]DS-a13f97e1-49f8-4a21-b4a8-57ce818addae:NORMAL:127.0.0.1:46171|FINALIZED]]} size 0
   [junit4]   1> Working on pass [5] contains [false]
   [junit4]   2> 438430 INFO  (IPC Server handler 5 on 35443) [    ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:47329 is added to blk_1073741832_1008{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-7e62f7ee-4893-43bb-a5af-ce3fd18691b7:NORMAL:127.0.0.1:46171|RBW], ReplicaUnderConstruction[[DISK]DS-35c6c048-304c-4d94-a2b2-47d07d42be08:NORMAL:127.0.0.1:47329|FINALIZED]]} size 0
   [junit4]   2> 438430 INFO  (IPC Server handler 6 on 35443) [    ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:46171 is added to blk_1073741832_1008{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-7e62f7ee-4893-43bb-a5af-ce3fd18691b7:NORMAL:127.0.0.1:46171|RBW], ReplicaUnderConstruction[[DISK]DS-35c6c048-304c-4d94-a2b2-47d07d42be08:NORMAL:127.0.0.1:47329|FINALIZED]]} size 0
   [junit4]   1> Working on pass [6] contains [false]
   [junit4]   2> 439738 INFO  (IPC Server handler 2 on 35443) [    ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:46171 is added to blk_1073741833_1009{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-3362e969-6b1f-4f8b-90c2-519bfe11a4e3:NORMAL:127.0.0.1:47329|RBW], ReplicaUnderConstruction[[DISK]DS-a13f97e1-49f8-4a21-b4a8-57ce818addae:NORMAL:127.0.0.1:46171|RBW]]} size 0
   [junit4]   2> 439739 INFO  (IPC Server handler 3 on 35443) [    ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:47329 is added to blk_1073741833_1009{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-3362e969-6b1f-4f8b-90c2-519bfe11a4e3:NORMAL:127.0.0.1:47329|RBW], ReplicaUnderConstruction[[DISK]DS-a13f97e1-49f8-4a21-b4a8-57ce818addae:NORMAL:127.0.0.1:46171|RBW]]} size 0
   [junit4]   1> Working on pass [7] contains [false]
   [junit4]   2> 440142 INFO  (IPC Server handler 0 on 35443) [    ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:47329 is added to blk_1073741834_1010{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-7e62f7ee-4893-43bb-a5af-ce3fd18691b7:NORMAL:127.0.0.1:46171|RBW], ReplicaUnderConstruction[[DISK]DS-35c6c048-304c-4d94-a2b2-47d07d42be08:NORMAL:127.0.0.1:47329|RBW]]} size 0
   [junit4]   2> 440142 INFO  (IPC Server handler 1 on 35443) [    ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:46171 is added to blk_1073741834_1010{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-7e62f7ee-4893-43bb-a5af-ce3fd18691b7:NORMAL:127.0.0.1:46171|RBW], ReplicaUnderConstruction[[DISK]DS-35c6c048-304c-4d94-a2b2-47d07d42be08:NORMAL:127.0.0.1:47329|RBW]]} size 0
   [junit4]   1> Working on pass [8] contains [false]
   [junit4]   2> 441452 INFO  (IPC Server handler 8 on 35443) [    ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:47329 is added to blk_1073741835_1011{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-3362e969-6b1f-4f8b-90c2-519bfe11a4e3:NORMAL:127.0.0.1:47329|RBW], ReplicaUnderConstruction[[DISK]DS-a13f97e1-49f8-4a21-b4a8-57ce818addae:NORMAL:127.0.0.1:46171|RBW]]} size 0
   [junit4]   2> 441452 INFO  (IPC Server handler 7 on 35443) [    ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:46171 is added to blk_1073741835_1011{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-3362e969-6b1f-4f8b-90c2-519bfe11a4e3:NORMAL:127.0.0.1:47329|RBW], ReplicaUnderConstruction[[DISK]DS-a13f97e1-49f8-4a21-b4a8-57ce818addae:NORMAL:127.0.0.1:46171|RBW]]} size 0
   [junit4]   1> Working on pass [9] contains [false]
   [junit4]   2> 442021 INFO  (IPC Server handler 6 on 35443) [    ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:46171 is added to blk_1073741836_1012{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-35c6c048-304c-4d94-a2b2-47d07d42be08:NORMAL:127.0.0.1:47329|RBW], ReplicaUnderConstruction[[DISK]DS-7e62f7ee-4893-43bb-a5af-ce3fd18691b7:NORMAL:127.0.0.1:46171|FINALIZED]]} size 0
   [junit4]   2> 442021 INFO  (IPC Server handler 0 on 35443) [    ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:47329 is added to blk_1073741836_1012{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-35c6c048-304c-4d94-a2b2-47d07d42be08:NORMAL:127.0.0.1:47329|RBW], ReplicaUnderConstruction[[DISK]DS-7e62f7ee-4893-43bb-a5af-ce3fd18691b7:NORMAL:127.0.0.1:46171|FINALIZED]]} size 0
   [junit4]   2> 444142 INFO  (TEST-HdfsDirectoryTest.testRandomAccessWrites-seed#[6BF936321AE9FC53]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testRandomAccessWrites
   [junit4]   2> 444157 INFO  (TEST-HdfsDirectoryTest.testWritingAndReadingAFile-seed#[6BF936321AE9FC53]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testWritingAndReadingAFile
   [junit4]   2> 444194 INFO  (IPC Server handler 5 on 35443) [    ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:46171 is added to blk_1073741837_1013{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-35c6c048-304c-4d94-a2b2-47d07d42be08:NORMAL:127.0.0.1:47329|RBW], ReplicaUnderConstruction[[DISK]DS-a13f97e1-49f8-4a21-b4a8-57ce818addae:NORMAL:127.0.0.1:46171|RBW]]} size 0
   [junit4]   2> 444203 INFO  (IPC Server handler 7 on 35443) [    ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:47329 is added to blk_1073741837_1013{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-a13f97e1-49f8-4a21-b4a8-57ce818addae:NORMAL:127.0.0.1:46171|RBW], ReplicaUnderConstruction[[DISK]DS-3362e969-6b1f-4f8b-90c2-519bfe11a4e3:NORMAL:127.0.0.1:47329|FINALIZED]]} size 0
   [junit4]   2> 444224 INFO  (IPC Server handler 8 on 35443) [    ] BlockStateChange BLOCK* addToInvalidates: blk_1073741837_1013 127.0.0.1:47329 127.0.0.1:46171 
   [junit4]   2> 444225 INFO  (TEST-HdfsDirectoryTest.testWritingAndReadingAFile-seed#[6BF936321AE9FC53]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testWritingAndReadingAFile
   [junit4]   2> 444226 WARN  (SUITE-HdfsDirectoryTest-seed#[6BF936321AE9FC53]-worker) [    ] o.a.h.h.s.d.DirectoryScanner DirectoryScanner: shutdown has been called
   [junit4]   2> 444228 INFO  (SUITE-HdfsDirectoryTest-seed#[6BF936321AE9FC53]-worker) [    ] o.m.log Stopped HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:0
   [junit4]   2> 444331 WARN  (DataNode: [[[DISK]file:/var/lib/jenkins/jobs/Lucene-Solr-tests-6.x/workspace/solr/build/solr-core/test/J5/temp/solr.store.hdfs.HdfsDirectoryTest_6BF936321AE9FC53-001/tempDir-001/hdfsBaseDir/data/data3/, [DISK]file:/var/lib/jenkins/jobs/Lucene-Solr-tests-6.x/workspace/solr/build/solr-core/test/J5/temp/solr.store.hdfs.HdfsDirectoryTest_6BF936321AE9FC53-001/tempDir-001/hdfsBaseDir/data/data4/]]  heartbeating to localhost/127.0.0.1:35443) [    ] o.a.h.h.s.d.DataNode BPOfferService for Block pool BP-968347885-127.0.1.1-1458793441285 (Datanode Uuid c48cef8e-d1c1-4fa3-90c9-c2e0461c78c1) service to localhost/127.0.0.1:35443 interrupted
   [junit4]   2> 444331 WARN  (DataNode: [[[DISK]file:/var/lib/jenkins/jobs/Lucene-Solr-tests-6.x/workspace/solr/build/solr-core/test/J5/temp/solr.store.hdfs.HdfsDirectoryTest_6BF936321AE9FC53-001/tempDir-001/hdfsBaseDir/data/data3/, [DISK]file:/var/lib/jenkins/jobs/Lucene-Solr-tests-6.x/workspace/solr/build/solr-core/test/J5/temp/solr.store.hdfs.HdfsDirectoryTest_6BF936321AE9FC53-001/tempDir-001/hdfsBaseDir/data/data4/]]  heartbeating to localhost/127.0.0.1:35443) [    ] o.a.h.h.s.d.DataNode Ending block pool service for: Block pool BP-968347885-127.0.1.1-1458793441285 (Datanode Uuid c48cef8e-d1c1-4fa3-90c9-c2e0461c78c1) service to localhost/127.0.0.1:35443
   [junit4]   2> 444333 WARN  (SUITE-HdfsDirectoryTest-seed#[6BF936321AE9FC53]-worker) [    ] o.a.h.h.s.d.DirectoryScanner DirectoryScanner: shutdown has been called
   [junit4]   2> 444335 INFO  (SUITE-HdfsDirectoryTest-seed#[6BF936321AE9FC53]-worker) [    ] o.m.log Stopped HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:0
   [junit4]   2> 444438 WARN  (DataNode: [[[DISK]file:/var/lib/jenkins/jobs/Lucene-Solr-tests-6.x/workspace/solr/build/solr-core/test/J5/temp/solr.store.hdfs.HdfsDirectoryTest_6BF936321AE9FC53-001/tempDir-001/hdfsBaseDir/data/data1/, [DISK]file:/var/lib/jenkins/jobs/Lucene-Solr-tests-6.x/workspace/solr/build/solr-core/test/J5/temp/solr.store.hdfs.HdfsDirectoryTest_6BF936321AE9FC53-001/tempDir-001/hdfsBaseDir/data/data2/]]  heartbeating to localhost/127.0.0.1:35443) [    ] o.a.h.h.s.d.DataNode BPOfferService for Block pool BP-968347885-127.0.1.1-1458793441285 (Datanode Uuid a1c6edfb-4bb8-4e12-a3d4-dc5308fd9199) service to localhost/127.0.0.1:35443 interrupted
   [junit4]   2> 444438 WARN  (DataNode: [[[DISK]file:/var/lib/jenkins/jobs/Lucene-Solr-tests-6.x/workspace/solr/build/solr-core/test/J5/temp/solr.store.hdfs.HdfsDirectoryTest_6BF936321AE9FC53-001/tempDir-001/hdfsBaseDir/data/data1/, [DISK]file:/var/lib/jenkins/jobs/Lucene-Solr-tests-6.x/workspace/solr/build/solr-core/test/J5/temp/solr.store.hdfs.HdfsDirectoryTest_6BF936321AE9FC53-001/tempDir-001/hdfsBaseDir/data/data2/]]  heartbeating to localhost/127.0.0.1:35443) [    ] o.a.h.h.s.d.DataNode Ending block pool service for: Block pool BP-968347885-127.0.1.1-1458793441285 (Datanode Uuid a1c6edfb-4bb8-4e12-a3d4-dc5308fd9199) service to localhost/127.0.0.1:35443
   [junit4]   2> 444441 WARN  (org.apache.hadoop.hdfs.server.blockmanagement.DecommissionManager$Monitor@f84709f) [    ] o.a.h.h.s.b.DecommissionManager Monitor interrupted: java.lang.InterruptedException: sleep interrupted
   [junit4]   2> 444443 INFO  (SUITE-HdfsDirectoryTest-seed#[6BF936321AE9FC53]-worker) [    ] o.m.log Stopped HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:0
   [junit4]   2> 444545 ERROR (SUITE-HdfsDirectoryTest-seed#[6BF936321AE9FC53]-worker) [    ] o.a.h.m.l.MethodMetric Error invoking method getBlocksTotal
   [junit4]   2> java.lang.reflect.InvocationTargetException
   [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:497)
   [junit4]   2> 	at org.apache.hadoop.metrics2.lib.MethodMetric$2.snapshot(MethodMetric.java:111)
   [junit4]   2> 	at org.apache.hadoop.metrics2.lib.MethodMetric.snapshot(MethodMetric.java:144)
   [junit4]   2> 	at org.apache.hadoop.metrics2.lib.MetricsRegistry.snapshot(MetricsRegistry.java:387)
   [junit4]   2> 	at org.apache.hadoop.metrics2.lib.MetricsSourceBuilder$1.getMetrics(MetricsSourceBuilder.java:79)
   [junit4]   2> 	at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.getMetrics(MetricsSourceAdapter.java:195)
   [junit4]   2> 	at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.updateJmxCache(MetricsSourceAdapter.java:172)
   [junit4]   2> 	at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.getMBeanInfo(MetricsSourceAdapter.java:151)
   [junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.getClassName(DefaultMBeanServerInterceptor.java:1804)
   [junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.safeGetClassName(DefaultMBeanServerInterceptor.java:1595)
   [junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.checkMBeanPermission(DefaultMBeanServerInterceptor.java:1813)
   [junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.exclusiveUnregisterMBean(DefaultMBeanServerInterceptor.java:430)
   [junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.unregisterMBean(DefaultMBeanServerInterceptor.java:415)
   [junit4]   2> 	at com.sun.jmx.mbeanserver.JmxMBeanServer.unregisterMBean(JmxMBeanServer.java:546)
   [junit4]   2> 	at org.apache.hadoop.metrics2.util.MBeans.unregister(MBeans.java:81)
   [junit4]   2> 	at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.stopMBeans(MetricsSourceAdapter.java:227)
   [junit4]   2> 	at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.stop(MetricsSourceAdapter.java:212)
   [junit4]   2> 	at org.apache.hadoop.metrics2.impl.MetricsSystemImpl.stopSources(MetricsSystemImpl.java:461)
   [junit4]   2> 	at org.apache.hadoop.metrics2.impl.MetricsSystemImpl.stop(MetricsSystemImpl.java:212)
   [junit4]   2> 	at org.apache.hadoop.metrics2.impl.MetricsSystemImpl.shutdown(MetricsSystemImpl.java:592)
   [junit4]   2> 	at org.apache.hadoop.metrics2.lib.DefaultMetricsSystem.shutdownInstance(DefaultMetricsSystem.java:72)
   [junit4]   2> 	at org.apache.hadoop.metrics2.lib.DefaultMetricsSystem.shutdown(DefaultMetricsSystem.java:68)
   [junit4]   2> 	at org.apache.hadoop.hdfs.server.namenode.metrics.NameNodeMetrics.shutdown(NameNodeMetrics.java:145)
   [junit4]   2> 	at org.apache.hadoop.hdfs.server.namenode.NameNode.stop(NameNode.java:822)
   [junit4]   2> 	at org.apache.hadoop.hdfs.MiniDFSCluster.shutdown(MiniDFSCluster.java:1720)
   [junit4]   2> 	at org.apache.hadoop.hdfs.MiniDFSCluster.shutdown(MiniDFSCluster.java:1699)
   [junit4]   2> 	at org.apache.solr.cloud.hdfs.HdfsTestUtil.teardownClass(HdfsTestUtil.java:198)
   [junit4]   2> 	at org.apache.solr.store.hdfs.HdfsDirectoryTest.afterClass(HdfsDirectoryTest.java:66)
   [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:497)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1764)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:834)
   [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:367)
   [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:198)
   [junit4]   2> 	at org.apache.hadoop.hdfs.server.blockmanagement.BlockManager.getTotalBlocks(BlockManager.java:3291)
   [junit4]   2> 	at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.getBlocksTotal(FSNamesystem.java:6223)
   [junit4]   2> 	... 54 more
   [junit4]   2> 444549 INFO  (SUITE-HdfsDirectoryTest-seed#[6BF936321AE9FC53]-worker) [    ] o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> NOTE: leaving temporary files on disk at: /var/lib/jenkins/jobs/Lucene-Solr-tests-6.x/workspace/solr/build/solr-core/test/J5/temp/solr.store.hdfs.HdfsDirectoryTest_6BF936321AE9FC53-001
   [junit4]   2> Mar 24, 2016 12:24:13 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
   [junit4]   2> WARNING: Will linger awaiting termination of 2 leaked thread(s).
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene60): {}, docValues:{}, maxPointsInLeafNode=583, maxMBSortInHeap=4.08371409614075, sim=RandomSimilarity(queryNorm=false,coord=yes): {}, locale=hu, timezone=America/Nipigon
   [junit4]   2> NOTE: Linux 4.1.0-custom2-amd64 amd64/Oracle Corporation 1.8.0_45 (64-bit)/cpus=16,threads=3,free=98708736,total=524812288
   [junit4]   2> NOTE: All tests run in this JVM: [ChaosMonkeyNothingIsSafeTest, CursorMarkTest, DistanceUnitsTest, TestExactStatsCache, SchemaVersionSpecificBehaviorTest, TestCloudManagedSchema, TestImplicitCoreProperties, HdfsRecoverLeaseTest, NumericFieldsTest, TestDistributedMissingSort, TestCloudDeleteByQuery, DistributedTermsComponentTest, OverseerRolesTest, SimpleCollectionCreateDeleteTest, AnalyticsQueryTest, TestAddFieldRealTimeGet, TestIndexingPerformance, TestDocBasedVersionConstraints, TestOverriddenPrefixQueryForCustomFieldType, TestAuthenticationFramework, TestHashQParserPlugin, ZkStateWriterTest, HdfsDirectoryTest]
   [junit4] Completed [308/582 (3!)] on J5 in 22.09s, 4 tests, 1 error <<< FAILURES!

Attachments

Issue Links

duplicates

SOLR-8742 HdfsDirectoryTest fails reliably after changes in LUCENE-6932

Closed

Activity

People

Assignee:: Unassigned

Reporter:: Steven Rowe

Votes:: 0 Vote for this issue

Watchers:: 1 Start watching this issue

Dates

Created:: 24/Mar/16 12:34

Updated:: 24/Mar/16 13:39

Resolved:: 24/Mar/16 13:39