linux cpu性能调优套路（一）

左手的ㄟ右手 2023-02-14 07:53 8阅读 0赞

uptime 发现平均负载升高

\# -d 参数表示高亮显示变化的区域

$ watch -d uptime
    ...,  load average: 1.00, 0.75, 0.39

mpstat可查看各个CPU核心的使用率

# -P ALL 表示监控所有CPU，后面数字5表示间隔5秒后输出一组数据
    $ mpstat -P ALL 5
    Linux 4.15.0 (ubuntu) 09/22/18 _x86_64_ (2 CPU)
    13:30:06     CPU    %usr   %nice    %sys %iowait    %irq   %soft  %steal  %guest  %gnice   %idle
    13:30:11     all   50.05    0.00    0.00    0.00    0.00    0.00    0.00    0.00    0.00   49.95
    13:30:11       0    0.00    0.00    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00
    13:30:11       1  100.00    0.00    0.00    0.00    0.00    0.00    0.00    0.00    0.00    0.00

但是最重要的是用pidstat定位到具体的进程。到底是哪些进程让平均负载升高。

场景一： CPU 密集型进程

# 间隔5秒后输出一组数据
    $ pidstat -u 5 1
    13:37:07      UID       PID    %usr %system  %guest   %wait    %CPU   CPU  Command
    13:37:12        0      2962  100.00    0.00    0.00    0.00  100.00     1  stress

%usr很高，说明是程序代码里面出现运行在用户态的进程一直在执行。比如where(1);  
此种情况是单进程用户态占用资源很多的情况。也就是极客时间教程上的 CPU 密集型进程

场景二：I/O 密集型进程

# 间隔5秒后输出一组数据，-u表示CPU指标
    $ pidstat -u 5 1
    Linux 4.15.0 (ubuntu)     09/22/18     _x86_64_    (2 CPU)
    13:42:08      UID       PID    %usr %system  %guest   %wait    %CPU   CPU  Command
    13:42:13        0       104    0.00    3.39    0.00    0.00    3.39     1  kworker/1:1H
    13:42:13        0       109    0.00    0.40    0.00    0.00    0.40     0  kworker/0:1H
    13:42:13        0      2997    2.00   35.53    0.00    3.99   37.52     1  stress
    13:42:13        0      3057    0.00    0.40    0.00    0.00    0.40     0  pidstat

此种场景%usr很低，%sys较高， 说明该进程在内核态运行较长，导致平均负载升高。  
再用mpstat 查看到时iowait很高，说明%sys升高的原因是在等待io。

# 显示所有CPU的指标，并在间隔5秒输出一组数据
    $ mpstat -P ALL 5 1
    Linux 4.15.0 (ubuntu)     09/22/18     _x86_64_    (2 CPU)
    13:41:28     CPU    %usr   %nice    %sys %iowait    %irq   %soft  %steal  %guest  %gnice   %idle
    13:41:33     all    0.21    0.00   12.07   32.67    0.00    0.21    0.00    0.00    0.00   54.84
    13:41:33       0    0.43    0.00   23.87   67.53    0.00    0.43    0.00    0.00    0.00    7.74
    13:41:33       1    0.00    0.00    0.81    0.20    0.00    0.00    0.00    0.00    0.00   98.99

场景三：大量进程等待运行

# 间隔5秒后输出一组数据
    $ pidstat -u 5 1
    14:23:25      UID       PID    %usr %system  %guest   %wait    %CPU   CPU  Command
    14:23:30        0      3190   25.00    0.00    0.00   74.80   25.00     0  stress
    14:23:30        0      3191   25.00    0.00    0.00   75.20   25.00     0  stress
    14:23:30        0      3192   25.00    0.00    0.00   74.80   25.00     1  stress
    14:23:30        0      3193   25.00    0.00    0.00   75.00   25.00     1  stress
    14:23:30        0      3194   24.80    0.00    0.00   74.60   24.80     0  stress
    14:23:30        0      3195   24.80    0.00    0.00   75.00   24.80     0  stress
    14:23:30        0      3196   24.80    0.00    0.00   74.60   24.80     1  stress
    14:23:30        0      3197   24.80    0.00    0.00   74.80   24.80     1  stress
    14:23:30        0      3200    0.00    0.20    0.00    0.20    0.20     0  pidstat

