Details
Major Description
BP service actor LastHeartbeat is not sufficient to track realtime connection breaks.
Each BP service actor thread maintains lastHeartbeatTime with the namenode that it is connected to. However, this is updated even if the connection to the namenode is broken.
Suppose, the actor thread keeps heartbeating to namenode and suddenly the socket connection is broken. When this happens, until specific time duration, the actor thread consistently keeps updating lastHeartbeatTime before even initiating heartbeat connection with namenode. If connection cannot be established even after RPC retries are exhausted, then IOException is thrown. This means that heartbeat response has not been received from the namenode. In the loop, the actor thread keeps trying connecting for heartbeat and the last heartbeat stays close to 1/2s even though in reality there is no response being received from namenode.
Sample Exception from the BP service actor thread, during which LastHeartbeat stays very low:
2023-02-03 22:34:55,725 WARN [xyz:9000] datanode.DataNode - IOException in offerService java.io.EOFException: End of File Exception between local host is: "dn-0"; destination host is: "nn-1":9000; : java.io.EOFException; For more details see: http://wiki.apache.org/hadoop/EOFException at sun.reflect.GeneratedConstructorAccessor34.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:913) at org.apache.hadoop.net.NetUtils.wrapException(NetUtils.java:862) at org.apache.hadoop.ipc.Client.getRpcResponse(Client.java:1553) at org.apache.hadoop.ipc.Client.call(Client.java:1495) at org.apache.hadoop.ipc.Client.call(Client.java:1392) at org.apache.hadoop.ipc.ProtobufRpcEngine2$Invoker.invoke(ProtobufRpcEngine2.java:242) at org.apache.hadoop.ipc.ProtobufRpcEngine2$Invoker.invoke(ProtobufRpcEngine2.java:129) at com.sun.proxy.$Proxy17.sendHeartbeat(Unknown Source) at org.apache.hadoop.hdfs.protocolPB.DatanodeProtocolClientSideTranslatorPB.sendHeartbeat(DatanodeProtocolClientSideTranslatorPB.java:168) at org.apache.hadoop.hdfs.server.datanode.BPServiceActor.sendHeartBeat(BPServiceActor.java:544) at org.apache.hadoop.hdfs.server.datanode.BPServiceActor.offerService(BPServiceActor.java:682) at org.apache.hadoop.hdfs.server.datanode.BPServiceActor.run(BPServiceActor.java:890) at java.lang.Thread.run(Thread.java:750) Caused by: java.io.EOFException at java.io.DataInputStream.readInt(DataInputStream.java:392) at org.apache.hadoop.ipc.Client$IpcStreams.readResponse(Client.java:1884) at org.apache.hadoop.ipc.Client$Connection.receiveRpcResponse(Client.java:1176) at org.apache.hadoop.ipc.Client$Connection.run(Client.java:1074)
Attaching screenshots of how last heartbeat value looks when the above error is consistently getting logged.
Last heartbeat response time is important to initiate any auto-recovery from datanode. Hence, we should introduce LastHeartbeatResponseTime that only gets updated if the BP service actor thread was successfully able to retrieve response from namenode.
