1
2
3
4
5
6
7
作者:李晓辉

联系方式:

1. 微信:Lxh_Chat

2. 邮箱:939958092@qq.com

最近在帮同事排查一台 RHEL 10 的测试机,业务打日志特别慢。第一反应是磁盘坏了,结果跑了一圈排查才发现,是 I/O 等待把 CPU 都堵住了。

我把自己踩坑的排查路径整理下来,专门给新手看的。跟着做一遍,你就能明白 wa 高到底在说啥,慢究竟是盘慢、进程太猛,还是调度器在捣乱。

先看 top:系统是不是在等磁盘

先别管别的,先上 top 看整体状态。

1
2
3
top - 04:35:03 up 3 min, 2 users, load average: 0.04, 0.05, 0.01
%Cpu(s): 2.3 us, 0.2 sy, 0.0 ni, 99.2 id, 95.2 wa, 0.0 hi, 0.0 si, 0.0 st
MiB Mem : 1705.2 total, 1340.4 free, 374.0 used

看懂这一行就好。us 用户态 CPU 才 2.3%,id 空闲 99%,看起来很闲对吧?但 wa 是 95.2%,这个 wa 就是 iowait,CPU 在干等磁盘返回数据。

Linux 的负载平均值里是把磁盘等待也算进去的,所以你会觉得系统很卡但 CPU 不高。这就是典型的存储 I/O 瓶颈信号。

确认是 I/O 问题后,下一步要问:是哪块盘在掉链子?是谁在用?

看设备有没有被打满:iostat

iostat 是 sysstat 工具包里的老朋友,先装上。

1
[root@localhost ~]# dnf install sysstat -y

第一次跑会给你自启动以来的平均值,之后再跑就是按间隔的增量值。

1
[root@localhost ~]# iostat

输出大概长这样,第一部分是 CPU,第二部分是每个设备。

1
2
3
4
5
6
7
8
9
Linux 6.12.0-211.16.1.el10_2.0.1.x86_64 (localhost.localdomain)         10/12/2026      _x86_64_        (4 CPU)

avg-cpu: %user %nice %system %iowait %steal %idle
0.08 0.00 0.45 0.06 0.00 99.41

Device tps kB_read/s kB_wrtn/s kB_dscd/s kB_read kB_wrtn kB_dscd
dm-0 11.52 247.65 120.96 0.00 177255 86574 0
dm-1 0.14 3.11 0.00 0.00 2228 0 0
nvme0n1 11.58 266.18 123.82 0.00 190516 88622 0

更常用的是扩展模式:

1
2
3
4
5
6
7
8
[root@localhost ~]# iostat -xd
Linux 6.12.0-211.16.1.el10_2.0.1.x86_64 (localhost.localdomain) 10/12/2026 _x86_64_ (4 CPU)

Device r/s rkB/s rrqm/s %rrqm r_await rareq-sz w/s wkB/s wrqm/s %wrqm w_await wareq-sz d/s dkB/s drqm/s %drqm d_await dareq-sz f/s f_await aqu-sz %util
dm-0 8.86 232.58 0.00 0.00 0.42 26.24 1.98 113.78 0.00 0.00 2.93 57.39 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.01 2.05
dm-1 0.13 2.92 0.00 0.00 0.11 22.28 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
nvme0n1 9.41 249.98 0.01 0.07 0.33 26.56 1.49 116.47 0.56 27.35 3.56 78.07 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.01 0.30

加了 -x 后能看到 avgqu-sz 平均队列长度、await 平均等待时间、%util 使用率。

这里有两个关键指标要记牢:

  • %util:磁盘忙碌百分比。超过 100% 就说明请求排队排爆了,设备已经处理不过来了。
  • await:从请求发出到完成的平均时间,单位毫秒。几毫秒是正常的,几十毫秒以上就要警惕。

如果 nvme0n1 的 %util 长期 80% 以上,同时 await 很高,那基本就是这块盘的瓶颈。

揪出背后的进程:iotop

盘慢了,下一步就是找凶手。是数据库在写?还是日志刷爆了?

1
[root@localhost ~]# dnf install iotop-c -y

运行一下看看

1
[root@localhost ~]# iotop

界面会实时显示每个进程的磁盘读写的 B/s,还有一个小图形条,看 I/O 是尖峰还是持续。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
  Total DISK READ:    0.00 B/s ⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀ |   Total DISK WRITE:    0.00 B/s ⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀
