我的基本假设是,当进程的唯一限制因素是磁盘和 CPU 时,系统总“iowait”+ CPU 使用率应至少等于一个逻辑 CPU 的 100%。(在其他情况下,这将不成立。例如,当使用 下载文件时wget
,网络通常是限制因素)。
一个简单的测试违反了这个假设。这是预期的吗?如果预计,有一组,我的条件应该期待我的假设是成立的?
这里有一些关于“iowait”的背景:CPU 如何知道有 IO 挂起? 这里的答案引用了一个违反直觉的想法,即累积 iowait“在某些情况下可能会减少”。我想知道我的简单测试是否会触发这种未记录的情况?
更新:请跳到答案。
答案的测试比我最初使用的测试更简单。我保留了下面的原始问题。原始问题可能会显示一些其他详细信息。
在一个简短的测试中,我使用dd
请求内核生成随机字节,并将它们写入文件。我在dd
里面运行命令perf stat
,只是为了计算在内核中花费的 CPU 时间。我也在里面运行它perf trace -s
,报告里面花费的时间write()
。同时,我vmstat 5
在另一个终端运行,看到系统“iowait”。
详细结果和测试环境如下所示。还显示了一个替代测试,我的假设确实成立。注意:必须在perf stat
内部运行perf trace
,而不是相反。这在这里有详细说明:在运行“perf trace - s”时,“perf stat”(和“time”!)是否显示不正确的结果?
以下是来自
sar
联机帮助页的定义:%io等待:
在系统有未完成的磁盘 I/O 请求期间 CPU 或多个 CPU 空闲的时间百分比。
因此,%iowait 意味着从 CPU 的角度来看,没有任务可运行,但至少有一个 I/O 正在进行。iowait 只是一种空闲时间形式,此时无法安排任何事情。该值在指示性能问题时可能有用也可能没有用,但它确实告诉用户系统处于空闲状态并且本可以进行更多工作。
https://support.hpe.com/hpsc/doc/public/display?docId=c02783994
还有一篇更长的文章:Understanding I/O Wait (or why 0% Idle can be OK)。这解释了如何从内核代码中清楚地看到定义。代码略有改动,但思路还是很清晰的:
/*
* Account for idle time.
* @cputime: the CPU time spent in idle wait
*/
void account_idle_time(u64 cputime)
{
u64 *cpustat = kcpustat_this_cpu->cpustat;
struct rq *rq = this_rq();
if (atomic_read(&rq->nr_iowait) > 0)
cpustat[CPUTIME_IOWAIT] += cputime;
else
cpustat[CPUTIME_IDLE] += cputime;
}
Run Code Online (Sandbox Code Playgroud)
文章还展示了一些在单 CPU 系统上的相关实验。一些实验中甚至使用dd
带有if=/dev/urandom
!但是实验不包括我的测试dd if=/dev/urandom of=test.out
。它只使用dd if=/dev/urandom of=/dev/null
.
“IO 等待”现在考虑起来有点棘手,因为我们使用多 CPU 系统,但我想我仍然理解它,基于引用的代码。
我有四个逻辑 CPU。
我使用 LVM 和 ext4 文件系统。我没有在我的磁盘或文件系统上使用任何加密。我根本没有安装任何网络文件系统,所以我没有读或写网络文件系统。
下面的结果来自 kernel 4.20.15-200.fc29.x86_64
,使用noop
IO 调度程序。该cfq
IO调度也给出了类似的结果。
(我还在基于类似配置的内核构建中看到了类似的结果,但更接近内核版本 5.1,并且使用mq-deadline
. 所以这是使用新blk-mq
代码)。
$ sudo perf trace -s \
perf stat \
dd if=/dev/urandom of=test.out bs=1M oflag=direct count=3000
3000+0 records in
3000+0 records out
3145728000 bytes (3.1 GB, 2.9 GiB) copied, 31.397 s, 100 MB/s
Performance counter stats for 'dd if=/dev/urandom of=test.out bs=1M oflag=direct count=3000':
18,014.26 msec task-clock # 0.574 CPUs utilized
3,199 context-switches # 0.178 K/sec
4 cpu-migrations # 0.000 K/sec
328 page-faults # 0.018 K/sec
45,232,163,658 cycles # 2.511 GHz
74,538,278,379 instructions # 1.65 insn per cycle
4,372,725,344 branches # 242.737 M/sec
4,650,429 branch-misses # 0.11% of all branches
31.398466725 seconds time elapsed
0.006966000 seconds user
17.910332000 seconds sys
Summary of events:
...
dd (4620), 12156 events, 12.0%
syscall calls total min avg max stddev
(msec) (msec) (msec) (msec) (%)
--------------- -------- --------- --------- --------- --------- ------
read 3007 17624.985 0.002 5.861 12.345 0.21%
write 3003 13722.837 0.004 4.570 179.928 2.63%
openat 12 0.371 0.002 0.031 0.267 70.36%
...
Run Code Online (Sandbox Code Playgroud)
我读了iowait
从图中wa
的列vmstat
。您可以通过查看io
列(bo
= 1K 块输出)来判断测试何时运行。
$ vmstat 5
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
0 0 0 5126892 176512 1486060 0 0 1788 4072 321 414 4 4 83 9 0
1 0 0 5126632 176520 1485988 0 0 0 7 212 405 0 1 99 0 0
0 0 0 5126884 176520 1485988 0 0 0 0 130 283 0 0 99 0 0
0 0 0 5126948 176520 1485908 0 0 0 1 157 325 0 0 99 0 0
0 0 0 5126412 176520 1486412 0 0 115 0 141 284 0 0 99 0 0
0 2 0 5115724 176548 1487056 0 0 0 6019 18737 10733 3 6 89 2 0
1 0 0 5115708 176580 1487104 0 0 3 91840 1276 990 0 13 77 9 0
1 0 0 5115204 176600 1487128 0 0 2 91382 1382 1014 0 14 81 4 0
1 0 0 5115268 176636 1487084 0 0 4 88281 1257 901 0 14 83 3 0
0 1 0 5113504 177028 1487764 0 0 77 92596 1374 1111 0 15 83 2 0
1 0 0 5114008 177036 1487768 0 0 0 113282 1460 1060 0 16 81 2 0
1 0 0 5113472 177044 1487792 0 0 0 110821 1489 1118 0 16 74 10 0
0 0 0 5123852 177068 1487896 0 0 0 20537 631 714 1 3 94 2 0
0 0 0 5123852 177076 1487856 0 0 0 10 324 529 2 1 98 0 0
2 0 0 5123852 177084 1487872 0 0 0 70 150 299 0 0 99 0 0
Run Code Online (Sandbox Code Playgroud)
我在具有 1 个 CPU 的 VM 中尝试了相同的测试,该 VM 正在运行内核5.0.9-301.fc30.x86_64
并使用mq-deadline
(因此是 blk-mq)。在这个测试中,它按照我的预期工作。
$ sudo perf trace -s \
perf stat \
dd if=/dev/urandom of=test.out bs=1M oflag=direct count=3000
[sudo] password for alan-sysop:
3000+0 records in
3000+0 records out
3145728000 bytes (3.1 GB, 2.9 GiB) copied, 46.8071 s, 67.2 MB/s
Performance counter stats for 'dd if=/dev/urandom of=test.out bs=1M oflag=direct count=3000':
18,734.89 msec task-clock # 0.400 CPUs utilized
16,690 context-switches # 0.891 K/sec
0 cpu-migrations # 0.000 K/sec
328 page-faults # 0.018 K/sec
<not supported> cycles
<not supported> instructions
<not supported> branches
<not supported> branch-misses
46.820355993 seconds time elapsed
0.011840000 seconds user
18.531449000 seconds sys
Summary of events:
...
dd (1492), 12156 events, 38.4%
syscall calls total min avg max stddev
(msec) (msec) (msec) (msec) (%)
--------------- -------- --------- --------- --------- --------- ------
write 3003 28269.070 0.019 9.414 5764.657 22.39%
read 3007 18371.469 0.013 6.110 14.848 0.53%
execve 6 10.399 0.012 1.733 10.328 99.18%
...
Run Code Online (Sandbox Code Playgroud)
的输出vmstat 5
:
$ vmstat 5
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
0 0 0 726176 52128 498508 0 0 2040 231 236 731 7 5 77 11 0
0 0 0 726176 52136 498508 0 0 0 10 25 46 0 0 99 1 0
0 0 0 726208 52136 498508 0 0 0 0 29 56 0 0 100 0 0
0 1 0 702280 55944 511780 0 0 2260 13109 4399 9049 3 17 55 25 0
0 1 0 701776 56040 511960 0 0 18 129582 1406 1458 0 73 0 27 0
0 2 0 701524 56156 512168 0 0 22 87060 960 991 0 50 0 50 0
3 1 0 701524 56228 512328 0 0 14 118170 1301 1322 0 68 0 32 0
1 1 0 701272 56260 512392 0 0 6 86426 994 982 0 53 0 46 0
0 2 0 701020 56292 512456 0 0 6 56115 683 660 0 37 0 63 0
3 2 0 700540 56316 512504 0 0 5 33450 446 457 0 26 0 74 0
0 2 0 700860 56332 512536 0 0 3 16998 311 240 0 19 0 81 0
1 2 0 700668 56368 512616 0 0 7 32563 443 428 0 24 0 76 0
1 0 0 700668 56392 512648 0 0 3 20338 245 272 0 12 0 88 0
0 1 0 707096 56408 512920 0 0 54 20913 312 530 0 12 79 8 0
0 0 0 707064 56432 512920 0 0 0 49 39 64 0 0 45 55 0
0 0 0 707064 56432 512920 0 0 0 0 24 46 0 0 100 0 0
0 0 0 707064 56432 512920 0 0 0 80 28 47 0 0 100 0 0
Run Code Online (Sandbox Code Playgroud)
我尝试将 CPU 热添加到 VM 并再次测试。结果是可变的:有时它在空闲列中显示大约 0%,有时它显示大约 50% 空闲(即两个 CPU 中的一个)。在 0%“空闲”的情况下,“iowait”非常高,即超过一个 CPU 的价值。即我的期望点 2 不正确。我可以勉强接受“iowait”在多 CPU 系统上的这种明显限制。(虽然我不是很明白,如果有人想确切地解释它,那就太好了)。然而,在任何一种情况下,“空闲”都没有超过 50%,所以这些测试仍然与我对“iowait”的第一个假设一致。
我尝试关闭 VM 并使用 4 个 CPU 启动它。同样,我经常有正好 75% 的空闲,有时我有 50% 的空闲,但我没有看到超过 75% 的空闲(即超过四分之三的 CPU)。
而在具有 4 个 CPU 的物理系统上,我仍然可以重现 80% 以上空闲的结果,如上图所示。
内容通知:这篇文章包括各种 Linux 讨论和代码的链接。某些链接内容不符合StackExchange或Linux的当前行为准则。大多数情况下,他们“侮辱代码[但不是人]”。然而,使用了一些语言,不应该重复。我要求你避免模仿、模仿或辩论这种语言。
回复:iowait 与空闲记帐“不一致”- iowait 太低
在 05/07/2019 12:38,Peter Zijlstra 写道:
在 2019 年 7 月 5 日星期五下午 12:25:46 +0100,Alan Jenkins 写道:
我的 cpu "iowait" 时间似乎报告不正确。你知道为什么会发生这种情况吗?
因为 iowait 是一个神奇的随机数,没有任何意义。就我个人而言,我更愿意删除整个内容,除了ABI:/
另请参阅nr_iowait()附近的评论
谢谢。我认为 [当前文档中提到的问题] 是不同的问题,但您的意思是没有太多需求(或指向)来“解决”我的问题。
我发现了我的问题。五年前就已经注意到了,修复起来并非易事。
“iowait”时间由函数更新account_idle_time()
:
/*
* Account for idle time.
* @cputime: the CPU time spent in idle wait
*/
void account_idle_time(u64 cputime)
{
u64 *cpustat = kcpustat_this_cpu->cpustat;
struct rq *rq = this_rq();
if (atomic_read(&rq->nr_iowait) > 0)
cpustat[CPUTIME_IOWAIT] += cputime;
else
cpustat[CPUTIME_IDLE] += cputime;
}
Run Code Online (Sandbox Code Playgroud)
如果您通过使用传统定时器中断(“滴答”)“采样”来估算 CPU 时间,这将按我的预期工作。但是,如果在空闲时间关闭滴答以节省电量,它可能不起作用 - NO_HZ_IDLE
。如果出于性能原因允许关闭刻度线,它也可能会失败NO_HZ_FULL
- 因为这需要启动VIRT_CPU_ACCOUNTING
。大多数 Linux 内核使用省电功能。一些嵌入式系统不使用这两种功能。这是我的解释:
IO 完成后,设备发送中断。内核中断处理程序使用try_to_wake_up()
. 它从nr_iowait
计数器中减去一:
if (p->in_iowait) {
delayacct_blkio_end(p);
atomic_dec(&task_rq(p)->nr_iowait);
}
Run Code Online (Sandbox Code Playgroud)
如果进程在空闲 CPU 上被唤醒,则该 CPU 调用account_idle_time()
. 根据适用的配置,这就是所谓的无论是从tick_nohz_account_idle_ticks()
从__tick_nohz_idle_restart_tick()
,或vtime_task_switch()
从finish_task_switch()
。
到了这个时候,->nr_iowait
已经是递减了。如果减少到零,则不会记录 iowait 时间。
这种影响可能会有所不同:这取决于进程在哪个 CPU 上被唤醒。如果进程在接收到 IO 完成中断的同一 CPU 上被唤醒,则空闲时间可以更早地计算,然后->nr_iowait
递减。在我的例子中,我发现 CPU 0 处理ahci中断,通过查看watch cat /proc/interrupts
.
我用一个简单的顺序读取测试了这个:
dd if=largefile iflag=direct bs=1M of=/dev/null
Run Code Online (Sandbox Code Playgroud)
如果我使用 将命令固定到 CPU 0 taskset -c 0 ...
,我会看到 iowait 的“正确”值。如果我将它固定到不同的 CPU,我看到的值要低得多。如果我正常运行命令,它会因调度程序行为而异,这在内核版本之间发生了变化。在最近的内核(4.17、5.1、5.2-rc5-ish)中,该命令似乎在 CPU 0 上花费了大约 1/4 的时间,因为“iowait”时间减少到了这一部分。
(未解释:为什么现在在我的虚拟机上运行此测试似乎可以为每个(或任何)CPU 重现“正确”的 iowait。我怀疑这可能涉及IRQ_TIME_ACCOUNTING
,尽管此功能也在我的 VM 外部测试中使用。
我也没有确切地确认为什么抑制NO_HZ_IDLE
会在 4.17+ 上为每个 CPU 提供“正确的”iowait,但在 4.16 或 4.15 上没有。
在我的虚拟机上运行此测试似乎可以为每个(或任何)CPU 重现“正确”的 iowait。这是由于 IRQ_TIME_ACCOUNTING
. 它也用于 VM 外部的测试,但在 VM 内部测试时我得到更多中断。具体来说,运行“dd”的虚拟CPU上每秒有1000多个“函数调用中断”。
所以你不应该过分依赖我解释的细节:-)
这里有一些关于“iowait”的背景:CPU 如何知道有 IO 挂起? 这里的答案引用了一个违反直觉的想法,即累积 iowait“在某些情况下可能会减少”。我想知道我的简单测试是否会触发这种未记录的情况?
是的。
当我第一次查看这个时,我发现了“打嗝”的说法。此外,该问题通过显示累积的“iowait”时间是非单调的。那就是它有时会向后跳(减少)。它不像上面的测试那么简单。
然而,当他们调查时,他们发现了同样的基本问题。Peter Zijlstra 和 Hidetoshi Seto 分别提出并制作了一个解决方案。封面消息中解释了该问题:
[RFC PATCH 0/8] 返工 iowait 会计(2014-07-07)
我没有发现除此之外取得进展的证据。关于其中一个细节有一个悬而未决的问题。此外,整个系列涉及 PowerPC、S390 和 IA64 CPU 架构的特定代码。所以我说这不是很容易解决。