我的基本假设是,当一个进程的唯一限制因素是磁盘和 CPU 时,则总系统“iowait”+ CPU 使用率应至少等于一个逻辑 CPU 的 100%。 (在其他情况下,这不会成立。例如,当使用 下载文件时wget
,网络通常是限制因素)。
一个简单的测试就违反了这个假设。这是预期的吗?如果是预期的话,是否有一系列条件可以让我应该期望我的假设成立吗?
这里有一些关于“iowait”的背景:CPU 如何知道有 IO 待处理? 这里的答案引用了反直觉的想法,即累积 iowait“在某些条件下可能会减少”。我想知道我的简单测试是否会触发这种未记录的情况?
更新: 请跳到答案。
答案有一个比我最初使用的测试更简单的测试。我保留了下面的原始问题。原来的问题可能会显示一些额外的细节。
原问题
在一个简短的测试中,我用来dd
请求内核生成随机字节,并将它们写入文件。我运行dd
inside 的命令perf stat
,只是为了计算内核中花费的 CPU 时间。我也在里面运行它perf trace -s
,报告里面花费的时间write()
。同时,我vmstat 5
在另一个终端中运行,看到系统“iowait”。
- 我预计至少会看到整个 CPU 处于“非空闲”状态,即 100% 的时间它要么正在运行,要么已停止但正在等待 IO(“iowait”状态)。不是。
- (另外,我期望看到“iowait”时间与 write() 中花费的时间大致匹配。但它似乎并没有这样做。)
详细结果和测试环境如下所示。还显示了另一种测试,我的假设确实成立。注意:必须perf stat
往里面跑perf trace
,而不是相反。详细信息如下:运行“perf trace -s”时,“perf stat”(和“时间”!)是否显示不正确的结果?
“iowait”的背景信息
以下是取自联机帮助页的定义
sar
:%io等待:
系统有未完成的磁盘 I/O 请求期间,一个或多个 CPU 处于空闲状态的时间百分比。
因此,%iowait 意味着从 CPU 的角度来看,没有任务可运行,但至少有一个 I/O 正在进行。 iowait 只是一种空闲时间,无法安排任何事情。该值在指示性能问题方面可能有用,也可能没有用,但它确实告诉用户系统处于空闲状态并且可能需要进行更多工作。
https://support.hpe.com/hpsc/doc/public/display?docId=c02783994
还有一篇较长的文章:了解 I/O 等待(或者为什么 0% 空闲就可以)。这就解释了如何从内核代码中清楚地看到定义。代码稍有改动,但思路仍然清晰:
/*
* 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;
}
文章还展示了在单CPU系统上的一些相关实验。有些实验甚至dd
使用if=/dev/urandom
!然而实验不包括我的测试dd if=/dev/urandom of=test.out
。它只使用dd if=/dev/urandom of=/dev/null
.
现在考虑“IO等待”有点棘手,因为我们使用多CPU系统,但根据引用的代码,我想我仍然理解它。
环境
我有四个逻辑 CPU。
我使用 LVM 和 ext4 文件系统。我没有在磁盘或文件系统上使用任何加密。我根本没有安装任何网络文件系统,因此我没有读取或写入网络文件系统。
下面的结果来自内核4.20.15-200.fc29.x86_64
,使用noop
IO 调度程序。 IO调度器cfq
也给出了类似的结果。
(我还在内核构建上看到了类似的结果,该内核构建基于类似的配置,但更接近内核版本 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%
...
我从专栏中读到了这个iowait
数字。您可以通过查看列(= 1K 块输出)来判断测试何时运行。wa
vmstat
io
bo
$ 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
测试结果(在虚拟机内)
我在具有 1 个 CPU 的虚拟机中尝试了相同的测试,该虚拟机正在运行内核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%
...
输出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
我尝试将 CPU 热添加到虚拟机并再次测试。结果各不相同:有时空闲列显示约 0%,有时显示约 50% 空闲(即两个 CPU 中的一个)。在 0%“空闲”的情况下,“iowait”非常高,即超过一个 CPU 的值。也就是说,我的预期点 2 不正确。我可以勉强接受这“iowait”在多 CPU 系统上的明显限制。 (虽然我不太明白。如果有人想准确地解释它,那就太好了)。然而,在这两种情况下,“idle”都不超过 50%,因此这些测试仍然与我对“iowait”的第一个假设一致。
我尝试关闭虚拟机,然后使用 4 个 CPU 启动它。同样,我经常看到正好 75% 的空闲,有时空闲率低至 50%,但我没有看到超过 75% 的空闲率(即超过 4 个 CPU 中的 3 个)。
而在具有 4 个 CPU 的物理系统上,我仍然可以重现如上所示的超过 80% 空闲的结果。
答案1
内容通知:这篇文章包含各种 Linux 讨论和代码的链接。某些链接内容不符合当前的行为准则堆栈交换或为了Linux。大多数情况下,他们“侮辱代码[而不是人]”。无论使用何种语言,都不应重复。我要求你们避免模仿、鹦鹉学舌或争论此类语言。
回复:iowait 与空闲记帐“不一致” - iowait 太低
2019 年 5 月 7 日 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;
}
这正如我预期的那样,如果你是近似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);
}
如果进程在空闲 CPU 上被唤醒,则该 CPU 会调用account_idle_time()
.根据应用的配置,这称为 from tick_nohz_account_idle_ticks()
from__tick_nohz_idle_restart_tick()
或 from vtime_task_switch()
from finish_task_switch()
。
此时,->nr_iowait
已经减少了。如果减为零,则不会记录 iowait 时间。
这种效果可能会有所不同:这取决于进程在哪个 CPU 上被唤醒。如果在接收 IO 完成中断的同一 CPU 上唤醒进程,则可以在->nr_iowait
减少之前更早地计算空闲时间。就我而言,我发现 CPU 0 处理阿奇中断,通过查看watch cat /proc/interrupts
.
我通过简单的顺序读取对此进行了测试:
dd if=largefile iflag=direct bs=1M of=/dev/null
如果我使用 将该命令固定到 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
,尽管这个功能也在我的虚拟机之外的测试中使用。
我还没有确切地确认为什么抑制NO_HZ_IDLE
在 4.17+ 上为每个 CPU 提供“正确”的 iowait,但在 4.16 或 4.15 上则不然。
在我的虚拟机上运行此测试似乎可以为每个(或任何)CPU 重现“正确”的 iowait。这是因为 IRQ_TIME_ACCOUNTING
。它也用于虚拟机外部的测试,但在虚拟机内部测试时我会遇到更多中断。具体来说,“dd”运行的虚拟 CPU 上每秒有超过 1000 个“函数调用中断”。
所以你不应该过分依赖我的解释的细节:-)
这里有一些关于“iowait”的背景:CPU 如何知道有 IO 待处理? 这里的答案引用了反直觉的想法,即累积 iowait“在某些条件下可能会减少”。我想知道我的简单测试是否会触发这种未记录的情况?
是的。
当我第一次查到这个时,我发现了“打嗝”的说法。此外,通过显示累积的“iowait”时间是非单调的来说明该问题。也就是说,它有时会向后跳跃(减少)。它并不像上面的测试那么简单。
然而,当他们进行调查时,他们发现了同样的根本问题。 Peter Zijlstra 和 Hidetoshi Seto 分别提出了解决方案并原型化。封面消息中解释了该问题:
[RFC PATCH 0/8] 返工 iowait 记账(2014-07-07)
除此之外,我没有发现任何进展的证据。其中一个细节存在一个悬而未决的问题。此外,整个系列还涉及 PowerPC、S390 和 IA64 CPU 架构的特定代码。所以我说解决这个问题并不容易。