记一次HDFS报EOFException: End of File Exception异常的问题

记一次HDFS报EOFException: End of File Exception异常的问题

2018-09-07 20:32:16

## 现象

大晚上的收到线上DataNode挂掉异常的报警，值班同学随即做了重启处理，重启完成后，进程虽然在运行，但是NameNode的WebUI上显示大量的block丢失。

- There are 12622047 missing blocks.
- Number of Under-Replicated Blocks	14436901
- 重新启动的DataNode节点block数量为0，明显不正常

HDFS在对丢失的block做恢复，missing blocks的数量在减少，但是丢失的的太多了，恢复速度很慢，这种情况肯定不能指望集群自动恢复的。

看了下DataNode的数据目录，大小没什么变化，第一感觉应该是block的数据还在，但不知为何NameNode认为这些block丢失了。

业务侧报警持续，情况紧急，需要赶紧分析原因，恢复这些missing的block。

## 定位

看了下出现异常的DataNode节点日志，发现以下异常

```
2018-09-04 23:24:38,446 WARN org.apache.hadoop.hdfs.server.datanode.DataBlockScanner: No block pool scanner found for block pool id: BP-21853433-xxxxxxxxx-1484835379573
2018-09-05 00:45:13,777 INFO org.apache.hadoop.hdfs.server.datanode.DataNode: Unsuccessfully sent block report 0xa7b72c5217b7ac,  containing 1 storage report(s), of which we sent 0. The reports had 6076010 total blocks and used 0 RPC(s). This took 1636 msec to generate and 1082 msecs for RPC and NN processing. Got back no commands.
2018-09-05 00:45:13,777 WARN org.apache.hadoop.hdfs.server.datanode.DataNode: IOException in offerService
java.io.EOFException: End of File Exception between local host is: "xxxx"; destination host is: "xxx":53310; : java.io.EOFException; For more details see:  http://wiki.apache.org/hadoop/EOFException
	at sun.reflect.GeneratedConstructorAccessor8.newInstance(Unknown Source)
	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
	at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
	at org.apache.hadoop.net.NetUtils.wrapWithMessage(NetUtils.java:791)
	at org.apache.hadoop.net.NetUtils.wrapException(NetUtils.java:764)
	at org.apache.hadoop.ipc.Client.call(Client.java:1473)
	at org.apache.hadoop.ipc.Client.call(Client.java:1400)
	at org.apache.hadoop.ipc.ProtobufRpcEngine$Invoker.invoke(ProtobufRpcEngine.java:232)
	at com.sun.proxy.$Proxy12.blockReport(Unknown Source)
	at org.apache.hadoop.hdfs.protocolPB.DatanodeProtocolClientSideTranslatorPB.blockReport(DatanodeProtocolClientSideTranslatorPB.java:177)
	at org.apache.hadoop.hdfs.server.datanode.BPServiceActor.blockReport(BPServiceActor.java:524)
	at org.apache.hadoop.hdfs.server.datanode.BPServiceActor.offerService(BPServiceActor.java:750)
	at org.apache.hadoop.hdfs.server.datanode.BPServiceActor.run(BPServiceActor.java:889)
	at java.lang.Thread.run(Thread.java:745)
Caused by: java.io.EOFException
	at java.io.DataInputStream.readInt(DataInputStream.java:392)
	at org.apache.hadoop.ipc.Client$Connection.receiveRpcResponse(Client.java:1072)
	at org.apache.hadoop.ipc.Client$Connection.run(Client.java:967)
```

一开始的主要精力放在DataBlockScanner这个警告上了，网上查了一顿也没找到什么有价值的信息。

后来又关注了下EOFException这个异常，根据异常给的链接提示<http://wiki.apache.org/hadoop/EOFException>，看了下这个异常的原因：

1. 服务异常重启了，RPC过程中网络通信异常（比如服务重启，HA failover发生主从切换）
2. 通信协议不匹配，如：DataNode节点的Hadoop版本和NameNode不一致

要说服务重启，我这只有DataNode重启了，NameNode没变化；集群的Hadoop版本也是一致的，所以，都不是以上2点原因导致的`EOFException`异常。

好没头绪，接着又看了下NameNode日志，发现一个关键性的信息：

```
Requested data length 67521863 is longer than maximum configured RPC length 67108864
```

在结合DataNode的异常堆栈信息，大悟，应该是ipc的数据包过大导致的，知道问题所在，应该就好解决了。

## 解决

修改NameNode的hdfs-site.xml配置文件，添加以下配置：

```
<property>
    <name>ipc.maximum.data.length</name>
    <value>134217728</value>
</property>
```

允许ipc通讯最大的数据包为128MB，默认配置为64MB。

最后平滑重启NameNode，在重启异常的DataNode解决。

## 总结

出问题的集群规模比较小，但是小文件数量特别多。

从日志看是内存不足导致DataNode跪了，然后随即的重启，DataNode要给NameNode上报block信息，由于block信息较多，ipc通信的数据包超过了64MB，NameNode返回异常了，导致DataNode这边出现`EOFException`的异常，由于这个异常，DataNode没能把block信息上报给NameNode，NameNode就认为block丢失了。

这次的问题是由于block数量较多导致，也分析了下block数量与资源消耗的关系，针对单个DataNode上有500W个左右的block，大概消耗如下：

- DataNode内存6GB左右 
- 一次性向NameNode汇报block的ipc数据包大小约为64MB

今后维护HDFS可以根据block的数量信息分配合理的内存和`ipc.maximum.data.length`大小了。

好在出问题是在晚上，对业务没有产生太多影响。嗯，又多了些HDFS维护经验。

非特殊说明，均为原创，原创文章，未经允许谢绝转载。
原始链接：记一次HDFS报EOFException: End of File Exception异常的问题

stanzhai

赏