Current DISK READ: 0.00 B/s ⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀ | Current DISK WRITE: 0.00 B/s ⠀⠀⠀⠀⢸⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀
TID PRIO USER DISK READ DISK WRITE GRAPH[R+W]△ COMMAND [T](15:51:54)
1 be/4 root 0.00 B/s 0.00 B/s ⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀ systemd ▲
2 be/4 root 0.00 B/s 0.00 B/s ⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀ kthreadd █
3 be/4 root 0.00 B/s 0.00 B/s ⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀ pool_workqueue_release █
4 be/0 root 0.00 B/s 0.00 B/s ⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀ kworker/R-rcu_gp █
5 be/0 root 0.00 B/s 0.00 B/s ⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀ kworker/R-sync_wq ▇
6 be/0 root 0.00 B/s 0.00 B/s ⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀ kworker/R-kvfree_rcu_reclaim
7 be/0 root 0.00 B/s 0.00 B/s ⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀ kworker/R-slub_flushwq
8 be/0 root 0.00 B/s 0.00 B/s ⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀ kworker/R-netns
9 be/4 root 0.00 B/s 0.00 B/s ⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀ kworker/0:0-mm_percpu_wq
11 be/0 root 0.00 B/s 0.00 B/s ⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀ kworker/0:0H-events_highpri
12 be/4 root 0.00 B/s 0.00 B/s ⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀ kworker/u512:0-events_unbound
13 be/4 root 0.00 B/s 0.00 B/s ⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀ kworker/u512:1-ipv6_addrconf
14 be/0 root 0.00 B/s 0.00 B/s ⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀ kworker/R-mm_percpu_wq
15 be/4 root 0.00 B/s 0.00 B/s ⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀ ksoftirqd/0
16 be/4 root 0.00 B/s 0.00 B/s ⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀ rcu_preempt
17 be/4 root 0.00 B/s 0.00 B/s ⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀ rcu_exp_par_gp_kthread_worker/1
18 be/4 root 0.00 B/s 0.00 B/s ⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀ rcu_exp_gp_kthread_worker
19 rt/4 root 0.00 B/s 0.00 B/s ⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀ migration/0
20 rt/4 root 0.00 B/s 0.00 B/s ⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀ idle_inject/0
21 be/4 root 0.00 B/s 0.00 B/s ⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀ cpuhp/0
22 be/4 root 0.00 B/s 0.00 B/s ⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀⠀ cpuhp/1

我之前那台机器就是在这里看到 rsyslogd 有两个线程一直写,每秒好几 KB,看起来不多,但就是持续不断,把 IOPS 耗完了。

iotop 几个好用的参数:

  • -o 只显示当前正在做 I/O 的进程,省得刷屏
  • -P 只看进程不看线程
  • -a 显示累计总量,适合找长期大户

读写的数字能帮你判断是写满了还是读满了。很多新手只看带宽,其实小文件的随机读写更吃 IOPS。

往更深挖:blktrace 看块层延迟

前面两步是宏观层面,如果想知道延迟到底卡在内核还是硬件上,就得用 blktrace 这套组合拳。

它一共三步:

  1. blktrace 抓包,输出二进制
  2. blkparse 转成人类可读文本
  3. btt 做聚合统计

这个工具需要安装

1
[root@localhost ~]# dnf install blktrace -y

实操:

1
2
3
4
5
6
7
[root@localhost ~]# blktrace -d /dev/nvme0n1 -o trace.bin
^C=== nvme0n1 ===
CPU 0: 20 events, 1 KiB data
CPU 1: 0 events, 0 KiB data
CPU 2: 106 events, 5 KiB data
CPU 3: 36 events, 2 KiB data
Total: 162 events (dropped 0), 8 KiB data

blktrace -d /dev/nvme0n1 -o trace.bin 的意思是:追踪 /dev/nvme0n1 这块盘的所有块 I/O 事件,并把结果写到 trace.bin 这个前缀下。

它默认是持续采集的,不会自己停。你按 Ctrl+C 才结束,采集时间就是你让它跑的时间。跑得越久,文件越大,也越能抓到偶发慢 I/O。

运行完后不会只生成一个 trace.bin。它会按 CPU 核心生成多个二进制文件,比如:

1
2
[root@localhost ~]# ls
anaconda-ks.cfg trace.bin.blktrace.0 trace.bin.blktrace.1 trace.bin.blktrace.2 trace.bin.blktrace.3