%usr+ %system已经等于200%，两核cpu已经跑满。但%wait很高，说明大家都在等待。说明本主机已经运行了超过他自身太多的任务。需要加配置了。或者降低每个进程的%use

场景四：大量切换上下文导致平均负载升高

# 每隔1秒输出1组数据（需要 Ctrl+C 才结束）
    # -w参数表示输出进程切换指标，而-u参数则表示输出CPU使用指标
    $ pidstat -u 1
    08:06:33      UID       PID    %usr %system  %guest   %wait    %CPU   CPU  Command
    08:06:34        0     10488   30.00  100.00    0.00    0.00  100.00     0  sysbench
    08:06:34        0     26326    0.00    1.00    0.00    0.00    1.00     0  kworker/u4:2

此种场景%usr很低，%sys较高， 说明该进程在内核态运行较长，导致平均负载升高。  
此种场景类似场景二，但是我们用mpstat却看不到iowait升高（具体没使用来查看）  
那么久用另一个工具vmstat来分析%sys较高的原因：

# 每隔1秒输出1组数据（需要Ctrl+C才结束）
    $ vmstat 1
    procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
     r  b   swpd   free   buff  cache      si   so    bi    bo   in    cs      us sy id wa st
     6  0      0 6487428 118240 1292772    0    0     0     0    9019  1398830 16 84  0  0  0
     8  0      0 6487428 118240 1292772    0    0     0     0    10191 1392312 16 84  0  0  0

cs（context switch）是每秒上下文切换的次数。  
in（interrupt）则是每秒中断的次数。  
r（Running or Runnable）是就绪队列的长度，也就是正在运行和等待 CPU 的进程数。  
b（Blocked）则是处于不可中断睡眠状态的进程数。

cs 列的上下文切换次数从之前的 35 骤然上升到了 139 万。  
r 列：就绪队列的长度已经到了 8，远远超过了系统 CPU 的个数 2，所以肯定会有大量的 CPU 竞争。  
us（user）和 sy（system）列：这两列的 CPU 使用率加起来上升到了 100%，其中系统 CPU 使用率，也就是 sy 列高达 84%，说明 CPU 主要是被内核占用了。  
in 列：中断次数也上升到了 1 万左右，说明中断处理也是个潜在的问题。

这时候需要再分析具体是哪个进程切换上下文这么频繁导致平均负载升高  
那么还是需要使用pidstat工具，只是现在要加上-w选项。

# 每隔1秒输出1组数据（需要 Ctrl+C 才结束）
    # -w参数表示输出进程切换指标，而-u参数则表示输出CPU使用指标
    $ pidstat -w -u 1
    08:06:33      UID       PID    %usr %system  %guest   %wait    %CPU   CPU  Command
    08:06:34        0     10488   30.00  100.00    0.00    0.00  100.00     0  sysbench
    08:06:34        0     26326    0.00    1.00    0.00    0.00    1.00     0  kworker/u4:2
    
    08:06:33      UID       PID   cswch/s nvcswch/s  Command
    08:06:34        0         8     11.00      0.00  rcu_sched
    08:06:34        0        16      1.00      0.00  ksoftirqd/1
    08:06:34        0       471      1.00      0.00  hv_balloon
    08:06:34        0      1230      1.00      0.00  iscsid
    08:06:34        0      4089      1.00      0.00  kworker/1:5
    08:06:34        0      4333      1.00      0.00  kworker/0:3
    08:06:34        0     10499      1.00    224.00  pidstat
    08:06:34        0     26326    236.00      0.00  kworker/u4:2
    08:06:34     1000     26784    223.00      0.00  sshd

cswch  ，表示每秒自愿上下文切换（voluntary context switches）的次数，  
nvcswch  ，表示每秒非自愿上下文切换（non voluntary context switches）的次数。  
这两个概念你一定要牢牢记住，因为它们意味着不同的性能问题：  
所谓自愿上下文切换，是指进程无法获取所需资源，导致的上下文切换。比如说， I/O、内存等系统资源不足时，就会发生自愿上下文切换。  
而非自愿上下文切换，则是指进程由于时间片已到等原因，被系统强制调度，进而发生的上下文切换。比如说，大量进程都在争抢 CPU 时，就容易发生非自愿上下文切换。

