一、现象
1、flink job log
2022-05-17 02:48:25,688 INFO org.apache.hadoop.hdfs.DataStreamer ? ? ? ? ? ? ? ? ? ? ? ? [] - Slow ReadProcessor read fields for block BP-1487117196-110.246.92.211-1641695608175:blk_1305548153_236768430 took 44369ms (threshold=30000ms); ack: seqno: 2041 reply: SUCCESS reply: SUCCESS reply: SUCCESS downstreamAckTimeNanos: 44349240826 flag: 0 flag: 0 flag: 0, targets: [DatanodeInfoWithStorage[110.246.92.130:9866,DS-3ee15ef0-7de4-49ed-b031-1a2769cd9a97,DISK], DatanodeInfoWithStorage[110.246.92.217:9866,DS-382900d8-67b2-4aa0-8a66-e1ea435aaba4,DISK], DatanodeInfoWithStorage[110.246.92.218:9866,DS-e28bb23b-7a03-498a-b8a2-859382ad300e,DISK]]
2、hadoop datanode log
2022-05-24 01:27:12,269 WARN ?[DataXceiver for client DFSClient_NONMAPREDUCE_-1719586450_1 at /110.246.92.219:60654 [Receiving block BP-1487117196-110.246.92.211-1641695608175:blk_1328326532_260060124]] datanode.DataNode (BlockReceiver.java:manageWriterOsCache(934)) - Slow manageWriterOsCache took 510ms (threshold=300ms), volume=file:/data/hadoop/, blockId=1328326532
二、问题分析及处理
1、在每个DataNode上运行以下命令来收集所有Slow消息的计数
$ egrep -o "Slow.*?(took|cost)" hadoop-root-datanode-datanode-1.out | sort | uniq -c
? ?1105 Slow BlockReceiver write data to disk cost
? ? 330 Slow BlockReceiver write packet to mirror took
? ? 102 Slow flushOrSync took
? ?5031 Slow manageWriterOsCache took
? ? 388 Slow PacketResponder send ack to upstream took
| 现象 | 原因 |
|---|---|
| 集群负载高 | 如果你的集群处于或接近资源上限（内存，cpu或磁盘），则你在处理作业时，你的集群可能无法确保数据本地化，因此需要在网络上传输数据块。如果是这种情况，由于使用集群上的额外负载来传输数据块，因此可能会在作业或数据节点中看到WARN消息。 |
| Slow BlockReceiver write packet to mirror | 这表明在网络上写入块时有延迟 |
| Slow BlockReceiver write data to disk cost | 这表示在将块写入OS缓存或磁盘时存在延迟 |
| Slow flushOrSync | 这表示在将块写入OS缓存或磁盘时存在延迟 |
| Slow manageWriterOsCache | 这表示在将块写入OS缓存或磁盘时存在延迟 |
需要注意的是，在生产环境的正常负载下，一些集群的WARN消息在datanode日志中是正常的。当单个节点具有比正常情况更多的上述WARN消息时，表明存在底层硬件问题。
2、如果单个节点的一个或多个类别的”Slow“消息比其他主机的”Slow“消息数量多出数量级，则需要调查底层硬件问题。
3、如果Slow消息数最多的是Slow BlockReceiver write packet tomirror took，请通过以下命令的输出来调查可能的网络问题：
- ifconfig -a(定期检查问题主机上增加的errors和dropped的数量，往往代表的是网卡，网线或者上游的网络有问题)
- netstat -s（与正常节点相比，查找大量重新传输的数据包或其他异常高的指标）。
- netstat -s | grep -i retrans（整个集群执行）。 （在一个或多个节点上查找大于正常的计数）。
4、如果Slow消息最多的是一些其他消息，请使用以下命令检查磁盘问题：
- iostat[高iowait百分比，超过15%]
- iostat -x和sar -d（特定分区的高await或％util）
- dmesg (磁盘错误)
- 使用smartctl对磁盘进行健康检查：停止受影响节点的所有Hadoop进程，然后运行sudo smartctl -H /dev/<disk>，检查HDFS使用的每块<disk>
三、iostat 用法
iostat [选项] [<时间间隔>] [<次数>]
命令参数：
- -c： 显示CPU使用情况
- -d： 显示磁盘使用情况
- -N： 显示磁盘阵列(LVM) 信息
- -n： 显示NFS 使用情况
- -k： 以 KB 为单位显示
- -m： 以 M 为单位显示
- -t： 报告每秒向终端读取和写入的字符数和CPU的信息
- -V： 显示版本信息
- -x： 显示详细信息
- -p：[磁盘] 显示磁盘和分区的情况
示例1：
显示所有设备负载情况
$ iostat
Linux 4.18.0-305.3.1.el8_4.x86_64 (datanode-1) ?? ?05/27/2022 ?? ?_x86_64_?? ?(56 CPU)avg-cpu: ?%user ? %nice %system %iowait ?%steal ? %idle
? ? ? ? ? ?1.61 ? ?0.00 ? ?0.86 ? ?0.03 ? ?0.00 ? 97.50Device ? ? ? ? ? ? tps ? ?kB_read/s ? ?kB_wrtn/s ? ?kB_read ? ?kB_wrtn
sdc ? ? ? ? ? ? ?10.58 ? ? ? 359.21 ? ? ?1883.53 4304228032 22569192188
sde ? ? ? ? ? ? ?10.71 ? ? ? 378.36 ? ? ?1894.66 4533707080 22702573592
sdf ? ? ? ? ? ? ?10.70 ? ? ? 382.28 ? ? ?1895.95 4580623920 22717997980
sdh ? ? ? ? ? ? ?10.70 ? ? ? 378.91 ? ? ?1903.69 4540288592 22810744428
sdi ? ? ? ? ? ? ?10.66 ? ? ? 358.34 ? ? ?1902.37 4293810648 22794905924
sdg ? ? ? ? ? ? ?10.71 ? ? ? 372.79 ? ? ?1902.01 4466956568 22790663472
sdd ? ? ? ? ? ? ?10.60 ? ? ? 358.42 ? ? ?1891.27 4294701984 22661970536
sda ? ? ? ? ? ? ?11.67 ? ? ? 383.96 ? ? ?1913.88 4600786635 22932900259
sdb ? ? ? ? ? ? ?10.61 ? ? ? 359.89 ? ? ?1887.82 4312299484 22620539680
dm-0 ? ? ? ? ? ? ?0.71 ? ? ? ? 1.13 ? ? ? ? 9.16 ? 13594428 ?109721860
dm-1 ? ? ? ? ? ? ?0.32 ? ? ? ? 0.41 ? ? ? ? 0.88 ? ?4918668 ? 10528140
dm-2 ? ? ? ? ? ? ?4.93 ? ? ? 382.41 ? ? ?1903.85 4582230392 22812647732
cpu属性值说明：
- %user：CPU处在用户模式下的时间百分比。
- %nice：CPU处在带NICE值的用户模式下的时间百分比。
- %system：CPU处在系统模式下的时间百分比。
- %iowait：CPU等待输入输出完成时间的百分比。
- %steal：管理程序维护另一个虚拟处理器时，虚拟CPU的无意识等待时间百分比。
- %idle：CPU空闲时间百分比。
dis磁盘属性值说明：
- device:磁盘名称
- tps:每秒钟发送到的I/O请求数
- Blk_read/s:每秒读取的block数
- Blk_wrtn/s:每秒写入的block数
- Blk_read:读入的block总数
- Blk_wrtn:写入的block总数.
注意：
如果%iowait的值过高，表示硬盘存在I/O瓶颈，%idle值高，表示CPU较空闲，如果%idle值高但系统响应慢时，有可能是CPU等待分配内存，此时应加大内存容量。%idle值如果持续低于10，那么系统的CPU处理能力相对较低，表明系统中最需要解决的资源是CPU。
实例2：
间隔1秒，总共显示5次
iostat 1 5
每隔2秒,显示一次设备统计信息.
iostat -d 2
每隔2秒,显示一次设备统计信息.总共输出3次.
iostat -d 2 3
每隔2秒显示一次sda, sdb两个设备的扩展统计信息,共输出3次.
iostat -x sda sdb 2 3
每隔2秒显示一次sda及上面所有分区的统计信息,共输出3次.
iostat -p sda 2 3
以M为单位显示所有信息
iostat -m
显示指定硬盘信息
iostat -d sda
报告每秒向终端读取和写入的字符数
iostat -t
查看TPS和吞吐量信息
iostat -d -k 1 1
查看设备使用率（%util）、响应时间（await）
iostat -d -x -k 1 1
参数说明：
- rrqm/s: 每秒进行 merge 的读操作数目。即 rmerge/s
- wrqm/s: 每秒进行 merge 的写操作数目。即 wmerge/s
- r/s: 每秒完成的读 I/O 设备次数。即 rio/s
- w/s: 每秒完成的写 I/O 设备次数。即 wio/s
- rkB/s: 每秒读K字节数。是 rsect/s 的一半，因为每扇区大小为512字节。
- wkB/s: 每秒写K字节数。是 wsect/s 的一半。
- avgrq-sz: 平均每次设备I/O操作的数据大小 (扇区)。
- avgqu-sz: 平均I/O队列长度。
- rsec/s: 每秒读扇区数。即 rsect/s
- wsec/s: 每秒写扇区数。即 wsect/s
- r_await:每个读操作平均所需的时间
- 不仅包括硬盘设备读操作的时间，还包括了在kernel队列中等待的时间。
- w_await:每个写操作平均所需的时间
- 不仅包括硬盘设备写操作的时间，还包括了在kernel队列中等待的时间。
- await: 平均每次设备I/O操作的等待时间 (毫秒)。
- svctm: 平均每次设备I/O操作的服务时间 (毫秒)。
- %util: 一秒中有百分之多少的时间用于 I/O 操作，即被io消耗的cpu百分比
注意：
如果 %util 接近 100%，说明产生的I/O请求太多，I/O系统已经满负荷，该磁盘可能存在瓶颈。如果 svctm 比较接近 await，说明 I/O 几乎没有等待时间；如果 await 远大于 svctm，说明I/O 队列太长，io响应太慢，则需要进行必要优化。如果avgqu-sz比较大，也表示有当量io在等待。
查看cpu状态，间隔1秒显示一次，总共显示2次
iostat -c 1 2
