Hi,
I have 10 Node cluster running from last 25days( running with Hbase cluster).
Recently observed that for every continuos blocks scans, there are many
timeouts coming in DataNode.
After this block scan verifications, again reads succeeded. This situation
keep occurring many times now, for every continuous block scans. Here Hbase
continuously performing many random reads.
Whether any one faced this situation in your clusters?
Below is the logs with timeouts.
2011-12-28 11:30:42,618 INFO DataNode.clienttrace
(BlockSender.java:sendBlock(529)) - src: /107.252.175.3:10010, dest:
/107.252.175.3:52764, bytes: 264192, op: HDFS_READ, cliID:
DFSClient_hb_rs_107-252-175-3,20020,1324837769603_1324837770095_1770885334_27,
srvID: DS-306564179-107.252.175.3-10010-1322019943818, blockid:
blk_1323251633953_187190
2011-12-28 11:30:42,621 INFO DataNode.clienttrace
(BlockSender.java:sendBlock(529)) - src: /107.252.175.3:10010, dest:
/107.252.175.3:52772, bytes: 396288, op: HDFS_READ, cliID:
DFSClient_hb_rs_107-252-175-3,20020,1324837769603_1324837770095_1770885334_27,
srvID: DS-306564179-107.252.175.3-10010-1322019943818, blockid:
blk_1323251635735_188342
2011-12-28 11:30:42,641 INFO DataNode.clienttrace
(BlockSender.java:sendBlock(529)) - src: /107.252.175.3:10010, dest:
/107.252.175.3:52796, bytes: 396288, op: HDFS_READ, cliID:
DFSClient_hb_rs_107-252-175-3,20020,1324837769603_1324837770095_1770885334_27,
srvID: DS-306564179-107.252.175.3-10010-1322019943818, blockid:
blk_1323251634096_187277
2011-12-28 11:30:42,889 INFO DataNode.clienttrace
(BlockSender.java:sendBlock(529)) - src: /107.252.175.3:10010, dest:
/107.252.175.3:52732, bytes: 264192, op: HDFS_READ, cliID:
DFSClient_hb_rs_107-252-175-3,20020,1324837769603_1324837770095_1770885334_27,
srvID: DS-306564179-107.252.175.3-10010-1322019943818, blockid:
blk_1323251635763_188363
2011-12-28 11:30:42,889 INFO DataNode.clienttrace
(BlockSender.java:sendBlock(529)) - src: /107.252.175.3:10010, dest:
/107.252.175.3:52637, bytes: 264192, op: HDFS_READ, cliID:
DFSClient_hb_rs_107-252-175-3,20020,1324837769603_1324837770095_1770885334_27,
srvID: DS-306564179-107.252.175.3-10010-1322019943818, blockid:
blk_1323251634921_187798
2011-12-28 11:30:42,976 INFO DataNode.clienttrace
(BlockSender.java:sendBlock(529)) - src: /107.252.175.3:10010, dest:
/107.252.175.3:52755, bytes: 396288, op: HDFS_READ, cliID:
DFSClient_hb_rs_107-252-175-3,20020,1324837769603_1324837770095_1770885334_27,
srvID: DS-306564179-107.252.175.3-10010-1322019943818, blockid:
blk_1323251635359_188075
2011-12-28 11:30:57,757 INFO datanode.DataBlockScanner
(DataBlockScanner.java:verifyBlock(481)) - Verification succeeded for
blk_1323251602823_167208
2011-12-28 11:32:15,757 INFO datanode.DataBlockScanner
(DataBlockScanner.java:verifyBlock(481)) - Verification succeeded for
blk_1323251599175_166755
2011-12-28 11:32:54,561 INFO datanode.DataBlockScanner
(DataBlockScanner.java:verifyBlock(481)) - Verification succeeded for
blk_1323251673745_194676
2011-12-28 11:33:33,561 INFO datanode.DataBlockScanner
(DataBlockScanner.java:verifyBlock(481)) - Verification succeeded for
blk_1323251640709_189383
2011-12-28 11:34:12,557 INFO datanode.DataBlockScanner
(DataBlockScanner.java:verifyBlock(481)) - Verification succeeded for
blk_1323251649630_190779
2011-12-28 11:34:51,557 INFO datanode.DataBlockScanner
(DataBlockScanner.java:verifyBlock(481)) - Verification succeeded for
blk_1323251463964_91885
2011-12-28 11:35:23,958 INFO datanode.DataBlockScanner
(DataBlockScanner.java:verifyBlock(481)) - Verification succeeded for
blk_1323251636310_188845
2011-12-28 11:36:01,155 INFO datanode.DataBlockScanner
(DataBlockScanner.java:verifyBlock(481)) - Verification succeeded for
blk_1322486683238_54999
2011-12-28 11:36:04,157 INFO datanode.DataBlockScanner
(DataBlockScanner.java:verifyBlock(481)) - Verification succeeded for
blk_1323251678959_195786
2011-12-28 11:36:43,157 INFO datanode.DataBlockScanner
(DataBlockScanner.java:verifyBlock(481)) - Verification succeeded for
blk_1323251641803_189561
2011-12-28 11:37:20,357 INFO datanode.DataBlockScanner
(DataBlockScanner.java:verifyBlock(481)) - Verification succeeded for
blk_1322486706170_66445
2011-12-28 11:37:44,759 INFO datanode.DataBlockScanner
(DataBlockScanner.java:verifyBlock(481)) - Verification succeeded for
blk_1323251646924_190359
2011-12-28 11:38:23,759 INFO datanode.DataBlockScanner
(DataBlockScanner.java:verifyBlock(481)) - Verification succeeded for
blk_1323251673776_194683
2011-12-28 11:38:30,157 INFO datanode.DataBlockScanner
(DataBlockScanner.java:verifyBlock(481)) - Verification succeeded for
blk_1323251621379_178399
2011-12-28 11:38:37,549 INFO DataNode.clienttrace
(BlockSender.java:sendBlock(529)) - src: /107.252.175.3:10010, dest:
/107.252.175.3:51942, bytes: 396288, op: HDFS_READ, cliID:
DFSClient_hb_rs_107-252-175-3,20020,1324837769603_1324837770095_1770885334_27,
srvID: DS-306564179-107.252.175.3-10010-1322019943818, blockid:
blk_1323251634345_187432
2011-12-28 11:38:37,550 WARN datanode.DataNode
(DataXceiver.java:readBlock(274)) - DatanodeRegistration(107.252.175.3:10010,
storageID=DS-306564179-107.252.175.3-10010-1322019943818, infoPort=10075,
ipcPort=10020):Got exception while serving blk_1323251634345_187432 to
/107.252.175.3:
java.net.SocketTimeoutException: 480000 millis timeout while waiting for
channel to be ready for write. ch : java.nio.channels.SocketChannel[connected
local=/107.252.175.3:10010 remote=/107.252.175.3:51942]
at
org.apache.hadoop.net.SocketIOWithTimeout.waitForIO(SocketIOWithTimeout.java:249)
at
org.apache.hadoop.net.SocketOutputStream.waitForWritable(SocketOutputStream.java:159)
at
org.apache.hadoop.net.SocketOutputStream.transferToFully(SocketOutputStream.java:198)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendChunks(BlockSender.java:410)
at
org.apache.hadoop.hdfs.server.datanode.BlockSender.sendBlock(BlockSender.java:508)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.readBlock(DataXceiver.java:247)
at
org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:130)
at java.lang.Thread.run(Thread.java:662)
Regards,
Uma
