[
https://issues.apache.org/jira/browse/HDFS-5042?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14170512#comment-14170512
]
Vikas Vishwakarma commented on HDFS-5042:
-----------------------------------------
Updating the results for 1000 files DFSIO write test run with dirsync
enabled/disabled and results for both runs are similar except for a very small
diff in Avg IO rate of -2% with dirsync enabled.
DFSIO Test:
./hadoop jar
$HADOOP_HOME/share/hadoop/mapreduce/hadoop-mapreduce-client-jobclient-2.3.0-cdh5.0.1-sfdc-2.0.0-tests.jar
TestDFSIO -write -nrFiles 1000 -fileSize 1000
Env1 (Datanodes:15, Containers:29, mount options: rw,dirsync,noatime)
===========================================================
14/10/14 04:11:47 [main] INFO fs.TestDFSIO(855): ----- TestDFSIO ----- : write
14/10/14 04:11:47 [main] INFO fs.TestDFSIO(855): Date & time: Tue
Oct 14 04:11:47 GMT+00:00 2014
14/10/14 04:11:47 [main] INFO fs.TestDFSIO(855): Number of files: 1000
14/10/14 04:11:47 [main] INFO fs.TestDFSIO(855): Total MBytes processed:
1000000.0
14/10/14 04:11:47 [main] INFO fs.TestDFSIO(855): Throughput mb/sec:
21.114069074888118
14/10/14 04:11:47 [main] INFO fs.TestDFSIO(855): Average IO rate mb/sec:
21.986719131469727
14/10/14 04:11:47 [main] INFO fs.TestDFSIO(855): IO rate std deviation:
4.507905485162703
14/10/14 04:11:47 [main] INFO fs.TestDFSIO(855): Test exec time sec:
1937.989
14/10/14 04:11:47 [main] INFO fs.TestDFSIO(855):
Env2 (Datanodes:15, Containers:29, mount options: rw,noatime)
====================================================
14/10/14 04:32:25 [main] INFO fs.TestDFSIO(855): ----- TestDFSIO ----- : write
14/10/14 04:32:25 [main] INFO fs.TestDFSIO(855): Date & time: Tue
Oct 14 04:32:25 GMT 2014
14/10/14 04:32:25 [main] INFO fs.TestDFSIO(855): Number of files: 1000
14/10/14 04:32:25 [main] INFO fs.TestDFSIO(855): Total MBytes processed:
1000000.0
14/10/14 04:32:25 [main] INFO fs.TestDFSIO(855): Throughput mb/sec:
21.391594681989666
14/10/14 04:32:25 [main] INFO fs.TestDFSIO(855): Average IO rate mb/sec:
22.406478881835938
14/10/14 04:32:25 [main] INFO fs.TestDFSIO(855): IO rate std deviation:
5.169537520933585
14/10/14 04:32:25 [main] INFO fs.TestDFSIO(855): Test exec time sec:
1872.904
14/10/14 04:32:25 [main] INFO fs.TestDFSIO(855):
> Completed files lost after power failure
> ----------------------------------------
>
> Key: HDFS-5042
> URL: https://issues.apache.org/jira/browse/HDFS-5042
> Project: Hadoop HDFS
> Issue Type: Bug
> Environment: ext3 on CentOS 5.7 (kernel 2.6.18-274.el5)
> Reporter: Dave Latham
> Priority: Critical
>
> We suffered a cluster wide power failure after which HDFS lost data that it
> had acknowledged as closed and complete.
> The client was HBase which compacted a set of HFiles into a new HFile, then
> after closing the file successfully, deleted the previous versions of the
> file. The cluster then lost power, and when brought back up the newly
> created file was marked CORRUPT.
> Based on reading the logs it looks like the replicas were created by the
> DataNodes in the 'blocksBeingWritten' directory. Then when the file was
> closed they were moved to the 'current' directory. After the power cycle
> those replicas were again in the blocksBeingWritten directory of the
> underlying file system (ext3). When those DataNodes reported in to the
> NameNode it deleted those replicas and lost the file.
> Some possible fixes could be having the DataNode fsync the directory(s) after
> moving the block from blocksBeingWritten to current to ensure the rename is
> durable or having the NameNode accept replicas from blocksBeingWritten under
> certain circumstances.
> Log snippets from RS (RegionServer), NN (NameNode), DN (DataNode):
> {noformat}
> RS 2013-06-29 11:16:06,812 DEBUG org.apache.hadoop.hbase.util.FSUtils:
> Creating
> file=hdfs://hm3:9000/hbase/users-6/b5b0820cde759ae68e333b2f4015bb7e/.tmp/6e0cc30af6e64e56ba5a539fdf159c4c
> with permission=rwxrwxrwx
> NN 2013-06-29 11:16:06,830 INFO org.apache.hadoop.hdfs.StateChange: BLOCK*
> NameSystem.allocateBlock:
> /hbase/users-6/b5b0820cde759ae68e333b2f4015bb7e/.tmp/6e0cc30af6e64e56ba5a539fdf159c4c.
> blk_1395839728632046111_357084589
> DN 2013-06-29 11:16:06,832 INFO
> org.apache.hadoop.hdfs.server.datanode.DataNode: Receiving block
> blk_1395839728632046111_357084589 src: /10.0.5.237:14327 dest:
> /10.0.5.237:50010
> NN 2013-06-29 11:16:11,370 INFO org.apache.hadoop.hdfs.StateChange: BLOCK*
> NameSystem.addStoredBlock: blockMap updated: 10.0.6.1:50010 is added to
> blk_1395839728632046111_357084589 size 25418340
> NN 2013-06-29 11:16:11,370 INFO org.apache.hadoop.hdfs.StateChange: BLOCK*
> NameSystem.addStoredBlock: blockMap updated: 10.0.6.24:50010 is added to
> blk_1395839728632046111_357084589 size 25418340
> NN 2013-06-29 11:16:11,385 INFO org.apache.hadoop.hdfs.StateChange: BLOCK*
> NameSystem.addStoredBlock: blockMap updated: 10.0.5.237:50010 is added to
> blk_1395839728632046111_357084589 size 25418340
> DN 2013-06-29 11:16:11,385 INFO
> org.apache.hadoop.hdfs.server.datanode.DataNode: Received block
> blk_1395839728632046111_357084589 of size 25418340 from /10.0.5.237:14327
> DN 2013-06-29 11:16:11,385 INFO
> org.apache.hadoop.hdfs.server.datanode.DataNode: PacketResponder 2 for block
> blk_1395839728632046111_357084589 terminating
> NN 2013-06-29 11:16:11,385 INFO org.apache.hadoop.hdfs.StateChange: Removing
> lease on file
> /hbase/users-6/b5b0820cde759ae68e333b2f4015bb7e/.tmp/6e0cc30af6e64e56ba5a539fdf159c4c
> from client DFSClient_hb_rs_hs745,60020,1372470111932
> NN 2013-06-29 11:16:11,385 INFO org.apache.hadoop.hdfs.StateChange: DIR*
> NameSystem.completeFile: file
> /hbase/users-6/b5b0820cde759ae68e333b2f4015bb7e/.tmp/6e0cc30af6e64e56ba5a539fdf159c4c
> is closed by DFSClient_hb_rs_hs745,60020,1372470111932
> RS 2013-06-29 11:16:11,393 INFO org.apache.hadoop.hbase.regionserver.Store:
> Renaming compacted file at
> hdfs://hm3:9000/hbase/users-6/b5b0820cde759ae68e333b2f4015bb7e/.tmp/6e0cc30af6e64e56ba5a539fdf159c4c
> to
> hdfs://hm3:9000/hbase/users-6/b5b0820cde759ae68e333b2f4015bb7e/n/6e0cc30af6e64e56ba5a539fdf159c4c
> RS 2013-06-29 11:16:11,505 INFO org.apache.hadoop.hbase.regionserver.Store:
> Completed major compaction of 7 file(s) in n of
> users-6,\x12\xBDp\xA3,1359426311784.b5b0820cde759ae68e333b2f4015bb7e. into
> 6e0cc30af6e64e56ba5a539fdf159c4c, size=24.2m; total size for store is 24.2m
> ------- CRASH, RESTART ---------
> NN 2013-06-29 12:01:19,743 INFO org.apache.hadoop.hdfs.StateChange: BLOCK*
> NameSystem.addStoredBlock: addStoredBlock request received for
> blk_1395839728632046111_357084589 on 10.0.6.1:50010 size 21978112 but was
> rejected: Reported as block being written but is a block of closed file.
> NN 2013-06-29 12:01:19,743 INFO org.apache.hadoop.hdfs.StateChange: BLOCK*
> NameSystem.addToInvalidates: blk_1395839728632046111 is added to invalidSet
> of 10.0.6.1:50010
> NN 2013-06-29 12:01:20,155 INFO org.apache.hadoop.hdfs.StateChange: BLOCK*
> NameSystem.addStoredBlock: addStoredBlock request received for
> blk_1395839728632046111_357084589 on 10.0.5.237:50010 size 16971264 but was
> rejected: Reported as block being written but is a block of closed file.
> NN 2013-06-29 12:01:20,155 INFO org.apache.hadoop.hdfs.StateChange: BLOCK*
> NameSystem.addToInvalidates: blk_1395839728632046111 is added to invalidSet
> of 10.0.5.237:50010
> NN 2013-06-29 12:01:20,175 INFO org.apache.hadoop.hdfs.StateChange: BLOCK*
> NameSystem.addStoredBlock: addStoredBlock request received for
> blk_1395839728632046111_357084589 on 10.0.6.24:50010 size 21913088 but was
> rejected: Reported as block being written but is a block of closed file.
> NN 2013-06-29 12:01:20,175 INFO org.apache.hadoop.hdfs.StateChange: BLOCK*
> NameSystem.addToInvalidates: blk_1395839728632046111 is added to invalidSet
> of 10.0.6.24:50010
> (note the clock on the server running DN is wrong after restart. I believe
> timestamps are off by 6 hours:)
> DN 2013-06-29 06:07:22,877 INFO
> org.apache.hadoop.hdfs.server.datanode.DataNode: Scheduling block
> blk_1395839728632046111_357084589 file
> /data/hadoop/dfs/data/blocksBeingWritten/blk_1395839728632046111 for deletion
> DN 2013-06-29 06:07:24,952 INFO
> org.apache.hadoop.hdfs.server.datanode.DataNode: Deleted block
> blk_1395839728632046111_357084589 at file
> /data/hadoop/dfs/data/blocksBeingWritten/blk_1395839728632046111
> {noformat}
> There was some additional discussion on this thread on the mailing list:
> http://mail-archives.apache.org/mod_mbox/hadoop-hdfs-user/201307.mbox/%3CCA+qbEUPuf19PL_EVeWi1104+scLVrcS0LTFUvBPw=qcuxnz...@mail.gmail.com%3E
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