这些文件是二进制的,人直接看不了。后面要用 blkparse 转成文本,再用 btt 做统计。典型流程是:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
[root@localhost ~]blkparse -i  trace.bin
Input file trace.bin.blktrace.0 added
Input file trace.bin.blktrace.2 added
Input file trace.bin.blktrace.3 added
259,0 0 1 0.000000000 9 A WSM 514095524 + 12 <- (253,0) 514093476
259,0 0 2 0.000000081 9 A WSM 518293924 + 12 <- (259,3) 514095524
259,0 0 3 0.000000176 9 Q WSM 518293924 + 12 [kworker/0:0]
259,0 0 4 0.000004776 9 G WSM 518293924 + 12 [kworker/0:0]
259,0 0 5 0.000011665 9 P N [kworker/0:0]
259,0 0 6 0.000011981 9 U N [kworker/0:0] 1
259,0 0 7 0.000015525 9 D WSM 518293924 + 12 [kworker/0:0]
259,0 3 1 0.000089445 767 A WM 2049 + 1 <- (253,0) 1
259,0 3 2 0.000089512 767 A WM 4200449 + 1 <- (259,3) 2049
259,0 3 3 0.000089590 767 Q WM 4200449 + 1 [xfsaild/dm-0]
259,0 3 4 0.000092739 767 G WM 4200449 + 1 [xfsaild/dm-0]
259,0 3 5 0.000093534 767 P N [xfsaild/dm-0]
259,0 3 6 0.000096889 767 A WM 2056 + 8 <- (253,0) 8
259,0 3 7 0.000096942 767 A WM 4200456 + 8 <- (259,3) 2056
259,0 3 8 0.000096998 767 Q WM 4200456 + 8 [xfsaild/dm-0]
259,0 3 9 0.000097361 767 G WM 4200456 + 8 [xfsaild/dm-0]
259,0 3 10 0.000099940 767 A WM 2064 + 8 <- (253,0) 16
259,0 3 11 0.000099995 767 A WM 4200464 + 8 <- (259,3) 2064
259,0 3 12 0.000100041 767 Q WM 4200464 + 8 [xfsaild/dm-0]
259,0 3 13 0.000100851 767 M WM 4200464 + 8 [xfsaild/dm-0]
259,0 3 14 0.000102074 767 A WM 329792 + 32 <- (253,0) 327744
259,0 3 15 0.000102117 767 A WM 4528192 + 32 <- (259,3) 329792
259,0 3 16 0.000102162 767 Q WM 4528192 + 32 [xfsaild/dm-0]
259,0 3 17 0.000102368 767 G WM 4528192 + 32 [xfsaild/dm-0]
259,0 3 18 0.000105302 767 A WM 362512 + 8 <- (253,0) 360464
259,0 3 19 0.000105345 767 A WM 4560912 + 8 <- (259,3) 362512
259,0 3 20 0.000105390 767 Q WM 4560912 + 8 [xfsaild/dm-0]
259,0 3 21 0.000105561 767 G WM 4560912 + 8 [xfsaild/dm-0]
259,0 3 22 0.000105804 767 U N [xfsaild/dm-0] 4
259,0 3 23 0.000106997 767 D WM 4200449 + 1 [xfsaild/dm-0]
259,0 3 24 0.000110025 767 D WM 4200456 + 16 [xfsaild/dm-0]
259,0 3 25 0.000111200 767 D WM 4528192 + 32 [xfsaild/dm-0]
259,0 3 26 0.000111508 767 D WM 4560912 + 8 [xfsaild/dm-0]
259,0 0 8 0.000240576 0 C WSM 518293924 + 12 [0]
259,0 3 27 0.000260146 0 C WM 4200449 + 1 [0]
259,0 3 28 0.000265646 0 C WM 4200456 + 16 [0]
259,0 3 29 0.000266437 0 C WM 4528192 + 32 [0]
259,0 3 30 0.000266737 0 C WM 4560912 + 8 [0]
259,0 2 1 30.207728303 767 A WM 203296 + 32 <- (253,0) 201248
259,0 2 2 30.207728356 767 A WM 4401696 + 32 <- (259,3) 203296
259,0 2 3 30.207728443 767 Q WM 4401696 + 32 [xfsaild/dm-0]
259,0 2 4 30.207733615 767 G WM 4401696 + 32 [xfsaild/dm-0]
259,0 2 5 30.207741090 767 P N [xfsaild/dm-0]
259,0 2 6 30.207743252 767 A WM 513964033 + 1 <- (253,0) 513961985
259,0 2 7 30.207743303 767 A WM 518162433 + 1 <- (259,3) 513964033
259,0 2 8 30.207743365 767 Q WM 518162433 + 1 [xfsaild/dm-0]
259,0 2 9 30.207743896 767 G WM 518162433 + 1 [xfsaild/dm-0]
259,0 2 10 30.207745489 767 A WM 513964034 + 1 <- (253,0) 513961986
259,0 2 11 30.207745530 767 A WM 518162434 + 1 <- (259,3) 513964034
259,0 2 12 30.207745578 767 Q WM 518162434 + 1 [xfsaild/dm-0]
259,0 2 13 30.207746117 767 G WM 518162434 + 1 [xfsaild/dm-0]
259,0 2 14 30.207749891 767 A WM 513964040 + 8 <- (253,0) 513961992
259,0 2 15 30.207749931 767 A WM 518162440 + 8 <- (259,3) 513964040
259,0 2 16 30.207749979 767 Q WM 518162440 + 8 [xfsaild/dm-0]
259,0 2 17 30.207750166 767 G WM 518162440 + 8 [xfsaild/dm-0]
259,0 2 18 30.207752832 767 A WM 513964048 + 8 <- (253,0) 513962000
259,0 2 19 30.207752874 767 A WM 518162448 + 8 <- (259,3) 513964048
259,0 2 20 30.207752918 767 Q WM 518162448 + 8 [xfsaild/dm-0]
259,0 2 21 30.207753380 767 M WM 518162448 + 8 [xfsaild/dm-0]
259,0 2 22 30.207756694 767 A WM 513964056 + 8 <- (253,0) 513962008
259,0 2 23 30.207756735 767 A WM 518162456 + 8 <- (259,3) 513964056
259,0 2 24 30.207756780 767 Q WM 518162456 + 8 [xfsaild/dm-0]
259,0 2 25 30.207756894 767 M WM 518162456 + 8 [xfsaild/dm-0]
259,0 2 26 30.207759344 767 A WM 513964064 + 8 <- (253,0) 513962016
259,0 2 27 30.207759386 767 A WM 518162464 + 8 <- (259,3) 513964064
259,0 2 28 30.207759429 767 Q WM 518162464 + 8 [xfsaild/dm-0]
259,0 2 29 30.207759532 767 M WM 518162464 + 8 [xfsaild/dm-0]
259,0 2 30 30.207760366 767 A WM 514466048 + 32 <- (253,0) 514464000
259,0 2 31 30.207760406 767 A WM 518664448 + 32 <- (259,3) 514466048
259,0 2 32 30.207760449 767 Q WM 518664448 + 32 [xfsaild/dm-0]
259,0 2 33 30.207760629 767 G WM 518664448 + 32 [xfsaild/dm-0]
259,0 2 34 30.207761365 767 A WM 514632256 + 32 <- (253,0) 514630208
259,0 2 35 30.207761408 767 A WM 518830656 + 32 <- (259,3) 514632256
259,0 2 36 30.207761452 767 Q WM 518830656 + 32 [xfsaild/dm-0]
259,0 2 37 30.207761617 767 G WM 518830656 + 32 [xfsaild/dm-0]
259,0 2 38 30.207762587 767 A WM 514658336 + 32 <- (253,0) 514656288
259,0 2 39 30.207762631 767 A WM 518856736 + 32 <- (259,3) 514658336
259,0 2 40 30.207762676 767 Q WM 518856736 + 32 [xfsaild/dm-0]
259,0 2 41 30.207762842 767 G WM 518856736 + 32 [xfsaild/dm-0]
259,0 2 42 30.207767937 767 A WM 514664616 + 8 <- (253,0) 514662568
259,0 2 43 30.207767980 767 A WM 518863016 + 8 <- (259,3) 514664616
259,0 2 44 30.207768025 767 Q WM 518863016 + 8 [xfsaild/dm-0]
259,0 2 45 30.207768203 767 G WM 518863016 + 8 [xfsaild/dm-0]
259,0 2 46 30.207770909 767 A WM 581700016 + 8 <- (253,0) 581697968
259,0 2 47 30.207770951 767 A WM 585898416 + 8 <- (259,3) 581700016
259,0 2 48 30.207770997 767 Q WM 585898416 + 8 [xfsaild/dm-0]
259,0 2 49 30.207771247 767 G WM 585898416 + 8 [xfsaild/dm-0]
259,0 2 50 30.207771738 767 U N [xfsaild/dm-0] 9
259,0 2 51 30.207776985 767 D WM 4401696 + 32 [xfsaild/dm-0]
259,0 2 52 30.207777690 767 D WM 518162433 + 1 [xfsaild/dm-0]
259,0 2 53 30.207778128 767 D WM 518162434 + 1 [xfsaild/dm-0]
259,0 2 54 30.207778818 767 D WM 518162440 + 32 [xfsaild/dm-0]
259,0 2 55 30.207779216 767 D WM 518664448 + 32 [xfsaild/dm-0]
259,0 2 56 30.207779513 767 D WM 518830656 + 32 [xfsaild/dm-0]
259,0 2 57 30.207779887 767 D WM 518856736 + 32 [xfsaild/dm-0]
259,0 2 58 30.207780056 767 D WM 518863016 + 8 [xfsaild/dm-0]
259,0 2 59 30.207780332 767 D WM 585898416 + 8 [xfsaild/dm-0]
259,0 2 60 30.208020512 0 C WM 4401696 + 32 [0]
259,0 2 61 30.208026629 0 C WM 518162433 + 1 [0]
259,0 2 62 30.208026975 0 C WM 518162434 + 1 [0]
259,0 2 63 30.208027353 0 C WM 518162440 + 32 [0]
259,0 2 64 30.208027996 0 C WM 518664448 + 32 [0]
259,0 2 65 30.208028411 0 C WM 518830656 + 32 [0]
259,0 2 66 30.208028679 0 C WM 518856736 + 32 [0]
259,0 2 67 30.208028830 0 C WM 518863016 + 8 [0]
259,0 2 68 30.208029092 0 C WM 585898416 + 8 [0]
259,0 0 9 60.416006565 9 A WSM 514095536 + 2 <- (253,0) 514093488
259,0 0 10 60.416006610 9 A WSM 518293936 + 2 <- (259,3) 514095536
259,0 0 11 60.416006697 9 Q WSM 518293936 + 2 [kworker/0:0]
259,0 0 12 60.416011264 9 G WSM 518293936 + 2 [kworker/0:0]
259,0 0 13 60.416018641 9 P N [kworker/0:0]
259,0 0 14 60.416019034 9 U N [kworker/0:0] 1
259,0 0 15 60.416022489 9 D WSM 518293936 + 2 [kworker/0:0]
259,0 0 16 60.416162706 0 C WSM 518293936 + 2 [0]
259,0 2 69 60.416277291 767 A WM 2048 + 1 <- (253,0) 0
259,0 2 70 60.416277346 767 A WM 4200448 + 1 <- (259,3) 2048
259,0 2 71 60.416277417 767 Q WM 4200448 + 1 [xfsaild/dm-0]
259,0 2 72 60.416280566 767 G WM 4200448 + 1 [xfsaild/dm-0]
259,0 2 73 60.416280737 767 P N [xfsaild/dm-0]
259,0 2 74 60.416280934 767 U N [xfsaild/dm-0] 1
259,0 2 75 60.416282166 767 D WM 4200448 + 1 [xfsaild/dm-0]
259,0 2 76 60.416448856 0 C WM 4200448 + 1 [0]
259,0 2 77 90.623740042 1109 A WSM 514095538 + 2 <- (253,0) 514093490
259,0 2 78 90.623740118 1109 A WSM 518293938 + 2 <- (259,3) 514095538
259,0 2 79 90.623740219 1109 Q WSM 518293938 + 2 [kworker/2:2]
259,0 2 80 90.623745325 1109 G WSM 518293938 + 2 [kworker/2:2]
259,0 2 81 90.623752208 1109 P N [kworker/2:2]
259,0 2 82 90.623752583 1109 U N [kworker/2:2] 1
259,0 2 83 90.623756384 1109 D WSM 518293938 + 2 [kworker/2:2]
259,0 2 84 90.623912009 0 C WSM 518293938 + 2 [0]
259,0 2 85 90.623945239 767 A WM 2048 + 1 <- (253,0) 0
259,0 2 86 90.623945404 767 A WM 4200448 + 1 <- (259,3) 2048
259,0 2 87 90.623945483 767 Q WM 4200448 + 1 [xfsaild/dm-0]
259,0 2 88 90.623947028 767 G WM 4200448 + 1 [xfsaild/dm-0]
259,0 2 89 90.623947423 767 P N [xfsaild/dm-0]
259,0 2 90 90.623947586 767 U N [xfsaild/dm-0] 1
259,0 2 91 90.623948644 767 D WM 4200448 + 1 [xfsaild/dm-0]
259,0 2 92 90.624039052 0 C WM 4200448 + 1 [0]
CPU0 (trace.bin):
Reads Queued: 0, 0KiB Writes Queued: 2, 7KiB
Read Dispatches: 0, 0KiB Write Dispatches: 2, 7KiB
Reads Requeued: 0 Writes Requeued: 0
Reads Completed: 0, 0KiB Writes Completed: 2, 7KiB
Read Merges: 0, 0KiB Write Merges: 0, 0KiB
Read depth: 0 Write depth: 9
IO unplugs: 2 Timer unplugs: 0
CPU2 (trace.bin):
Reads Queued: 0, 0KiB Writes Queued: 15, 91KiB
Read Dispatches: 0, 0KiB Write Dispatches: 12, 91KiB
Reads Requeued: 0 Writes Requeued: 0
Reads Completed: 0, 0KiB Writes Completed: 12, 91KiB
Read Merges: 0, 0KiB Write Merges: 3, 12KiB
Read depth: 0 Write depth: 9
IO unplugs: 4 Timer unplugs: 0
CPU3 (trace.bin):
Reads Queued: 0, 0KiB Writes Queued: 5, 28KiB
Read Dispatches: 0, 0KiB Write Dispatches: 4, 28KiB
Reads Requeued: 0 Writes Requeued: 0
Reads Completed: 0, 0KiB Writes Completed: 4, 28KiB
Read Merges: 0, 0KiB Write Merges: 1, 4KiB
Read depth: 0 Write depth: 9
IO unplugs: 1 Timer unplugs: 0