从 pidstat 的输出你可以发现，CPU 使用率的升高果然是 sysbench 导致的，  
它的 CPU 使用率已经达到了 100%。但上下文切换则是来自其他进程，包括非自愿上下文切换频率最高的 pidstat   
 ，以及自愿上下文切换频率最高的内核线程 kworker 和 sshd。  
不过，细心的你肯定也发现了一个怪异的事儿：pidstat 输出的上下文切换次数，加起来也就几百，  
比 vmstat 的 139 万明显小了太多。这是怎么回事呢？难道是工具本身出了错吗？

原因：vmstat 命令展示的包括了线程上下文切换。而-w选项仅展示进程上下文切换。  
此时要排查，就需要再加上-t选项；

# 每隔1秒输出一组数据（需要 Ctrl+C 才结束）
    # -wt 参数表示输出线程的上下文切换指标
    $ pidstat -wt 1
    08:14:05      UID      TGID       TID   cswch/s nvcswch/s  Command
    ...
    08:14:05        0     10551         -      6.00      0.00  sysbench
    08:14:05        0         -     10551      6.00      0.00  |__sysbench
    08:14:05        0         -     10552  18911.00 103740.00  |__sysbench
    08:14:05        0         -     10553  18915.00 100955.00  |__sysbench
    08:14:05        0         -     10554  18827.00 103954.00  |__sysbench

...

此时即可发现，那么多上下文切换的具体进程，就是sysbench。  
在此排查过程中，还有个是观察/proc/interrupts。 watch -d cat /proc/interrupts这里没看懂，先记录一下。  
还有个知识点是查看cpu核数。在/proc/cpuinfo文件中可查看。

\----------------------------------------------------------------------------------------------------------------  
总结：  
场景1：%usr很高，%sys很低：%usr仅一个进程使用很高。说明程序代码有问题，可能有如where(1)的代码  
场景2：%usr很低 %syst很高：说明进程在内核态执行比较耗时，再通过mpstat 分析出进程在内核态耗时的原因是iowait  
场景3： %usr很高 %sys很低，但%usr很高的进程很多，且均分。其中 %wait 很高，说明大量进程在等待执行。说明很多本主机已经运行了超过他自身太多的任务。需要加配置了。或者降低每个进程的%use  
场景4：%usr很低 %syst很高：mpstat却看不到iowait升高，vmstat发现上下文切换每秒100多万次。再借助pidstat -wt选项，定位到具体的进程，内部的线程上下文切换过于频繁导致。

那么现在，我们进一步分析场景一：%usr很高，%sys很低：%usr仅一个进程使用很高。分析该进程是哪个函数执行过多导致的。  
通过 top、ps、pidstat 等工具，能够轻松找到 CPU 使用率较高（比如 100% ）的进程。  
接下来：通过perf top分析占用 CPU 的到底是代码里的哪个函数。

$ perf top
    Samples: 833  of event 'cpu-clock', Event count (approx.): 97742399
    Overhead  Shared Object       Symbol
       7.28%  perf                [.] 0x00000000001f78a4
       4.72%  [kernel]            [k] vsnprintf
       4.32%  [kernel]            [k] module_get_kallsym
       3.65%  [kernel]            [k] _raw_spin_unlock_irqrestore

...

分别是采样数（Samples）、事件类型（event）和事件总数量（Event count）。  
比如这个例子中，perf 总共采集了 833 个 CPU 时钟事件，而总事件数则为 97742399。  
第一列 Overhead ，是该符号的性能事件在所有采样中的比例，用百分比来表示。  
第二列 Shared ，是该函数或指令所在的动态共享对象（Dynamic Shared Object），如内核、进程名、动态链接库名、内核模块名等。  
第三列 Object ，是动态共享对象的类型。比如 \[.\] 表示用户空间的可执行程序、或者动态链接库，而 \[k\] 则表示内核空间。  
最后一列 Symbol 是符号名，也就是函数名。当函数名未知时，用十六进制的地址来表示。

第二种常见用法，也就是 perf record 和 perf report。   
perf top 虽然实时展示了系统的性能信息，但它的缺点是并不保存数据，也就无法用于离线或者后续的分析。  
而 perf record 则提供了保存数据的功能，保存后的数据，需要你用 perf report 解析展示。

