Linux性能分析-CPU上下文切换
前言
在Linux性能分析-平均负载中，提到过一种导致平均负载升高的情况，就是有大量进程或线程等待cpu调度。
为什么大量进程或者线程等待CPU调度会导致负载升高呢？
当大量进程或者线程等待调度时，cpu需要更加频繁的切换任务，在切换任务的过程中，需要保存上一个任务的context到内核中，并且恢复当前任务的context，这种保存和恢复的操作也是需要cpu来执行的，导致cpu都消耗在了 保存上文和恢复下文这个过程中。
除了进程和线程导致的上下文切换以外，硬件产生的中断事件也会导致上下文切换。并且中断事件的优先级是高于线程和进程任务的。
这篇文章会模拟测试这种情况。
必备的工具介绍
vmstat
vmstat是一个观测总体上下文切换状况的命令。
下面指令可以每隔5秒输出一组数据。
[root@localhost shell]# 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
1 0 1544 1011512 4172 1674144 0 0 5 829 39 72 1 0 99 0 0
1 0 1544 1011380 4172 1674176 0 0 0 162 163 236 1 0 99 0 0
0 0 1544 1011412 4172 1674176 0 0 0 0 142 240 1 0 99 0 0
0 0 1544 1011412 4172 1674176 0 0 0 0 119 159 1 0 99 0 0
0 0 1544 1012404 4172 1674076 0 0 0 0 533 783 1 1 97 0 0
重点关注列含义：
- r列：就绪队列的长度，也就是正在运行和等待cpu的任务数
- b列：处于不可中断睡眠状态的任务数
- in列：每秒中断的次数
- cs列：每秒上下文切换的次数
pidstat
使用vmstat关注到了整体的情况，接下来可以使用pidstat关注具体线程的情况
注：pidstat -wt 可以输出线程的情况
[root@localhost shell]# pidstat -w 5
Linux 3.10.0-1062.el7.x86_64 (localhost.localdomain) 2020年07月08日 _x86_64_ (4 CPU)
13时55分20秒 UID PID cswch/s nvcswch/s Command
13时55分25秒 0 9 12.48 0.00 rcu_sched
13时55分25秒 0 11 0.20 0.00 watchdog/0
13时55分25秒 0 12 0.20 0.00 watchdog/1
13时55分25秒 0 14 0.20 0.00 ksoftirqd/1
13时55分25秒 0 17 0.20 0.00 watchdog/2
13时55分25秒 0 22 0.20 0.00 watchdog/3
13时55分25秒 0 47 0.20 0.00 khugepaged
13时55分25秒 0 378 1.39 0.00 irq/16-vmwgfx
13时55分25秒 0 501 0.20 0.00 kworker/0:1H
13时55分25秒 0 1891 12.87 0.20 X
13时55分25秒 0 2175 0.20 0.00 wpa_supplicant
13时55分25秒 0 2529 0.20 0.00 ssh-agent
13时55分25秒 0 2581 14.26 0.00 gnome-shell
13时55分25秒 0 2604 0.79 0.00 ibus-daemon
13时55分25秒 0 2668 0.20 0.00 goa-identity-se
13时55分25秒 0 2756 0.99 0.00 gsd-color
13时55分25秒 0 2847 10.10 0.00 vmtoolsd
13时55分25秒 0 2947 0.20 0.00 ibus-engine-sim
13时55分25秒 0 6206 5.74 0.00 gnome-terminal-
13时55分25秒 0 6833 0.99 0.00 kworker/1:28
13时55分25秒 0 15685 0.20 0.00 fwupd
13时55分25秒 0 24573 10.10 0.00 vmtoolsd
13时55分25秒 0 24900 1.58 0.00 rngd
13时55分25秒 0 112976 1.39 0.00 kworker/3:0
13时55分25秒 0 115704 0.79 0.00 kworker/2:2
13时55分25秒 0 116180 0.99 0.00 kworker/u256:2
13时55分25秒 0 119739 3.37 0.00 kworker/0:0
13时55分25秒 0 119809 0.59 0.00 kworker/0:3
13时55分25秒 0 119826 0.20 0.00 pidstat
重点关注列含义：
- cswch/s：自愿切换上下文。比如IO内存等系统资源不足时，任务会主动切换上下文。
- nvcswch/s：非自愿上下文切换，当大量任务等待调度时，系统会强制任务上下cpu。
实际测试
系统环境：
操作系统：centos7
cpu：4核，内存：8g
首先安装sysbench，使用sysbench，我们可以模拟一个进程内多线程调度引起的上下文切换问题。
[root@localhost shell]# yum install sysbench
安装好后，执行下面命令
[root@localhost shell]# sysbench --num-threads=20 --max-time=300 --test=threads run
查看下vmstat和pidstat
[root@localhost shell]# 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
12 0 1544 984260 4172 1700288 0 0 5 819 42 28 1 0 99 0 0
12 0 1544 984136 4172 1700288 0 0 0 2 64063 1469914 19 66 15 0 0
[root@localhost shell]# pidstat -wt 5
Linux 3.10.0-1062.el7.x86_64 (localhost.localdomain) 2020年07月08日 _x86_64_ (4 CPU)
14时10分21秒 UID TGID TID cswch/s nvcswch/s Command
14时10分26秒 0 119981 - 3.33 0.00 kworker/0:0
14时10分26秒 0 - 119981 3.33 0.00 |__kworker/0:0
14时10分26秒 0 120045 - 0.39 0.00 kworker/0:3
14时10分26秒 0 - 120045 0.39 0.00 |__kworker/0:3
14时10分26秒 0 - 120069 13182.55 57331.57 |__sysbench
14时10分26秒 0 - 120070 13993.33 50786.86 |__sysbench
14时10分26秒 0 - 120071 17088.63 59359.61 |__sysbench
14时10分26秒 0 - 120072 15789.22 53959.61 |__sysbench
14时10分26秒 0 - 120073 13882.35 53891.57 |__sysbench
14时10分26秒 0 - 120074 14793.33 46352.75 |__sysbench
14时10分26秒 0 - 120075 13281.18 55530.78 |__sysbench
14时10分26秒 0 - 120076 14189.80 56319.61 |__sysbench
14时10分26秒 0 - 120077 14870.39 52858.24 |__sysbench
14时10分26秒 0 - 120078 13928.04 57796.47 |__sysbench
14时10分26秒 0 - 120079 13780.39 56587.25 |__sysbench
14时10分26秒 0 - 120080 14157.65 55370.00 |__sysbench
14时10分26秒 0 - 120081 13403.14 54099.22 |__sysbench
14时10分26秒 0 - 120082 16154.31 50767.06 |__sysbench
14时10分26秒 0 - 120083 15907.45 48268.24 |__sysbench
14时10分26秒 0 - 120084 14213.53 49035.69 |__sysbench
14时10分26秒 0 - 120085 14125.29 55470.78 |__sysbench
14时10分26秒 0 - 120086 13912.16 54188.63 |__sysbench
14时10分26秒 0 - 120087 14980.59 49492.55 |__sysbench
14时10分26秒 0 - 120088 15290.39 55748.24 |__sysbench
14时10分26秒 0 120102 - 0.20 1.18 pidstat
14时10分26秒 0 - 120102 0.20 1.18 |__pidstat
[root@localhost shell]# pidstat -u 5 5
Linux 3.10.0-1062.el7.x86_64 (localhost.localdomain) 2020年07月08日 _x86_64_ (4 CPU)
14时31分22秒 UID PID %usr %system %guest %CPU CPU Command
14时31分27秒 0 1891 0.40 0.00 0.00 0.40 0 X
14时31分27秒 0 2581 0.80 0.20 0.00 1.00 0 gnome-shell
14时31分27秒 0 120701 69.26 100.00 0.00 100.00 2 sysbench
14时31分27秒 0 120722 0.00 0.20 0.00 0.20 1 pidstat
14时31分27秒 UID PID %usr %system %guest %CPU CPU Command
14时31分32秒 0 1891 0.40 0.20 0.00 0.60 0 X
14时31分32秒 0 2581 0.80 0.20 0.00 1.00 1 gnome-shell
14时31分32秒 0 6206 0.00 0.20 0.00 0.20 0 gnome-terminal-
14时31分32秒 0 120701 70.20 100.00 0.00 100.00 2 sysbench
14时31分32秒 0 120722 0.20 0.20 0.00 0.40 1 pidstat
观察vmstat结果，可以看到
- 系统整体的cs列和in列都发生了显著的提高。
- cpu使用率，用户进程使用率us=19% 和系统进程使用率sy=66%，加起来达到了85%，并且sy占用了大头，说明更多的cpu消耗在了运行系统进程。
观察pidstat两类结果，可以发现
- sysbench进程下的子线程，cswsh和nvcswsh的数值都很高，其中非自愿切换次数远大于自愿切换次数。
- %user（该进程在用户空间对cpu的使用率）和%system（该进程在系统空间对cpu的使用率）更是达到了70.20和100.00，说明系统资源大部分都被这个进程所占用。
整体结果符合我们的预期。
针对in列显著提高，可以查看 /proc/interrupts 文件，里面记录了中断相关的数据，这些数据记录的是从上次启动到现在的累加值。
我们把系统重新启动下，看下空闲状态下的文件
NMI: 0 0 0 0 Non-maskable interrupts
LOC: 28984 32366 32128 34741 Local timer interrupts
SPU: 0 0 0 0 Spurious interrupts
PMI: 0 0 0 0 Performance monitoring interrupts
IWI: 353 420 266 154 IRQ work interrupts
RTR: 0 0 0 0 APIC ICR read retries
RES: 24371 25023 24748 22077 Rescheduling interrupts
CAL: 6516 7288 6917 7134 Function call interrupts
TLB: 1706 1874 1598 1534 TLB shootdowns
TRM: 0 0 0 0 Thermal event interrupts
THR: 0 0 0 0 Threshold APIC interrupts
DFR: 0 0 0 0 Deferred Error APIC interrupts
MCE: 0 0 0 0 Machine check exceptions
MCP: 2 2 2 2 Machine check polls
ERR: 0
MIS: 0
PIN: 0 0 0 0 Posted-interrupt notification event
NPI: 0 0 0 0 Nested posted-interrupt event
PIW: 0 0 0 0 Posted-interrupt wakeup event
当执行sysbench命令后，并运行一段时间后，该文件如下
NMI: 0 0 0 0 Non-maskable interrupts
LOC: 90200 96701 93600 97704 Local timer interrupts
SPU: 0 0 0 0 Spurious interrupts
PMI: 0 0 0 0 Performance monitoring interrupts
IWI: 616 666 505 450 IRQ work interrupts
RTR: 0 0 0 0 APIC ICR read retries
RES: 1028166 1012515 1035222 1028515 Rescheduling interrupts
CAL: 6526 7306 6963 7134 Function call interrupts
TLB: 1753 1946 1680 1661 TLB shootdowns
TRM: 0 0 0 0 Thermal event interrupts
THR: 0 0 0 0 Threshold APIC interrupts
DFR: 0 0 0 0 Deferred Error APIC interrupts
MCE: 0 0 0 0 Machine check exceptions
MCP: 3 3 3 3 Machine check polls
ERR: 0
MIS: 0
PIN: 0 0 0 0 Posted-interrupt notification event
NPI: 0 0 0 0 Nested posted-interrupt event
PIW: 0 0 0 0 Posted-interrupt wakeup event
其中，LOC和RES显著升高
RES表示，唤醒空闲状态的CPU来调度新的任务运行，和我们模拟的过多任务调度有关。
LOC不太理解，暂时先放在这里。