Total (trace.bin):
Reads Queued: 0, 0KiB Writes Queued: 22, 126KiB
Read Dispatches: 0, 0KiB Write Dispatches: 18, 126KiB
Reads Requeued: 0 Writes Requeued: 0
Reads Completed: 0, 0KiB Writes Completed: 18, 126KiB
Read Merges: 0, 0KiB Write Merges: 4, 16KiB
IO unplugs: 7 Timer unplugs: 0

Throughput (R/W): 0KiB/s / 1KiB/s
Events (trace.bin): 138 entries
Skips: 0 forward (0 - 0.0%)
Trace started at Mon Oct 12 15:55:45 2026

简单拆解:设备号、CPU、序列号、时间戳、PID、操作类型 Q 排队/D 分派/C 完成、读写类型、块号、进程名。

用 btt 做统计

btt 可以帮助我们分析块 I/O 在不同阶段花费的时间:

  • Q2C:从请求进入队列到请求完成的总时间。
  • Q2D:从进入队列到分派的时间,可用于观察请求在分派前经历的等待。
  • D2C:从请求分派到完成的时间,可用于观察分派后的处理耗时。

如果 Q2D 明显增大,可以继续检查块层排队、请求合并、设备队列以及 I/O 调度等因素;如果 D2C 明显增大,则需要进一步检查设备驱动、底层存储延迟和设备内部排队等因素。

