如何分析上下文切换问题

2023-02-08  本文已影响0人  _Irving

vmstat

vmstat是一个常用的系统性能分析工具,主要用来分析系统的内存使用情况,也常用来分析cpu上下文切换和中断次数

[wanchao@localhost ~]$ 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
 3  0      0 1168240    932 531912    0    0     7  1034   65  667  2  2 96  1  0
 0  0      0 1168240    932 531912    0    0     0    37   36   65  0  0 100  0  0
 0  0      0 1168240    932 531912    0    0     0     5   41   74  0  0 100  0  0

pidstat

vmstat只给出了系统总体的上下文切换情况,要想查看每个进程的详细情况,就需要使用我们前面提到过的pidstat了。给它加上 -w选项,你就可以查看每个进程上下文切换的情况

[wanchao@localhost ~]$ pidstat -w 5    #每隔5秒输出一组数据
Linux 3.10.0-327.el7.x86_64 (localhost.localdomain)     02/08/23    _x86_64_    (1 CPU)

18:53:59      UID       PID   cswch/s nvcswch/s  Command
18:54:04        0         3      0.37      0.00  ksoftirqd/0
18:54:04        0       137      1.69      0.00  rcu_sched
18:54:04        0       138      1.12      0.00  rcuos/0
18:54:04        0       266      0.19      0.00  watchdog/0
18:54:04        0       825      0.19      0.00  auditd
18:54:04        0       847      9.93      0.00  vmtoolsd
18:54:04        0       884      0.94      0.00  rngd
18:54:04        0       897      0.19      0.00  crond
18:54:04        0     62042      0.94      0.00  kworker/u256:2
18:54:04        0     62864      2.06      0.19  kworker/0:0
18:54:04        0     62884      0.75      0.00  kworker/0:2H
18:54:04     1000     62885      0.19      0.00  pidstat

案例分析

上面的vmstat执行结果便是空闲系统的上下文切换次数,cs是在70左右,in是40左右

1、使用sysbench模拟上下文切换过多的问题,以十个线程运行5分钟的基准测试,模拟多线程切换的问题

[wanchao@localhost ~]$ sysbench --threads=10 --max-time=300 threads run
WARNING: --max-time is deprecated, use --time instead
sysbench 1.0.20 (using bundled LuaJIT 2.1.0-beta2)
Running the test with following options:
Number of threads: 10
Initializing random number generator from current time
Initializing worker threads...
Threads started!

2、 使用vmstat,观察上下文切换情况:

[root@localhost ~]# 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
 9  0      0 1158132    932 532396    0    0     7   985   64  449  2  2 96  1  0
 6  0      0 1158008    932 532396    0    0     0     0  158 2345591 11 89  0  0  0
 8  0      0 1156524    932 532468    0    0     0     0  113 1525236 11 89  0  0  0
 9  0      0 1156508    932 532468    0    0     0     0  147 2359798 14 86  0  0  0

1、 cs列:上下文切换次数从70骤然上升到234万
2、 r列:就绪队列的长度已经到了9,远远超过了系统的cpu个数1,所有就会有大量的cpu竞争
3、 us(user)和sy (system)列:这两列的cpu使用率加起来上升到了100%,其中系统使用率也就是sy列高达89%,说明cpu主要被内核占用了
4、 in列:中断次数300左右,不是很高
综合这几个指标,我们可以知道,系统的就绪队列过长,也就是正在运行和等待cpu的进程数过多,导致了大量的上下文切换,而上下文切换又导致了系统的cpu占用率升高

3、 继续分析,使用pidstat看一下cpu和进程的上下文切换情况:

#-w参数表示输出进程切换指标,而-u参数则表示输出cpu使用指标
[root@localhost ~]# pidstat -w -u 1
19:40:25      UID       PID    %usr %system  %guest   %wait    %CPU   CPU  Command
19:40:26     1000     63139   14.85   91.09    0.00    0.00  105.94     0  sysbench
19:40:26        0     63151    0.00    1.98    0.00    0.00    1.98     0  pidstat

19:40:25      UID       PID   cswch/s nvcswch/s  Command
19:40:26        0       137      1.98      0.00  rcu_sched
19:40:26        0       138      1.98      0.00  rcuos/0
19:40:26        0       847      9.90      0.00  vmtoolsd
19:40:26        0       884      0.99      0.00  rngd
19:40:26        0     62042      0.99      0.00  kworker/u256:2
19:40:26     1000     62972      2.97      0.00  sshd
19:40:26        0     63105    205.94      0.00  kworker/0:0
19:40:26        0     63151      0.99    204.95  pidstat

从pidstat的输出可以发现,使用率的升高是sysbench导致的,它的cpu使用率已经达到100%。但上下文切换则是来自其他进程,包括非自愿上下文切换频率最高的pidstat,以及自愿上下文切换频率最高的内核线程kworker

