查看CPU上下文切换的命令
了解了CPU上下文切会导致系统负载升高，下面我们介绍下用linux命令查看系统CPU上下文切换信息
vmstat
# 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
4 0 0 864188 45680 761716 0 0 1 12 4 5 0 0 99 0 0
和cpu上下文切换相关的，我们需要关注四列
- r（running or runnable）就绪队列长度，正在运行和等待cpu的进程数
- b (Blocked) 处于不可中断睡眠状态的进程数
- in （interrupt）每秒中断次数
- cs（context switch）每秒上下文切换次数
上面vmstat命令给出的输出是系统总体的上下文切换
pidstat
通过pidstat可以查看详细进程的上下文切换信息
pidstat -w 1
Linux 3.10.0-693.2.2.el7.x86_64 (iz2zeab8t820b32tt9i96gz) 2019年12月13日 _x86_64_ (1 CPU)
21时32分22秒 UID PID cswch/s nvcswch/s Command
21时32分23秒 0 3 1.00 0.00 ksoftirqd/0
21时32分23秒 0 9 33.00 0.00 rcu_sched
21时32分23秒 0 10 1.00 0.00 watchdog/0
21时32分23秒 38 797 1.00 0.00 ntpd
21时32分23秒 0 10370 9.00 0.00 kworker/0:2
21时32分23秒 0 10387 1.00 0.00 sshd
21时32分23秒 0 10408 1.00 0.00 pidstat
- cswch（voluntary context switches）: 表示每秒自愿上下文切换次数
- 自愿上下文切换：进程无法获取所需自愿，导致上下文切换，比如I/O，内存等资源不足时
- nvcswch（non voluntary context switches）：表示每秒非自愿上下文切换次数
- 非自愿上下文切换：进程由于时间片到等原因，被系统强制调度，发生的上下文切换
案例分析
机器配置：2C4G，centos系统
预先安装：sysbench，sysstat
开四个终端，用于监控性能
- 通过第一个终端sysbench模拟多线程调度瓶颈
$ sysbench --threads=10 --max-time=300 threads run
- 第二个终端用vmstat监控上下文情况
# 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
8 0 0 7331532 4172 450216 0 0 15 2778 623 2142 3 3 94 0 0
4 0 0 7331532 4172 450216 0 0 0 0 35229 5074073 15 84 2 0 0
7 0 0 7331532 4172 450216 0 0 0 0 34426 4942170 14 83 3 0 0
5 0 0 7331532 4172 450216 0 0 0 0 37055 5134408 14 84 3 0 0
6 0 0 7331532 4172 450216 0 0 0 0 43965 4843946 13 83 4 0 0
9 0 0 7331532 4172 450216 0 0 0 0 31367 5100571 14 83 3 0 0
- cs上下文切换从2142 升高到了500万
- r列：就绪队列长度到了8-9，远远超过了系统CPU的个数
- us（user）和sy（system）列：这两列的CPU使用率加起来上升到了100%，其中sy列使用率达到84%说明CPU主要被内核占用
- in列：中断次数也上升到了1万左右，说明中断处理也是个潜在问题
- 第三个终端使用pidstat查看
上面vmstat输出的是系统总体的CPU上下文切换情况，我们需要用pidstat查看具体那个进程或者线程占用了CPU
pidstat -wt -u 1
Linux 3.10.0-693.el7.x86_64 (localhost.localdomain) 2019年12月13日 _x86_64_ (2 CPU)
23时05分46秒 UID TGID TID %usr %system %guest %CPU CPU Command
23时05分47秒 0 13722 - 0.00 0.99 0.00 0.99 0 kworker/0:3
23时05分47秒 0 - 13722 0.00 0.99 0.00 0.99 0 |__kworker/0:3
23时05分47秒 0 16060 - 27.72 100.00 0.00 100.00 0 sysbench
23时05分47秒 0 - 16061 1.98 16.83 0.00 18.81 0 |__sysbench
23时05分47秒 0 - 16062 2.97 15.84 0.00 18.81 1 |__sysbench
23时05分47秒 0 - 16063 3.96 16.83 0.00 20.79 1 |__sysbench
23时05分47秒 0 - 16064 2.97 16.83 0.00 19.80 0 |__sysbench
23时05分47秒 0 - 16065 1.98 14.85 0.00 16.83 1 |__sysbench
23时05分47秒 0 - 16066 3.96 15.84 0.00 19.80 1 |__sysbench
23时05分47秒 0 - 16067 1.98 16.83 0.00 18.81 1 |__sysbench
23时05分47秒 0 - 16068 2.97 15.84 0.00 18.81 1 |__sysbench
23时05分47秒 0 - 16069 1.98 17.82 0.00 19.80 0 |__sysbench
23时05分47秒 0 - 16070 2.97 15.84 0.00 18.81 1 |__sysbench
23时05分47秒 0 16075 - 0.00 0.99 0.00 0.99 0 pidstat
23时05分47秒 0 - 16075 0.00 0.99 0.00 0.99 0 |__pidstat
23时05分46秒 UID TGID TID cswch/s nvcswch/s Command
23时05分47秒 0 3 - 2.97 0.00 ksoftirqd/0
23时05分47秒 0 - 3 2.97 0.00 |__ksoftirqd/0
23时05分47秒 0 9 - 8.91 0.00 rcu_sched
23时05分47秒 0 - 9 8.91 0.00 |__rcu_sched
23时05分47秒 0 - 671 0.99 0.00 |__in:imjournal
23时05分47秒 0 669 - 9.90 0.00 vmtoolsd
23时05分47秒 0 - 669 9.90 0.00 |__vmtoolsd
23时05分47秒 0 - 1147 0.99 0.00 |__tuned
23时05分47秒 0 13670 - 0.99 0.00 kworker/u256:2
23时05分47秒 0 - 13670 0.99 0.00 |__kworker/u256:2
23时05分47秒 0 13722 - 1.98 0.00 kworker/0:3
23时05分47秒 0 - 13722 1.98 0.00 |__kworker/0:3
23时05分47秒 0 15871 - 3.96 0.00 kworker/1:3
23时05分47秒 0 - 15871 3.96 0.00 |__kworker/1:3
23时05分47秒 0 15982 - 0.99 0.00 kworker/1:1
23时05分47秒 0 - 15982 0.99 0.00 |__kworker/1:1
23时05分47秒 0 - 16061 62697.03 429596.04 |__sysbench
23时05分47秒 0 - 16062 69033.66 437688.12 |__sysbench
23时05分47秒 0 - 16063 49371.29 490245.54 |__sysbench
23时05分47秒 0 - 16064 57375.25 434861.39 |__sysbench
23时05分47秒 0 - 16065 59927.72 426571.29 |__sysbench
23时05分47秒 0 - 16066 54672.28 434754.46 |__sysbench
23时05分47秒 0 - 16067 58420.79 441480.20 |__sysbench
23时05分47秒 0 - 16068 47862.38 467382.18 |__sysbench
23时05分47秒 0 - 16069 71267.33 426084.16 |__sysbench
23时05分47秒 0 - 16070 48990.10 461634.65 |__sysbench
23时05分47秒 0 16075 - 0.99 0.00 pidstat
23时05分47秒 0 - 16075 0.99 0.00 |__pidstat
上面pidstat的输出你可以发现，CPU使用率最高的为sysbench导致，sysbench的线程上下文切换很多，看来上下文切换罪魁祸首，但是上面查看中断次数也很高
- 第四个终端查看中断次数
$ watch -d cat /proc/interrupts
...
RES: 9781574 10163271 Rescheduling interrupts
...
变化速度最快的是重调度中断(RES)，这个中断类型表示，唤醒空闲状态CPU来调度新的任务运行。这是多处理器系统（SMP）中，调度器用来分散任务到不通CPU的机制，通常也被成为 处理器间中断 (inter processor interrupts, IPI)
所以这里中断升高还是因为过多的任务调度问题
- 结论
因为sysbench较多线程使用CPU，导致大量非自愿上下文切换导致系统负载升高
小结
- 系统上下文切换从数百到一万以内，都算是正常的
- 自愿上下文切换变多了，说明进程都在等待资源，有可能发生了I/O等其他问题
- 非自愿上下文切变多了，说明进程都在被强制调度，也就是都在抢占CPU，说明CPU的确成了瓶颈
- 中断次数变多了，说明CPU被中断处理程序占用，还需要查看/proc/interroupts 文件分析具体中断类型