这些指标用于缩小排查范围,并不能单独证明故障一定来自内核调度器或物理硬盘。

先合并一下前面的4个文件

1
2
3
4
5
6
7
8
9
10
11
12
13
14
[root@localhost ~]# blkparse -i trace.bin -d trace-merged.bin
[root@localhost ~]# ll -h
total 48K
-rw-r--r--. 1 root root 14 Oct 12 16:01 259,0_iops_fp.dat
-rw-r--r--. 1 root root 28 Oct 12 16:01 259,0_mbps_fp.dat
-rw-------. 1 root root 988 Sep 24 18:11 anaconda-ks.cfg
-rw-r--r--. 1 root root 424 Oct 12 16:03 result_monitor.bin
-rw-r--r--. 1 root root 14 Oct 12 16:01 sys_iops_fp.dat
-rw-r--r--. 1 root root 28 Oct 12 16:01 sys_mbps_fp.dat
-rw-r--r--. 1 root root 976 Oct 12 15:57 trace.bin.blktrace.0
-rw-r--r--. 1 root root 0 Oct 12 15:57 trace.bin.blktrace.1
-rw-r--r--. 1 root root 5.0K Oct 12 15:57 trace.bin.blktrace.2
-rw-r--r--. 1 root root 1.7K Oct 12 15:57 trace.bin.blktrace.3
-rw-r--r--. 1 root root 7.7K Oct 12 16:14 trace-merged.bin

