Details
Description
When client write slow, it will print a slow log from DataStreamer
if (ack.getSeqno() != DFSPacket.HEART_BEAT_SEQNO) { Long begin = packetSendTime.get(ack.getSeqno()); if (begin != null) { long duration = Time.monotonicNow() - begin; if (duration > dfsclientSlowLogThresholdMs) { LOG.info("Slow ReadProcessor read fields for block " + block + " took " + duration + "ms (threshold=" + dfsclientSlowLogThresholdMs + "ms); ack: " + ack + ", targets: " + Arrays.asList(targets)); } } }
here is an example:
Slow ReadProcessor read fields for block BP-XXX:blk_XXX took 2756ms (threshold=100ms); ack: seqno: 3341 status: SUCCESS status: SUCCESS status: SUCCESS downstreamAckTimeNanos: 2751531959 4: "\000\000\000", targets: [XXX, XXX, XXX]
There is an ack seqno in the log, so we can find which packet cause write slow. However, datanode didn't print the seqno in slow log, so we can't kown this packet write slow in which stage.
HDFS-11603 and HDFS-12814 add some slow warnings in BlockReceiver, i think we should add seqno in these slow warnings, in order to find the corresponding packet write slow in which stage.