系统负载高，但Linux上的CPU使用率低？

在这篇文章中，我将向您展示如何通过负载贡献者或原因来分解Linux系统负载。您也可以深入研究“成千上万的Linux系统负载”和“系统负载高，但CPU利用率低”的问题模式。

系统负载度量旨在将系统“资源需求”表示为一个数字。在经典Unix上，它仅计算对CPU的需求（处于Runnable状态的线程）

系统负载量度的单位是“进程/线程数”（或在Linux上称为调度单位的任务）。平均负载是在一段时间（最后1,5,15分钟）内平均线程数，在经典Unix上“争夺CPU”或在Linux上“争夺CPU或等待不间断的睡眠状态”

可运行状态表示“不受任何阻止”，可以在CPU上运行。该线程当前正在CPU上运行，或者在CPU运行队列中等待OS调度程序将其放入CPU

在Linux上，系统负载包括处于Runnable（R）和处于Uninterruptible sleep（D）状态的线程（通常是磁盘I / O，但并非总是如此）

因此，在Linux上，除了CPU需求外，还有许多处于不间断睡眠（D）状态的线程可能会导致负载过高。

被上述监视工具错误地标记为“可运行的进程”的系统负载跃升至3000多个！

让我们用标准操作系统级别的命令来确认这一点，以避免被监视工具误导潜在的GUI魔术：

[tanel @ linux01〜] $ w 11:49:29最多13天，13:55，2个用户，平均负载：3446.04，1242.09，450.47 USER TTY FROM LOGIN @ IDLE JCPU PCPU WHATtanel pts / 0 192.168.0.159 Thu14 21： 09m 0.05s 0.05s -bashtanel pts / 1 192.168.0.159 11:46 1.00s 0.36s 0.23sw

这是否意味着我们对CPU时间有巨大的需求？ CPU运行队列中必须有很多线程，对吗？

[tanel @ linux01〜] $ sar -u 511：58：51 AM CPU％user％nice％system％iowait％steal％idle11：58：56 AM所有36.64 0.00 4.42 17.17 0.00 41.7711：59：01 AM所有41.04 0.00 3.72全部26.67 0.00 28.5711：59：06 35.38 0.00 2.95 28.39 0.00 33.27

但是CPU闲置率超过50％！将％user，％nice和％system一起添加时，CPU利用率约为40-45％。 ％iowait表示CPU处于空闲状态，它恰好在空闲之前由线程在其上提交了同步I / O。

因此，在这种情况下，我们似乎没有CPU超额预定的情况。有没有一种方法可以通过测量造成此负载的因素（以及是谁）来更系统地深入研究？

是的，而且非常简单。请记住，当前系统负载只是Linux上处于R或D状态的线程（称为任务）的数量。我们可以运行ps列出这些状态下的当前线程数：

[tanel @ linux01〜] $ ps -eo s，用户| grep ^ [RD] |排序uniq -c |排序-nbr |头-20 3045 D根20 R甲骨文3 R根1 R tanel

在上面的命令ps -eo s中，用户将首先列出线程状态字段，然后列出所有其他感兴趣的字段（如用户名）。 grep ^ [RD]过滤掉各种不会影响Linux负载（S，T，t，Z，I等）的处于“空闲”和“睡眠”状态的线程。

实际上，除了共有24个处于Runnable状态（R）的线程外，似乎有3000多个处于Uninterruptible Sleep（D）状态的线程通常（但并非总是）表示由于同步磁盘IO而处于睡眠状态。它们都是root拥有的。是否有一些守护进程变得疯狂，并且所有这些活动进程/线程都试图执行IO？

让我们在ps上再增加一列，以列出命令行/程序名称：

[tanel @ linux01〜] $ ps -eo s，user，cmd | grep ^ [RD] |排序uniq -c |排序-nbr |头-20 15 R oracle oracleLIN19C（LOCAL = NO）3 D oracle oracleLIN19C（LOCAL = NO）1 R tanel ps -eo s，user，cmd 1 R根xcapture -o / backup / tanel / 0xtools / xcaplog -c exe， cmdline，kstack 1 D根[kworker / 6：99] 1 D根[kworker / 6：98] 1 D根[kworker / 6：97] 1 D根[kworker / 6：96] 1 D根[kworker / 6 ：95] 1 D根[kworker / 6：94] 1 D根[kworker / 6：93] 1 D根[kworker / 6：92] 1 D根[kworker / 6：91] 1 D根[kworker / 6 ：90] 1 D根[kworker / 6：9] 1 D根[kworker / 6：89] 1 D根[kworker / 6：88] 1 D根[kworker / 6：87] 1 D根[kworker / 6 ：86] 1个D根[kworker / 6：85]