分析合并后的跟踪数据

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
[root@localhost ~]# btt -i trace-merged.bin
==================== All Devices ====================

ALL MIN AVG MAX N
--------------- ------------- ------------- ------------- -----------

Q2Q 0.000001003 4.315425967 30.208235700 21
Q2G 0.000000165 0.000001679 0.000005172 18
Q2M 0.000000103 0.000000372 0.000000810 4
M2D 0.000009174 0.000018955 0.000025438 4
D2C 0.000090408 0.000206014 0.000248939 22
Q2C 0.000093569 0.000224095 0.000292069 22

==================== Device Overhead ====================

DEV | Q2G G2I Q2M I2D D2C
---------- | --------- --------- --------- --------- ---------
(259, 0) | 0.6131% 0.0000% 0.0302% 0.0000% 91.9316%
---------- | --------- --------- --------- --------- ---------
Overall | 0.6131% 0.0000% 0.0302% 0.0000% 91.9316%

==================== Device Merge Information ====================

DEV | #Q #D Ratio | BLKmin BLKavg BLKmax Total
---------- | -------- -------- ------- | -------- -------- -------- --------
(259, 0) | 22 18 1.2 | 1 14 32 253

==================== Device Q2Q Seek Information ====================

DEV | NSEEKS MEAN MEDIAN | MODE
---------- | --------------- --------------- --------------- | ---------------
(259, 0) | 22 146558569.4 0 | 0(5)
---------- | --------------- --------------- --------------- | ---------------
Overall | NSEEKS MEAN MEDIAN | MODE
Average | 22 146558569.4 0 | 0(5)

==================== Device D2D Seek Information ====================

DEV | NSEEKS MEAN MEDIAN | MODE
---------- | --------------- --------------- --------------- | ---------------
(259, 0) | 18 179127140.3 0 | 0(1)
...(17 more)
---------- | --------------- --------------- --------------- | ---------------
Overall | NSEEKS MEAN MEDIAN | MODE
Average | 18 179127140.3 0 | 0(1)
...(17 more)


==================== Plug Information ====================

DEV | # Plugs # Timer Us | % Time Q Plugged
---------- | ---------- ---------- | ----------------
(259, 0) | 7( 0) | 0.000048952%

DEV | IOs/Unp IOs/Unp(to)
---------- | ---------- ----------
(259, 0) | 2.6 0.0
---------- | ---------- ----------
Overall | IOs/Unp IOs/Unp(to)
Average | 2.6 0.0

==================== Active Requests At Q Information ====================

DEV | Avg Reqs @ Q
---------- | -------------
(259, 0) | 2.5

