现象: 执行mapreduce任务时失败
通过hadoop fsck -openforwrite命令查看发现有文件没有关闭。
[root@com ~]# hadoop fsck -openforwrite /data/rc/click/mpp/15-08-05/
DEPRECATED: Use of this script to execute hdfs command is deprecated.
Instead use the hdfs command for it.
Connecting to namenode via http://com.hunantv.hadoopnamenode:50070
FSCK started by root (auth:SIMPLE) from /10.100.1.46 for path /data/rc/click/mpp/15-08-05/ at Thu Aug 06 14:05:03 CST 2015
....................................................................................................
....................................................................................................
........./data/rc/click/mpp/15-08-05/FlumeData.1438758322864 42888 bytes, 1 block(s), OPENFORWRITE:
/data/rc/click/mpp/15-08-05/FlumeData.1438758322864: Under replicated BP-1672356070-10.100.1.36-1412072991411:blk_1120646538_47162789{blockUCState=UNDER_CONSTRUCTION, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-f4fff5f3-f3fd-4054-a75c-1d7da53a73af:NORMAL|FINALIZED], ReplicaUnderConstruction[[DISK]DS-26f54bc5-5026-4e6a-94ec-8435224e4aa9:NORMAL|RWR], ReplicaUnderConstruction[[DISK]DS-4ab3fffc-6468-47df-8023-79f23a330371:NORMAL|FINALIZED]]}. Target Replicas is 3 but found 2 replica(s).
..........................................................................................
............................Status: HEALTHY
Total size: 99186583 B
Total dirs: 1
Total files: 328
Total symlinks: 0
Total blocks (validated): 328 (avg. block size 302398 B)
Minimally replicated blocks: 328 (100.0 %)
Over-replicated blocks: 0 (0.0 %)
Under-replicated blocks: 1 (0.30487806 %)
Mis-replicated blocks: 0 (0.0 %)
Default replication factor: 3
Average block replication: 2.996951
Corrupt blocks: 0
Missing replicas: 1 (0.101626016 %)
Number of data-nodes: 59
Number of racks: 6
FSCK ended at Thu Aug 06 14:05:03 CST 2015 in 36 milliseconds
The filesystem under path '/data/rc/click/mpp/15-08-05/' is HEALTHY
查看FLume日志
[root@10.100.1.117] out: 05 Aug 2015 11:15:19,322 INFO [SinkRunner-PollingRunner-DefaultSinkProcessor] (org.apache.flume.sink.hdfs.BucketWriter.open:234) - Creating hdfs://com.hunantv.hadoopnamenode:8020/data/logs/amobile/vod/15-08-05/FlumeData.1438744519293.tmp
[root@10.100.1.117] out: 05 Aug 2015 11:16:20,493 INFO [hdfs-sin_hdfs_201-roll-timer-0] (org.apache.flume.sink.hdfs.BucketWriter$5.call:429) - Closing idle bucketWriter hdfs://com.hunantv.hadoopnamenode:8020/data/logs/amobile/vod/15-08-05/FlumeData.1438744519293.tmp at 1438744580493
[root@10.100.1.117] out: 05 Aug 2015 11:16:20,497 INFO [hdfs-sin_hdfs_201-roll-timer-0] (org.apache.flume.sink.hdfs.BucketWriter.close:363) - Closing hdfs://com.hunantv.hadoopnamenode:8020/data/logs/amobile/vod/15-08-05/FlumeData.1438744519293.tmp
[root@10.100.1.117] out: 05 Aug 2015 11:16:30,501 WARN [hdfs-sin_hdfs_201-roll-timer-0] (org.apache.flume.sink.hdfs.BucketWriter.close:370) - failed to close() HDFSWriter for file (hdfs://com.hunantv.hadoopnamenode:8020/data/logs/amobile/vod/15-08-05/FlumeData.1438744519293.tmp). Exception follows.
[root@10.100.1.117] out: java.io.IOException: Callable timed out after 10000 ms on file: hdfs://com.hunantv.hadoopnamenode:8020/data/logs/amobile/vod/15-08-05/FlumeData.1438744519293.tmp
[root@10.100.1.117] out: 05 Aug 2015 11:16:30,503 INFO [hdfs-sin_hdfs_201-call-runner-7] (org.apache.flume.sink.hdfs.BucketWriter$8.call:629) - Renaming hdfs://com.hunantv.hadoopnamenode:8020/data/logs/amobile/vod/15-08-05/FlumeData.1438744519293.tmp to hdfs://com.hunantv.hadoopnamenode:8020/data/logs/amobile/vod/15-08-05/FlumeData.1438744519293
关闭hdfs文件操作因为超时失败,
查看源码:
public synchronized void close(boolean callCloseCallback) throws IOException, InterruptedException { checkAndThrowInterruptedException(); try { flush(); } catch (IOException e) { LOG.warn("pre-close flush failed", e); } boolean failedToClose = false; LOG.info("Closing {}", bucketPath); CallRunner<Void> closeCallRunner = createCloseCallRunner(); if (isOpen) { try { callWithTimeout(closeCallRunner); sinkCounter.incrementConnectionClosedCount(); } catch (IOException e) { LOG.warn( "failed to close() HDFSWriter for file (" + bucketPath + "). Exception follows.", e); sinkCounter.incrementConnectionFailedCount(); failedToClose = true; } isOpen = false; } else { LOG.info("HDFSWriter is already closed: {}", bucketPath); } // NOTE: timed rolls go through this codepath as well as other roll types if (timedRollFuture != null && !timedRollFuture.isDone()) { timedRollFuture.cancel(false); // do not cancel myself if running! timedRollFuture = null; } if (idleFuture != null && !idleFuture.isDone()) { idleFuture.cancel(false); // do not cancel myself if running! idleFuture = null; } if (bucketPath != null && fileSystem != null) { // could block or throw IOException try { renameBucket(bucketPath, targetPath, fileSystem); } catch(Exception e) { LOG.warn( "failed to rename() file (" + bucketPath + "). Exception follows.", e); sinkCounter.incrementConnectionFailedCount(); final Callable<Void> scheduledRename = createScheduledRenameCallable(); timedRollerPool.schedule(scheduledRename, retryInterval, TimeUnit.SECONDS); } } if (callCloseCallback) { runCloseAction(); closed = true; } }
默认超时为10000ms,失败后没有重试,代码中有 failedToClose变量, 但未用到,可能开发人员忘了处理了。。。
解决方法:
1. 配置调用操作超时时间,将其调大一点,如5分钟。Flume hdfs sink配置如下:
agent12.sinks.sin_hdfs_201.type=hdfs
agent12.sinks.sin_hdfs_201.channel=ch_hdfs_201
agent12.sinks.sin_hdfs_201.hdfs.path=hdfs://com.hunantv.hadoopnamenode:8020/data/logs/amobile/vod/15-%{month}-%{day}
agent12.sinks.sin_hdfs_201.hdfs.round=true
agent12.sinks.sin_hdfs_201.hdfs.roundValue=10
agent12.sinks.sin_hdfs_201.hdfs.roundUnit=minute
agent12.sinks.sin_hdfs_201.hdfs.fileType=DataStream
agent12.sinks.sin_hdfs_201.hdfs.writeFormat=Text
agent12.sinks.sin_hdfs_201.hdfs.rollInterval=0
agent12.sinks.sin_hdfs_201.hdfs.rollSize=209715200
agent12.sinks.sin_hdfs_201.hdfs.rollCount=0
agent12.sinks.sin_hdfs_201.hdfs.idleTimeout=300
agent12.sinks.sin_hdfs_201.hdfs.batchSize=100
agent12.sinks.sin_hdfs_201.hdfs.minBlockReplicas=1
agent12.sinks.sin_hdfs_201.hdfs.callTimeout=300000
2. 修改源码,增加重试。如下:
public synchronized void close(boolean callCloseCallback) throws IOException, InterruptedException { checkAndThrowInterruptedException(); try { flush(); } catch (IOException e) { LOG.warn("pre-close flush failed", e); } boolean failedToClose = false; LOG.info("Closing {}", bucketPath); CallRunner<Void> closeCallRunner = createCloseCallRunner(); int tryTime = 1; while (isOpen && tryTime <= 5) { try { callWithTimeout(closeCallRunner); sinkCounter.incrementConnectionClosedCount(); } catch (IOException e) { LOG.warn( "failed to close() HDFSWriter for file (try times:" + tryTime + "): " + bucketPath + ". Exception follows.", e); sinkCounter.incrementConnectionFailedCount(); failedToClose = true; } if (failedToClose) { isOpen = true; tryTime++; Thread.sleep(this.callTimeout); } else { isOpen = false; } } //如果isopen失敗 if (isOpen) { LOG.error("failed to close file: " + bucketPath + " after " + tryTime + " tries."); } else { LOG.info("HDFSWriter is already closed: {}", bucketPath); } // NOTE: timed rolls go through this codepath as well as other roll types if (timedRollFuture != null && !timedRollFuture.isDone()) { timedRollFuture.cancel(false); // do not cancel myself if running! timedRollFuture = null; } if (idleFuture != null && !idleFuture.isDone()) { idleFuture.cancel(false); // do not cancel myself if running! idleFuture = null; } if (bucketPath != null && fileSystem != null) { // could block or throw IOException try { renameBucket(bucketPath, targetPath, fileSystem); } catch (Exception e) { LOG.warn( "failed to rename() file (" + bucketPath + "). Exception follows.", e); sinkCounter.incrementConnectionFailedCount(); final Callable<Void> scheduledRename = createScheduledRenameCallable(); timedRollerPool.schedule(scheduledRename, retryInterval, TimeUnit.SECONDS); } } if (callCloseCallback) { runCloseAction(); closed = true; } }