4、上面的pidstat -w是默认显示的进程指标数据,而sysbench模拟的是线程调度问题,所以上面显示cswch和nvcswch才仅仅有几百,和vmstat的几百万次相差甚远。pidstat加上-t参数,就可以输出线程指标:

#
[wanchao@localhost ~]$  pidstat -wt -u 5
Linux 3.10.0-327.el7.x86_64 (localhost.localdomain)     02/08/23    _x86_64_    (1 CPU)
21:30:31      UID      TGID       TID    %usr %system  %guest   %wait    %CPU   CPU  Command
21:30:37     1000     63306         -    6.15   83.73    0.00    0.00   89.87     0  sysbench
21:30:37     1000         -     63307    1.08    8.32    0.00    0.00    9.40     0  |__sysbench
21:30:37     1000         -     63308    0.54    8.68    0.00    0.00    9.22     0  |__sysbench
21:30:37     1000         -     63309    0.54    8.14    0.00    0.00    8.68     0  |__sysbench
21:30:37     1000         -     63310    0.54    8.32    0.00    0.00    8.86     0  |__sysbench
21:30:37     1000         -     63311    0.36    8.68    0.00    0.00    9.04     0  |__sysbench
21:30:37     1000         -     63312    1.08    8.14    0.00    0.00    9.22     0  |__sysbench
21:30:37     1000         -     63313    0.54    8.68    0.00    0.00    9.22     0  |__sysbench
21:30:37     1000         -     63314    0.36    8.32    0.00    0.00    8.68     0  |__sysbench
21:30:37     1000         -     63315    0.54    8.14    0.00    0.00    8.68     0  |__sysbench
21:30:37     1000         -     63316    0.54    8.50    0.00    0.00    9.04     0  |__sysbench
21:30:37        0     63320         -    0.18    0.54    0.00    0.00    0.72     0  pidstat
21:30:37        0         -     63320    0.18    0.54    0.00    0.00    0.72     0  |__pidstat
21:30:31      UID      TGID       TID   cswch/s nvcswch/s  Command
21:30:37     1000         -     62930      0.18      0.00  |__sshd
21:30:37        0     63195         -      1.99      0.00  kworker/0:0
21:30:37        0         -     63195      1.99      0.00  |__kworker/0:0
21:30:37     1000     63306     63307   9937.43  82584.81  (sysbench)__sysbench
21:30:37     1000         -     63308  11930.02  77856.96  |__sysbench
21:30:37     1000         -     63309  12277.03  78040.51  |__sysbench
21:30:37     1000         -     63310  11256.60  79153.16  |__sysbench
21:30:37     1000         -     63311   9369.62  85189.69  |__sysbench
21:30:37     1000         -     63312   8365.28  85014.65  |__sysbench
21:30:37     1000         -     63313  10202.53  80580.11  |__sysbench
21:30:37     1000         -     63314  11838.70  78823.15  |__sysbench
21:30:37     1000         -     63315  13387.16  75047.38  |__sysbench
21:30:37     1000         -     63316  10794.03  82640.14  |__sysbench
21:30:37        0     63317         -      0.18      0.00  vmstat
21:30:37        0         -     63317      0.18      0.00  |__vmstat
21:30:37        0     63320         -      0.18      0.54  pidstat
21:30:37        0         -     63320      0.18      0.54  |__pidstat

这里我们就可以看到,上下文切换的罪魁祸首就是sysbench线程。

5、 前面虽然我们看到的中断次数不多,但是仍然是有增加,这里提供一个分析中断次数上升的方法,就是从/proc/interrupts这个只读文件中读取。/proc实际上是linux的一个虚拟文件系统,用于内核空间与用户空间之间的通信。/proc/interrupts就是这种通信机制的一部分,提供了一个只读的中断使用情况。

 -d 参数表示高亮显示变化区域
[wanchao@localhost ~]$ watch -d cat /proc/interrupts
          CPU0       
 19:      73600   IO-APIC-fasteoi   eno16777736

这里变化最快的是是网卡,因为没有中断次数过多的异常,且由于我的环境只有一个cpu,不是多处理其系统(调度器用来分散任务到不同cpu的机制),不然就可以模拟出次此中断原因,通常也被称为处理器间中断(Inter-Processor Interrupts,IPI),这里只是提供一个分析思路。

通过这个案例,发现了多工具、多方面指标对比观测的好处,那么每秒上下文切换多少次才算正常呢?这个数值其实取决于系统本身的cpu性能。如果系统的上下文切换次数比较稳定,那么从数百到一万以内,都应该算是正常的。但当上下文切换次数超过一万次,户或者切换次数出现数量级增长时,就可能出现性能问题

补充:

上一篇下一篇

猜你喜欢

热点阅读