$ perf record # 按Ctrl+C终止采样
    [ perf record: Woken up 1 times to write data ]
    [ perf record: Captured and wrote 0.452 MB perf.data (6093 samples) ]

$ perf report \# 展示类似于perf top的报告

在实际使用中，我们还经常为 perf top 和 perf record 加上 -g 参数，开启调用关系的采样，方便我们根据调用链来分析性能问题。

场景五： top发现CPU使用率高，

$ top
    ...
    %Cpu0  : 98.7 us,  1.3 sy,  0.0 ni,  0.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
    %Cpu1  : 99.3 us,  0.7 sy,  0.0 ni,  0.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
    ...
      PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
    21514 daemon    20   0  336696  16384   8712 R  41.9  0.2   0:06.00 php-fpm
    21513 daemon    20   0  336696  13244   5572 R  40.2  0.2   0:06.08 php-fpm
    21515 daemon    20   0  336696  16384   8712 R  40.2  0.2   0:05.67 php-fpm
    21512 daemon    20   0  336696  13244   5572 R  39.9  0.2   0:05.87 php-fpm
    21516 daemon    20   0  336696  16384   8712 R  35.9  0.2   0:05.61 php-fpm

可看到都是Php-fpm导致，  
于是开始分析php-fpm，任一进程都可

\# -g开启调用关系分析，-p指定php-fpm的进程号21515  
$ perf top -g -p 21515自己试验：  
写一个a.go

package main
    
    import(
            "fmt"
    )
    
    func hahah(a int) int {
            fmt.Println("haaa")
            return a+3;
    
    }
    
    func test(a int) int {
            return hahah(a);
    }
    
    func main() {
            a:=3
            for ;; {
               a = test(a);
            }
    
            return ;
    }

注意：不能使用go run a.go。这样会解析不出函数名  
需要编译成2进制文件运行才行。  
go build a.go  
./a

[root@portal-1 ~]# top
    top - 20:32:58 up 39 days,  8:31,  2 users,  load average: 0.80, 0.72, 0.77
    Tasks: 143 total,   2 running, 141 sleeping,   0 stopped,   0 zombie
    %Cpu(s): 18.8 us, 34.4 sy,  0.0 ni, 43.8 id,  0.0 wa,  0.0 hi,  0.0 si,  3.1 st
    KiB Mem :  3880260 total,  1468728 free,   325460 used,  2086072 buff/cache
    KiB Swap:  4063228 total,  4055036 free,     8192 used.  3074000 avail Mem
    
      PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
    22137 root      20   0    3148    748    468 S  87.5  0.0   0:01.80 a
     2732 root      20   0  153340   6180   4328 R   6.2  0.2   0:09.55 sshd

可观察到a的cpu使用率87.5  
pid可观察到a的使用率较高。

[root@portal-1 ~]# pidstat  5 1
    Linux 3.10.0-1062.4.1.el7.x86_64 (portal-1)     06/01/2020      _x86_64_        (2 CPU)
    
    08:38:01 PM   UID       PID    %usr %system  %guest    %CPU   CPU  Command
    08:38:06 PM     0     10397    5.59    8.58    0.00   14.17     0  a
    08:38:06 PM     0     11760    0.00    0.20    0.00    0.20     1  pidstat

然后使用perf top -g -p 21515  
或者是perf的离线分析方法，这里我都使用过。如下：可知使用率最高的main函数占用 cpu最高这是正常的，因为main函数一直在运行。  
然后分析得到各函数CPU占用情况。通过代码即可分析找到CPU占用率很高的原因

-   91.95%     0.60%  a        a                  [.] main.main                                                                                                     ▒
       - 91.36% main.main                                                                                                                                               ▒
          - 91.24% main.test                                                                                                                                            ▒
             - 90.78% main.hahah                                                                                                                                        ▒
                - 90.17% fmt.Println                                                                                                                                    ▒
                   - 89.59% fmt.Fprintln                                                                                                                                ▒
                      + 83.52% os.(*File).Write                                                                                                                         ▒
                      + 1.89% fmt.(*pp).doPrintln                                                                                                                       ▒
                      + 1.52% fmt.(*pp).free