==================== I/O Active Period Information ====================

DEV | # Live Avg. Act Avg. !Act % Live
---------- | ---------- ------------- ------------- ------
(259, 0) | 6 0.000176043 18.124596559 0.00
---------- | ---------- ------------- ------------- ------
Total Sys | 6 0.000176043 18.124596559 0.00

# Total System
# Total System : q activity
0.000000176 0.0
0.000000176 0.4
0.000105390 0.4
0.000105390 0.0
30.207728443 0.0
30.207728443 0.4
30.207770997 0.4
30.207770997 0.0
60.416006697 0.0
60.416006697 0.4
60.416277417 0.4
60.416277417 0.0
90.623740219 0.0
90.623740219 0.4
90.623945483 0.4
90.623945483 0.0

# Total System : c activity
0.000240576 0.5
0.000240576 0.9
0.000266737 0.9
0.000266737 0.5
30.208020512 0.5
30.208020512 0.9
30.208029092 0.9
30.208029092 0.5
60.416162706 0.5
60.416162706 0.9
60.416448856 0.9
60.416448856 0.5
90.623912009 0.5
90.623912009 0.9
90.624039052 0.9
90.624039052 0.5

# Per process
# kernel : q activity

# kernel : c activity
0.000240576 1.5
0.000240576 1.9
0.000266737 1.9
0.000266737 1.5
30.208020512 1.5
30.208020512 1.9
30.208029092 1.9
30.208029092 1.5
60.416162706 1.5
60.416162706 1.9
60.416448856 1.9
60.416448856 1.5
90.623912009 1.5
90.623912009 1.9
90.624039052 1.9
90.624039052 1.5

# kworker : q activity
0.000000176 2.0
0.000000176 2.4
0.000000176 2.4
0.000000176 2.0
60.416006697 2.0
60.416006697 2.4
60.416006697 2.4
60.416006697 2.0
90.623740219 2.0
90.623740219 2.4
90.623740219 2.4
90.623740219 2.0

# kworker : c activity

# xfsaild : q activity
0.000089590 3.0
0.000089590 3.4
0.000105390 3.4
0.000105390 3.0
30.207728443 3.0
30.207728443 3.4
30.207770997 3.4
30.207770997 3.0
60.416277417 3.0
60.416277417 3.4
60.416277417 3.4
60.416277417 3.0
90.623945483 3.0
90.623945483 3.4
90.623945483 3.4
90.623945483 3.0

# xfsaild : c activity

另外还有 blkiomon,可以实时画延迟和请求大小直方图:

1
blktrace -d /dev/nvme0n1 -o - | blkiomon -I 10 -b result_monitor.bin

-I 10 表示每 10 秒统计一次,适合长时间观察 I/O 模式。

全景视角:Performance Co-Pilot

sysstat 好用但信息分散。PCP 更像一个性能仪表盘,能把 CPU 内存磁盘网络一起看。

先启动服务:

1
2
3
4
[root@localhost ~]# dnf install pcp-system-tools -y

[root@localhost ~]# systemctl enable pmcd --now

最常用的两个命令:

pcp atop -d:磁盘版的 atop,会列出每个设备的 busy、读写量、avio 平均 I/O 时间,同时列出每个进程累计的读写量。能区分总 I/O 和实际物理 I/O,差值基本就是文件系统缓存干的。

1
[root@localhost ~]# pcp atop -d

看看输出

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
ATOP - localhost                             2026/10/12  16:05:07                             -----------------                             28m5s elapsed
PRC | sys 0.03s | user 0.02s | #proc 268 | #trun 1 | #tslpi 136 | #tslpu 0 | #tidle 131 | #zombie 0 | #exit 54 |
CPU | sys 1% | user 0% | irq 0% | idle 399% | wait 0% | steal 0% | guest 0% | | curf 2.30GHz |
cpu | sys 0% | user 0% | irq 0% | idle 100% | cpu002 w 0% | steal 0% | guest 0% | | |
cpu | sys 0% | user 0% | irq 0% | idle 100% | cpu003 w 0% | steal 0% | guest 0% | | |
cpu | sys 0% | user 0% | irq 0% | idle 100% | cpu000 w 0% | steal 0% | guest 0% | | |
cpu | sys 0% | user 0% | irq 0% | idle 100% | cpu001 w 0% | steal 0% | guest 0% | | |
CPL | numcpu 4 | | avg1 0.14 | avg5 0.07 | avg15 0.02 | | | csw 2214 | intr 2461 |
MEM | tot 7.7G | free 7.0G | avail 28.4G | cache 329.1M | dirty 0.0M | buff 4.1M | slab 138.8M | slrec 42.7M | |
MEM | numnode 1 | shmem 9.4M | shrss 0.0M | shswp 0.0M | tcpsk 0.5M | udpsk 0.0M | pgtab 0.7M | anthp 24.0M | zfarc 0.0M |
SWP | tot 7.8G | free 7.8G | swcac 0.0M | zswap 0.0M | zstor 0.0M | ksuse 0.0M | kssav 0.0M | vmcom 202.9M | vmlim 11.7G |
PAG | scan 0 | steal 0 | stall 0 | compact 0 | numamig 0 | migrate 0 | pgin 0 | pgout 36 | oomkill 0 |
LVM | rlm-root | busy 0% | read 0 | write 9 | discrd 0 | KiB/w 4 | MBr/s 0.0 | MBw/s 0.0 | avio 0.0 ns |
DSK | nvme0n1 | busy 0% | read 0 | write 9 | discrd 0 | KiB/w 4 | MBr/s 0.0 | MBw/s 0.0 | avio 0.0 ns |
NET | transport | tcpi 48 | tcpo 96 | udpi 0 | udpo 0 | tcpao 0 | tcppo 0 | tcprs 0 | udpie 0 |
NET | network | ipi 48 | ipo 96 | ipfrw 0 | deliv 48 | | | icmpi 0 | icmpo 0 |
NET | ens160 0% | pcki 48 | pcko 96 | sp 10 Gbps | si 0 Kbps | so 0 Kbps | erri 0 | erro 0 | drpo 0 |

