【问题标题】:Periodic high kernel CPU load?周期性高内核 CPU 负载?
【发布时间】:2021-02-04 21:32:16
【问题描述】:

对于通常使用很少 CPU 的程序来说,内核 CPU 非常高。 Linux 机器在状态之间交替。大多数时候,程序使用低 CPU 正常执行。在 CPU“激增”期间,程序会使用 100% 可用 CPU 的高内核 CPU。

下面的示例 C 程序和输出。

机器大约每五分钟进出一个奇怪的状态,其中一些(但不是全部)程序使用高内核 CPU。 CPU“浪涌”可能会持续一分钟,然后机器会再恢复正常状态 5-10 分钟。重新启动有时会有所帮助,但浪涌会在一周内逐渐增加,直到问题变得严重到需要再次重新启动。有时重新启动没有帮助,唯一的临时解决方法是尝试再次重新启动。

  • CentOS 6.9 版
  • 具有 14 个 CPU、32 GB 内存的戴尔 PowerEdge R630
  • Linux 2.6.32-696.30.1.el6.x86_64 x86_64

我能够用这个示例 C 程序重现 CPU 问题。它运行一个 shell 脚本,该脚本执行 sleep 0.01 秒,并打印 10 次迭代中每一次的运行时间。机器正常时运行快,机器异常时运行慢。

test_system.c

#include <stdio.h>
#include <stdlib.h>

int main(int argc, char *argv[])
{
    int i, n;
    char cmd[100];

    if (argc == 2) {
        n = atoi(argv[1]);
    }
    else {
        n = 1;
    }

    printf("n=%d\n", n);

    for (i=0; i<n; i++) {
        system("ts=$(date +%s%N) ; sleep 0.01 ; tt=$((($(date +%s%N) - $ts)/1000000)) ; echo \"Time taken: $tt milliseconds\"");
    }
}

这是机器处于正常状态时的输出。大部分 CPU 都在用户空间中。

$ time test_system 10
n=10
Time taken: 12 milliseconds
Time taken: 12 milliseconds
Time taken: 12 milliseconds
Time taken: 12 milliseconds
Time taken: 12 milliseconds
Time taken: 12 milliseconds
Time taken: 12 milliseconds
Time taken: 12 milliseconds
Time taken: 12 milliseconds
Time taken: 12 milliseconds

real    0m0.210s
user    0m0.059s
sys     0m0.015s
$

这是机器遇到 CPU“浪涌”模式时的输出。我在发生两次长时间停顿的地方添加了 cmets。延迟是由于机器 CPU 过载造成的。运行时间为 35.6 秒,比正常时间长 170 倍。这次运行的内核 CPU 使用率为 7.2 秒,比正常运行增加了 480 倍。

$ time test_system 10
n=10
Time taken: 161 milliseconds
Time taken: 406 milliseconds
Time taken: 58 milliseconds
Time taken: 176 milliseconds
Time taken: 189 milliseconds
--- approx. 17 sec delay ---
Time taken: 25 milliseconds
Time taken: 127 milliseconds
Time taken: 82 milliseconds
Time taken: 84 milliseconds
Time taken: 12 milliseconds
--- approx. 17 sec delay ---

real    0m35.641s
user    0m0.077s
sys     0m7.233s
$

post 表明为 I/O 缓冲区分配的内存过多会导致此问题,因为内核必须努力回收内存才能运行程序。但没有迹象表明内存交换或短缺。我进行了分配 100 MB 内存的单独测试,即使在 CPU 激增期间也没有看到延迟或高 CPU。

关于什么会导致这种行为的任何其他建议?

这是我最新的测试程序,分别计算 fork()exec()

test_fork.c

#include <stdio.h>
#include <stdlib.h>
#include <sys/time.h>
#include <unistd.h>
#include <assert.h>

#define ELAPSED_USEC(t1, t2)  (SEC2USEC((t2).tv_sec - (t1).tv_sec) + (t2).tv_usec - (t1).tv_usec)
#define SEC2USEC(sec)         ((sec)*1000000)


int main(int argc, char *argv[])
{
    int i, n;
    struct timeval start_time, end_time;
    struct timezone tz;
    pid_t pid;
    char *shell = "/bin/bash";
    char *shell_cmd;
    int status;

    if (argc == 3) {
        n = atoi(argv[1]);
        shell_cmd = argv[2];
    }
    else {
        fprintf(stderr, "Usage: %s count shell_cmd\n", argv[0]);
        exit(1);
    }

    printf("n=%d shell_cmd=[%s]\n", n, shell_cmd);

    for (i=0; i<n; i++) {
        gettimeofday(&start_time, &tz);
        pid = fork();
        if (pid == -1)
        {   
            fprintf(stderr, "fork failed.\n");
            exit(1);
        }
        else if (pid > 0)
        {   
            gettimeofday(&end_time, &tz);
            printf("fork: %ld usec, ", ELAPSED_USEC(start_time, end_time));

            gettimeofday(&start_time, &tz);
            waitpid(pid, &status, 0);
            gettimeofday(&end_time, &tz);
            printf("exec: %ld msec\n", ELAPSED_USEC(start_time, end_time)/1000);  // 1 msec = 1000 usec
            //assert(WEXITSTATUS(status) == 123);
        }
        else
        {
            // we are the child
            execl(shell, shell, "-c", shell_cmd, NULL);
            _exit(EXIT_FAILURE);   // exec never returns
        }
    }
}