但是现在“根”似乎已经从顶部消失了，我们只看到顶部附近只有一些Oracle进程，而R / D活动相对较少。我的命令最后使用head -20过滤器，以避免在大多数ps输出行都是唯一的情况下打印出数千行输出，在这种情况下，所有单独的kworker线程都具有唯一的名称。它们有成千上万，每个都仅对负载摘要贡献“具有该名称的1个线程”。

如果您不希望再使用其他awk / sed命令来更好地对ps输出进行分组，则可以使用0x.tools中的pSnapper来为您完成工作。而且，它多次采样线程状态并打印活动平均值的细目分类（以避免被一个“不幸”的样本误导）：

[tanel @ linux01〜] $ psnLinux进程快照程序v0.18，由Tanel Poder提供[https://0x.tools]对/ proc / stat采样5秒钟...已完成。===活动线程======= =====================================样品avg_threads |通讯|状态------------------------------------------------- ------------------ 10628 | 3542.67 | （kworker / *：*）|磁盘（不间断）37 | 12.33 | （oracle _ * _ l）|运行（CPU上）17 | 5.67 | （oracle _ * _ l）|磁盘（不间断）2 | 0.67 | （xcapture）|正在运行（CPU上）1 | 0.33 | （ora_lg * _xe）|磁盘（不间断）1 | 0.33 | （ora_lgwr_lin *）|磁盘（不间断）1 | 0.33 | （ora_lgwr_lin * c）|磁盘（不间断）样本：3（预期：100）总进程：10470，线程：11530运行时：6.13，测量时间：6.03

默认情况下，pSnapper会在汇总之前替换任务comm字段中的所有数字（comm2字段将使它们保持不变）。现在，我们可以很容易地看到我们的极端系统负载高峰是由大量kworker内核线程（“ root”作为进程所有者）引起的。因此，这不是关于在root用户下运行的某些userland守护程序，而是一个内核问题。

我将使用同一问题的另一实例（在同一台计算机上）更深入地研究此问题。这次系统负载为数百：

[tanel @ linux01〜] $ w 13:47:03最多7天，15：53、3个用户，平均负载：496.62、698.40、440.26 USER TTY LOGIN @ IDLE JCPU PCPU WHATtanel pts / 0 192.168.0.159 13:36 7:03 0.06s 0.06s -bashtanel pts / 1 192.168.0.159 13:41 7.00s 0.32s 0.23s wtanel pts / 2 192.168.0.159 13:42 3:03 0.23s 0.02s sshd：tanel [priv]

让我们再次按comm和state字段细分需求，但我还将在细分中添加当前系统调用和内核等待位置（wchan）。有了这些额外的字段，我应该使用sudo运行pSnapper，因为当以非root身份运行时，现代Linux内核版本往往会阻止对某些字段的访问（或隐藏其中的值）：

[tanel @ linux01〜] $ sudo psn -G syscall，wchanLinux进程快照程序v0.18，由Tanel Poder提供[https://0x.tools]采样/ proc / syscall，stat，wchan 5秒钟...完成。== =活动线程=============================================== ===================================== avg_threads |通讯|州| syscall | chan ------------------------------------------------- -------------------------------------------------- ---------- 511 | 255.50 | （kworker / *：*）|磁盘（不间断）| [kernel_thread] | blkdev_issue_flush 506 | 253.00 | （oracle _ * _ l）|磁盘（不间断）| pread64 | do_blockdev_direct_IO 28 | 14.00 | （oracle _ * _ l）|正在运行（在CPU上）| [运行中] 0 1 | 0.50 | （集合）|正在运行（在CPU上）| [运行中] 0 1 | 0.50 | （mysqld）|正在运行（在CPU上）| [运行中] 0 1 | 0.50 | （ora_lgwr_lin * c）|磁盘（不间断）| io_submit | inode_dio_wait 1 | 0.50 | （oracle _ * _ l）|磁盘（不间断）| pread64 | 0 1 | 0.50 | （oracle _ * _ l）|正在运行（在CPU上）| [运行中] SYSC_semtimedop 1 | 0.50 | （oracle _ * _ l）|正在运行（在CPU上）| [运行中] read_events 1 | 0.50 | （oracle _ * _ l）|正在运行（在CPU上）|阅读| 0 1 | 0.50 | （oracle _ * _ l）|正在运行（在CPU上）| semtimedop | SYSC_semtimedop

在上述当前系统负载的细分中，将近一半的活动是由内核kworker线程引起的，这些线程当前在blkdev_issue_flush内核函数中睡眠，该内核函数负责内部fsync，以确保写入可持久存储。其余“接近一半”的活动线程由oracle进程在do_blockdev_direct_IO内核函数中的同步pread64系统调用中等待。

从“正在运行（CPU上运行）”行中，您还可以看到CPU的使用情况，但似乎与I / O睡眠中的数百个线程没有什么关系。

在进行这些测试时，我运行了具有1000个并发连接（有时是空闲的）的Oracle基准测试，因此可以很容易地解释在同步pread64系统调用中等待的253个会话。例如，同步单块读取可用于索引树遍历和基于索引的表块访问。但是为什么我们还会看到这么多的kworker内核线程也在等待I / O？

答案是异步I / O和针对更高级别的块设备（例如，用于LVM的设备映射器dm设备和用于软件RAID的md设备）完成的I / O。使用异步I / O，在内核内存结构中完成I / O请求的线程与提交I / O的（应用程序）线程不同。这就是内核kworker线程进入的地方，而使用LVM / dm / md设备的情况变得更加复杂（因为请求路径上有多层I / O队列）。

因此，您可以说oracle进程在pread64 syscall中处于休眠状态的253线程是同步读取，而255.5内核线程（无系统调用，因为内核代码不需要系统调用即可进入内核模式）是异步的。 I / O。

请注意，虽然像pread64这样的同步I / O等待会因为它们最终处于D状态而增加了Linux系统的负载，但是异步I / O完成检查（和IO收割）系统调用io_getevents最终会处于S状态（休眠）。由应用程序指示等待。因此，只有同步I / O操作（通过应用程序或内核线程）才有助于Linux系统负载！

此外，在成功提交IO之前，用于I / O请求异步提交的io_submit系统调用本身可能会被阻止。如果I / O队列中已经充满了不完整，未收获的I / O请求，或者在块设备的路径上较早的某个地方存在“障碍”（例如文件系统层或LVM问题），则可能会发生这种情况。在这种情况下，尽管I / O甚至没有发送到硬件，但是io_submit调用本身也会被卡住（尽管I / O具有异步性质），并且发出I / O的线程最终仍在D状态下等待。设备呢。

在高通量系统中，至少有一个Linux内核错误导致kworkers和dm / md设备的接触点出现问题，但我将在下一篇文章中介绍。

您不必猜测瓶颈在哪里，只需使用pSnapper提供的功能进行更深入的研究即可。一个典型的问题是，我们等待最多的文件或设备是什么？让我们在细分中添加文件名（或将其中包含数字的文件名合并为一个的文件名和）：

[tanel @ linux01〜] $ sudo psn -G syscall，文件名总和Tanel Poder发行的Linux Process Snapper v0.18 [https://0x.tools]正在采样/ proc / syscall，状态持续5秒钟...已完成。===活动线程================================================= ================================================== ====样本| avg_threads |通讯|州| syscall | filenamesum ------------------------------------------------- -------------------------------------------------- ----------------------- 2027年| 506.75 | （kworker / *：*）|磁盘（不间断）| [kernel_thread] | 1963年| 490.75 | （oracle _ * _ l）|磁盘（不间断）| pread64 | /data/oracle/LIN*C/soe_bigfile.dbf 87 | 21.75 | （oracle _ * _ l）|正在运行（在CPU上）| [运行中] 13 | 3.25 | （kworker / *：*）|正在运行（在CPU上）| [运行中] 4 | 1.00 | （oracle _ * _ l）|正在运行（在CPU上）|阅读|套接字：[*] 2 | 0.50 | （集合）|正在运行（在CPU上）| [运行中] 1 | 0.25 | （java）|正在运行（在CPU上）| futex | 1 | 0.25 | （ora_ckpt_xe）|磁盘（不间断）| pread64 | /data/oracle/XE/control*.ctl 1 | 0.25 | （ora_m * _linprd）|正在运行（在CPU上）| [运行中] 1 | 0.25 | （ora_m * _lintes）|正在运行（在CPU上）| [运行中]

显然，系统负载现在已经增加了（处于R / D状态的活动线程超过1000个）。见证的大多数同步读取等待都针对/data/oracle/LIN*C/soe_bigfile.dbf文件（由oracle用户使用）。由于pSnapper从系统调用参数获取文件名（并在可能的情况下将文件描述符解析为文件名），因此kworker线程未显示其I / O的任何文件名-但是内核线程不需要它们的系统调用已经在内核深处运行，始终处于内核模式。但是，此字段在许多应用程序故障排除方案中很有用。

让我们深入探讨。您需要向右滚动才能查看完整图片。我已经从右至右突出了一些内容。我们也可以对线程的内核堆栈（内核线程以及用户空间应用程序线程，恰好在执行内核代码）进行采样：

[tanel @ linux01〜] $ sudo psn -p -G syscall，wchan，kstack Tanel Poder发行的Linux Process Snapper v0.18 [https://0x.tools]对/ proc / wchan，stack，syscall，stat进行采样5秒钟。 ..完成。===活动线程========================================== ================================================== ================================================== ================================================== ================================================== ================================================== ================================================== ================================样本| avg_threads |通讯|州| syscall | wchan | kstack ------------------------------------------------- -------------------------------------------------- -------------------------------------------------- -------------------------------------------------- -------------------------------------------------- -------------------------------------------------- -------------------------------------------------- --------------------------------------------- 281 | 140.50 | （kworker / *：*）|磁盘（不间断）| [kernel_thread] | blkdev_issue_flush | ret_from_fork_nospec_begin（）-> kthread（）-> worker_thread（）-> process_one_work（）-> dio_aio_complete_work（）-> dio_complete（）-> generic_write_sync（）-> xfs_file_fsync（）-> xfs_blkdev_issue_flush（）->> 105.50 | （kworker / *：*）|磁盘（不间断）| [kernel_thread] | call_rwsem_down_read_failed | ret_from_fork_nospec_begin（）-> kthread（）-> worker_thread（）-> process_one_work（）-> dio_aio_complete_work（）-> dio_complete（）-> generic_write_sync（）-> xfs_file_fsync（）-> xfs_ilock（）->（call_rwsem） 84.50 | （oracle _ * _ li）|磁盘（不间断）| pread64 | call_rwsem_down_write_failed | system_call_fastpath（）-> SyS_pread64（）-> vfs_read（）-> do_sync_read（）-> xfs_file_aio_read（）-> xfs_file_dio_aio_read（）-> touch_atime（）-> update_time（）-> xfs_vn_update-time（-） call_rwsem_down_write_failed（）64 | 32.00 | （kworker / *：*）|磁盘（不间断）| [kernel_thread] | xfs_log_force_lsn | ret_from_fork_nospec_begin（）-> kthread（）-> worker_thread（）-> process_one_work（）-> dio_aio_complete_work（）-> dio_complete（）-> generic_write_sync（）-> xfs_file_fsync（）-> xfs_log_force_lsn（）24 | 12.00 | （oracle _ * _ li）|磁盘（不间断）| pread64 | call_rwsem_down_read_failed | system_call_fastpath（）-> SyS_pread64（）-> vfs_read（）-> do_sync_read（）-> xfs_file_aio_read（）-> xfs_file_dio_aio_read（）-> __ blockdev_direct_IO（）-> do_blockdev_direct_IO（）-> xfs_s _> _ xfs_s xfs_ilock_data_map_shared（）-> xfs_ilock（）-> call_rwsem_down_read_failed（）5 | 2.50 | （oracle _ * _ li）|磁盘（不间断）| pread64 | do_blockdev_direct_IO | system_call_fastpath（）-> SyS_pread64（）-> vfs_read（）-> do_sync_read（）-> xfs_file_aio_read（）-> xfs_file_dio_aio_read（）-> __ blockdev_direct_IO（）-> do_blockdev_direct_IO（）3 | 1.50 | （oracle _ * _ li）|正在运行（在CPU上）| [运行中] 0 | system_call_fastpath（）-> SyS_pread64（）-> vfs_read（）-> do_sync_read（）-> xfs_file_aio_read（）-> xfs_file_dio_aio_read（）-> __ blockdev_direct_IO（）-> do_blockdev_direct_IO（）2 | 1.00 | （kworker / *：*）|磁盘（不间断）| [kernel_thread] | call_rwsem_down_write_failed | ret_from_fork_nospec_begin（）-> kthread（）-> worker_thread（）-> process_one_work（）-> dio_aio_complete_work（）-> dio_complete（）-> xfs_end_io_direct_write（）-> xfs_iomap_write_unwriter（）-> xfs_ilock（）-> 1.00 | （kworker / *：*）|正在运行（在CPU上）| [运行中] 0 | ret_from_fork_nospec_begin（）-> kthread（）-> worker_thread（）-> process_one_work（）-> dio_aio_complete_work（）-> dio_complete（）-> generic_write_sync（）-> xfs_file_fsync（）-> xfs_blkdev_issue_flush（）->> 1.00 | （oracle _ * _ li）|磁盘（不间断）| io_submit | call_rwsem_down_write_failed | system_call_fastpath（）-> SyS_io_submit（）-> do_io_submit（）-> xfs_file_aio_read（）-> xfs_file_dio_aio_read（）-> touch_atime（）-> update_time（）-> xfs_vn_update_time（）->-xfs_ilock（）-> xfs_ilock 0.50 | （java）|正在运行（在CPU上）| futex | futex_wait_queue_me | system_call_fastpath（）-> SyS_futex（）-> do_futex（）-> futex_wait（）-> futex_wait_queue_me（）1 | 0.50 | （ksoftirqd / *）|正在运行（在CPU上）| [运行中] 0 | ret_from_fork_nospec_begin（）-> kthread（）-> smpboot_thread_fn（）1 | 0.50 | （kworker / *：*）|磁盘（不间断）| [kernel_thread] | worker_thread | ret_from_fork_nospec_begin（）-> kthread（）-> worker_thread（）1 | 0.50 | （kworker / *：*）|磁盘（不间断）| [kernel_thread] | worker_thread | ret_from_fork_nospec_begin（）-> kthread（）-> worker_thread（）-> process_one_work（）-> dio_aio_complete_work（）-> dio_complete（）-> generic_write_sync（）-> xfs_file_fsync（）-> xfs_blkdev_issue_flush（）->> 0.50 | （ora_lg * _xe）|磁盘（不间断）| io_submit | inode_dio_wait | system_call_fastpath（）-> SyS_io_submit（）-> do_io_submit（）-> xfs_file_aio_write（）-> xfs_file_dio_aio_write（）-> inode_dio_wait（）1 | 0.50 | （oracle _ * _ li）|磁盘（不间断）| [运行中] 0 | --

看来我的基准测试系统现在发生了其他问题，报告中又弹出了其他WCHAN（内核睡眠位置）值：Oracle和kworker线程都无法调用call_rwsem_down _ * _ failed，而xfs_log_force_lsn则要等待32个kworker线程。 rwsem代表“读写器信号量”，它本质上是一种低级锁定。因此，我们系统负载（D状态等待）的很大一部分是由于现在内核中的某种锁定而不是等待硬件I / O完成而导致的。

如果一直滚动并遵循内核函数调用链，那么（某种程度上）显然，当我们访问（读取和写入）文件时，我们正在等待XFS inode锁。此外，在搜索xfs_log_force_lsn函数的功能时，您会看到这是XFS日志写操作，可将XFS元数据更新持久保存到磁盘上，这样在崩溃时不会导致文件系统损坏。 XFS延迟日志记录必须排序，并且检查点必须是原子的，因此在某些情况下，一个CPU上的一个与XFS相关的kworker会阻塞其余CPU上的其他kworker（承担相同的角色）。例如，如果由于某些原因XFS日志/检查点写入太慢。 pSnapper在我的32 CPU系统上的xfs_log_force_lsn函数中恰好显示了32个线程正在等待，这可能不是巧合。

为什么我们甚至还有明显的XFS元数据生成？与ZFS不同，XFS不会在日志中记录实际数据，只是