PID TID RDDSK WRDSK WCANCL DSK CMD 1/7
1215 - 0B 0B 0.0K 0% bash
8431 - 0B 0B 0.0K 0% pmdaproc
767 - 0B 0B 0.0K 0% xfsaild/dm-0
7537 - 0B 0B 0.0K 0% kworker/2:3-ev
1 - 0B 0B 0.0K 0% systemd
1010 - 0B 0B 0.0K 0% NetworkManager
840 - 0B 0B 0.0K 0% systemd-journa
8652 - 0B 0B 0.0K 0% pcp-atop
1136 - 0B 0B 0.0K 0% sshd-session
8426 - 0B 0B 0.0K 0% pmcd
8285 - 0B 0B 0.0K 0% systemd-userwo
8620 - 0B 0B 0.0K 0% systemd-userwo
8566 - 0B 0B 0.0K 0% systemd-userwo
1063 - 0B 0B 0.0K 0% rsyslogd
8433 - 0B 0B 0.0K 0% pmdalinux

pmiostat:PCP 的 iostat。默认看 SCSI 设备,想细化可以用:

1
2
3
pmiostat -R nvme0n1          # 只看 nvme0n1
pmiostat -x noidle # 只显示有活动的盘,去掉空闲的
pmiostat -x dm # 看设备映射器逻辑卷
1
2
3
4
5
6
7
8
9
10
11
12
13
[root@localhost ~]# pmiostat -R nvme0n1
# Device rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await %util
nvme0n1 0.00 0.00 0.00 0.00 0.00 0.00 0.000 0.000 0.00 0.00 0.00 0.00
nvme0n1 0.00 0.00 0.00 0.00 0.00 0.00 0.000 0.000 0.00 0.00 0.00 0.00
nvme0n1 0.00 0.00 0.00 0.00 0.00 0.00 0.000 0.000 0.00 0.00 0.00 0.00
nvme0n1 0.00 0.00 0.00 0.00 0.00 0.00 0.000 0.000 0.00 0.00 0.00 0.00
nvme0n1 0.00 0.00 0.00 0.00 0.00 0.00 0.000 0.000 0.00 0.00 0.00 0.00
nvme0n1 0.00 0.00 0.00 0.00 0.00 0.00 0.000 0.000 0.00 0.00 0.00 0.00
nvme0n1 0.00 0.00 0.00 0.00 0.00 0.00 0.000 0.000 0.00 0.00 0.00 0.00
nvme0n1 0.00 0.00 0.00 0.00 0.00 0.00 0.000 0.000 0.00 0.00 0.00 0.00
nvme0n1 0.00 0.00 0.00 0.00 0.00 0.00 0.000 0.000 0.00 0.00 0.00 0.00
nvme0n1 0.00 0.00 0.00 0.00 0.00 0.00 0.000 0.000 0.00 0.00 0.00 0.00
nvme0n1 0.00 0.00 0.00 0.00 0.00 0.00 0.000 0.000 0.00 0.00 0.00 0.00

这样一套下来,你既能看到设备实时指标,又能追溯到进程。

怎么串起来用?

我现在排查的流程基本是这样:

  1. top 看 wa 确认是不是在等磁盘
  2. iostat -xd 1 看哪块盘 %util 高、await 大
  3. iotop -o 看是哪个进程在猛写猛读
  4. blktrace + btt 确认延迟是排队问题还是硬件问题
  5. pcp atop -d 做一次全景复核,确认没有其他资源被拖累

把这几步跑通,基本 90% 的存储慢问题你都能定位到根因。很多时候不是磁盘坏了,而是日志没归档、备份在跑、或者调度器选错了。