以下是机器处于浪涌状态时的一些示例输出。只有 exec() 使用额外的 CPU。

$ test_fork 10 'exit 123'
n=10 shell_cmd=[exit 123]
fork: 41 usec, exec: 1 msec
fork: 46 usec, exec: 46586 msec
fork: 57 usec, exec: 1 msec
fork: 46 usec, exec: 12 msec
fork: 50 usec, exec: 112 msec
fork: 50 usec, exec: 1 msec
fork: 46 usec, exec: 2 msec
fork: 43 usec, exec: 1 msec
fork: 40 usec, exec: 18 msec
fork: 71 usec, exec: 1 msec

real    0m46.741s
user    0m0.005s
sys     0m13.999s
$

【问题讨论】:

  • 内存不足,进程列表已满,竞争进程太多,一切正常……
  • 我们几乎不可能用这么少的信息来判断您的系统出了什么问题……但是:Linux 2.6.32?老天爷,你考虑过升级吗?专门在那台电脑上。自该版本以来,可能修复了无数个错误。
  • 如果您在 C 程序中 nanosleep() 而不产生外部进程,17 秒的延迟是否可以重现?
  • 关于“浪涌”:CPU 是否会因为高核心/封装温度而定期节流?如果时钟频率降得太低,真的低,这或许可以解释为什么琐碎的任务突然变得如此缓慢,至少部分如此。 (dmesg、lm-sensors、/sys/devices/system/cpu/cpu0/thermal_throttle/*/sys/devices/system/cpu/cpu0/cpufreq/scaling_cur_freq 可能是您的朋友。)如果温度似乎还可以,但内存可能有问题,您可以 swapoff 所有交换设备/文件并等待查看是否有人调用了 OOM 杀手。
  • @vicky - 我监控核心温度。那里没问题。我同意,我需要看看问题是否特定于生成 shell。

标签: c linux centos kernel cpu-usage


【解决方案1】:

安装dTrace 并在您的系统遇到减速时运行类似于以下 dTrace 脚本:

#!/usr/sbin/dtrace -s

#pragma D option quiet

profile:::profile-1001hz
/ arg0 /
{
    @hot[ arg0 ] = count();
}

dtrace:::END
{
    printa( "%@u %a\n", @hot );
}

您可能需要更改 shebang。

当系统出现其中一个“情节”时运行它(可能会根据您问题中的一个时间测试程序自动启动),让它运行 10-15 秒(取出 @987654323 @如果你想查看一些细节),用键盘上的CTRL-C或进程中的SIGINT杀死它。

然后,该脚本将发出它采样的所有内核堆栈跟踪,最常见的最后出现 - 您可以在其中看到它们。

最后几个内核堆栈跟踪将告诉您内核在“情节”期间将时间花在哪里

不涉及猜测。没有复活节彩蛋狩猎。您会告诉发生了什么。

该脚本在执行zfs send ... | ... zfs receive ... 备份的过程中在 Solaris 11.4 机器上运行,显示如下:

   .
   .
   .
1729 zfs`zfs_lzjb_compress+0xcd
1834 zfs`zfs_lzjb_compress+0xe8
1883 zfs`zfs_lzjb_compress+0xf1
1991 zfs`zfs_lzjb_compress+0xbc
1994 unix`wrmsr+0xd
2015 unix`sys_syscall+0x1b9
2089 zfs`zfs_lzjb_compress+0x131
2182 zfs`zfs_lzjb_compress+0x115
2346 zfs`zfs_lzjb_compress+0x1bd
2363 zfs`zfs_lzjb_compress+0x93
2376 zfs`zfs_lzjb_compress+0x1a6
2869 unix`mutex_enter+0x10
3619 zfs`zfs_lzjb_compress+0x135
4223 zfs`zfs_lzjb_compress+0x108
5982 unix`mutex_delay_default+0xa
7480 unix`mutex_delay_default+0x7
8548 unix`bcopy+0x55a
3148971 unix`i86_mwait+0xd

请注意,在此示例中,绝大多数时间(三个数量级...)都花在空闲循环中,因为它是一个 24 核服务器,目前除了 zfs 备份之外什么都不做.几乎所有其他注意事项都涉及该备份。

【讨论】:

    猜你喜欢
    • 2017-07-15
    • 2023-04-09
    • 1970-01-01
    • 1970-01-01
    • 1970-01-01
    • 2012-10-24
    • 1970-01-01
    • 1970-01-01
    • 1970-01-01
    相关资源
    最近更新 更多