一、实际生产中如何查看系统的上下文切换
在之前的博客中提到过多的上下文切换,会把 CPU 时间消耗在寄存器、内核栈以及虚拟内存等数据的保存和恢复上,缩短进程真正运行的时间,成了系统性能大幅下降的一个元凶。
由于上下文切换对系统性能影响非常大,我们可以使用 vmstat 这个工具,来查询系统的上下文切换情况。
vmstat 是一个常用的系统性能分析工具,主要用来分析系统的内存使用情况,也常用来分析 CPU 上下文切换和中断的次数。
下面是一个vmstat的使用案例:
lighthouse@VM-24-16-ubuntu:~$ vmstat
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 237732 100776 1350836 0 0 27 107 24 10 1 1 98 0 0
对于上下文切换这一块,我们重点要关注以下几列的数据:
procs(进程)
r(Running or Runnable)是就绪队列的长度,也就是正在运行和等待 CPU 的进程数。
b(Blocked)则是处于不可中断睡眠状态的进程数。
system(系统)
cs(context switch)是每秒上下文切换的次数。
in(interrupt)则是每秒中断的次数。
根据上面的案例我们可以得到下面的数据:
就绪队列等待CPU的进程数为3
不可中断的进程数为0
每秒的上下文切换次数为10
每秒的中断次数为24
vmstat 只给出了系统总体的上下文切换情况,要想查看每个进程的详细情况,就需要使用我们前面提到过的 pidstat 了。给它加上 -w 选项,你就可以查看每个进程上下文切换的情况了。
pidstat的案例:
# 每隔5秒输出1组数据
lighthouse@VM-24-16-ubuntu:~$ pidstat -w 5
Linux 5.15.0-106-generic (VM-24-16-ubuntu) 06/07/2024 _x86_64_ (2 CPU)
09:29:30 AM UID PID cswch/s nvcswch/s Command
09:29:35 AM 0 1 0.20 0.00 systemd
09:29:35 AM 0 13 2.59 0.00 ksoftirqd/0
09:29:35 AM 0 14 30.74 0.00 rcu_sched
09:29:35 AM 0 15 2.00 0.00 migration/0
09:29:35 AM 0 21 1.60 0.00 migration/1
09:29:35 AM 0 22 4.99 0.00 ksoftirqd/1
09:29:35 AM 0 31 2.00 0.00 kcompactd0
09:29:35 AM 0 33 0.40 0.00 khugepaged
09:29:35 AM 0 90 0.40 0.00 kworker/0:1H-kblockd
09:29:35 AM 0 105 1.20 0.00 kworker/1:1H-kblockd
重点关注的数据:
一个是 cswch ,表示每秒自愿上下文切换(voluntary context switches)的次数
另一个则是 nvcswch ,表示每秒非自愿上下文切换(non voluntary context switches)的次数。
上面提到的两个概念我们要弄清楚是什么,可以帮我们后面更好的学习。
所谓自愿上下文切换,是指进程无法获取所需资源,导致的上下文切换。比如说, I/O、内存等系统资源不足时,就会发生自愿上下文切换。(资源不足,就进行自愿上下文切换)
而非自愿上下文切换,则是指进程由于时间片已到等原因,被系统强制调度,进而发生的上下文切换。比如说,大量进程都在争抢 CPU 时,就容易发生非自愿上下文切换。(系统强制调用,就是非自愿上下文切换)
二、案例分析
学完了以上的基础概念之后,我们就需要进行一个案例的实践,通过实践来进行分析和处理。
案例工具
sysbench sysstat
注:需要安装以上两个工具才能进行案例实践,不同操作系统有可能包名不一样,请自行查找。
工具介绍
Sysbench
Sysbench 是一个开源的模块化、跨平台的性能测试工具,主要用于评估和分析数据库和系统性能。它最初被设计为MySQL的基准测试工具,但随着时间的发展,它的功能已经扩展到支持多种数据库系统(如PostgreSQL、SQLite等)以及非数据库相关的系统性能测试,比如CPU、内存、线程、文件I/O等。
主要特点:
模块化设计:Sysbench包含多个模块,允许用户根据需求选择测试场景,包括CPU运算、内存操作、线程、I/O读写和数据库事务处理等。
灵活的配置:提供丰富的参数配置选项,用户可以自定义测试的并发数、运行时间、测试数据大小等,以模拟不同的负载情况。
跨平台:支持Linux、FreeBSD、Solaris等多种操作系统。
数据库性能测试:特别适合于数据库的性能评测,能够模拟真实世界中的查询、插入、更新和删除操作。
报告生成:测试完成后,Sysbench会生成详细的测试报告,包括吞吐量、响应时间等关键性能指标,帮助用户分析系统瓶颈。
Sysstat
Sysstat 是另一个非常有用的系统性能监控工具套件,它主要包括两个核心工具:sar(System Activity Reporter)和iostat,用于收集和报告系统活动信息,如CPU使用率、内存使用情况、磁盘I/O统计、网络流量等。
主要组件及功能:
sar:定期收集并报告系统活动信息,包括CPU负载、内存使用、磁盘I/O、进程统计等。通过sar,管理员可以回顾过去的系统状态,诊断系统问题或进行容量规划。
iostat:专门针对I/O子系统的性能监控工具,提供磁盘读写操作的详细统计信息,如每秒传输的块数量、读写请求的等待时间等,对于识别I/O瓶颈尤其有用。
长期数据收集:Sysstat可以配置为定期收集数据,并将这些数据存储在日志文件中,供后续分析使用。
实时监控与历史数据分析:既支持实时查看系统状态,也允许用户通过分析历史数据来发现趋势和异常。
总结
sysbench和sysstat是Linux环境下不可或缺的性能测试与监控工具。sysbench擅长于主动施压,模拟高负载场景来评估系统的极限性能,特别适用于数据库和系统整体的压力测试。而sysstat则更侧重于被动监控,通过收集系统运行时的各种指标,帮助用户理解系统的日常运行状况,及时发现并解决性能问题。两者结合使用,可以为系统管理员和开发者提供全面的性能优化和故障排查能力。
实践
我们先使用vmstat的命令查看当前服务器的上下文切换状态
lighthouse@VM-24-16-ubuntu:~$ vmstat
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
0 0 0 211036 100808 1364564 0 0 27 107 26 14 1 1 98 0 0
可以得到进程中的r就绪队列和b不可中断的进程数为0
cs:上下文切换次数是14次每秒
in:中断次数是26次每秒
我们现在重新新建一个窗口,使用sysbench ,模拟系统多线程调度的瓶颈:
# 以10个线程运行5分钟的基准测试,模拟多线程切换的问题
lighthouse@VM-24-16-ubuntu:~$ sysbench --threads=10 --max-time=300 threads run
接着在第二个终端中使用vmstat去查看当前的上下文切换次数:
#每秒获取一次上下文切换的情况,需要Ctrl+C才结束)
lighthouse@VM-24-16-ubuntu:~$ 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 238708 100808 1332980 0 0 27 107 28 15 1 1 98 0 0
6 0 0 238708 100808 1332984 0 0 0 4 13151 715508 31 63 5 0 0
8 0 0 238708 100808 1332984 0 0 0 44 12286 826789 28 70 2 0 0
8 0 0 238708 100808 1332984 0 0 0 0 12203 721058 31 65 4 0 0
这个时候我们观察到就绪队列r已经是8了,远远超过两个CPU 的数量了
,会出现CPU的竞争。
中断in次数从28次每秒直接提升到13151次每秒,上下文cs从15次每秒直接提升到715508次每秒。
us(user)和 sy(system)列:这两列的 CPU 使用率加起来上升到了 100%,其中系统 CPU 使用率,也就是 sy 列高达 70%左右,说明 CPU 主要是被内核占用了。
综合这几个指标,我们可以知道,系统的就绪队列过长,也就是正在运行和等待 CPU 的进程数过多,导致了大量的上下文切换,而上下文切换又导致了系统 CPU 的占用率升高。
那么到底是什么进程导致了这些问题呢?
我们继续分析,在第三个终端再用 pidstat 来看一下, CPU 和进程上下文切换的情况:
# 每隔1秒输出1组数据(需要 Ctrl+C 才结束)
# -w参数表示输出进程切换指标,而-u参数则表示输出CPU使用指标
lighthouse@VM-24-16-ubuntu:~$ pidstat -w -u 1
Linux 5.15.0-106-generic (VM-24-16-ubuntu) 06/07/2024 _x86_64_ (2 CPU)
10:27:59 AM UID PID %usr %system %guest %wait %CPU CPU Command
10:28:00 AM 0 8466 0.99 0.00 0.00 0.00 0.99 1 barad_agent
10:28:00 AM 0 273925 0.99 0.99 0.00 0.00 1.98 1 YDService
10:28:00 AM 1001 772716 62.38 120.79 0.00 0.00 183.17 1 sysbench
10:28:00 AM 1001 772922 0.00 0.99 0.00 0.00 0.99 0 pidstat
10:27:59 AM UID PID cswch/s nvcswch/s Command
10:28:00 AM 0 13 11.88 0.00 ksoftirqd/0
10:28:00 AM 0 14 57.43 0.00 rcu_sched
10:28:00 AM 0 21 0.99 0.00 migration/1
10:28:00 AM 0 22 11.88 0.00 ksoftirqd/1
10:28:00 AM 0 31 1.98 0.00 kcompactd0
10:28:00 AM 0 105 2.97 0.00 kworker/1:1H-kblockd
10:28:00 AM 0 289 8.91 0.00 jbd2/vda2-8
10:28:00 AM 0 404 1.98 0.00 multipathd
10:28:00 AM 0 8459 0.99 0.00 barad_agent
10:28:00 AM 0 8466 5.94 0.00 barad_agent
10:28:00 AM 0 8793 7.92 0.00 tat_agent
10:28:00 AM 0 445371 3.96 0.00 kworker/1:0-mm_percpu_wq
10:28:00 AM 0 445373 15.84 0.00 kworker/0:3-ata_sff
10:28:00 AM 0 702381 9.90 0.00 kworker/u4:0-events_freezable_power_
10:28:00 AM 1001 772902 3.96 3.96 orca-data.sh
10:28:00 AM 1001 772922 0.99 82.18 pidstat
10:28:00 AM 1001 772945 0.99 6.93 orca-data.sh
10:28:00 AM 1001 772946 0.99 3.96 top
10:28:00 AM 1001 772947 0.99 2.97 grep
10:28:00 AM 1001 772948 0.99 1.98 sed
10:28:00 AM 1001 772949 0.99 2.97 awk
10:28:00 AM 113 3129416 0.99 0.00 ntpd
10:28:00 AM 65534 4008121 0.99 0.00 openresty
从 pidstat 的输出你可以发现,CPU 使用率的升高果然是 sysbench 导致的,它的 CPU 使用率已经达到了 100%。但上下文切换则是来自其他进程,包括非自愿上下文切换频率最高的 pidstat ,以及自愿上下文切换频率最高的内核线程 kworker 和 sshd。
不过,细心的你肯定也发现了一个怪异的事儿:pidstat 输出的上下文切换次数,加起来也就几百,比 vmstat 的 输出的数据明显小了太多。这是怎么回事呢?难道是工具本身出了错吗?
别着急,在怀疑工具之前,我们再来回想一下,前面讲到的几种上下文切换场景。其中有一点提到, Linux 调度的基本单位实际上是线程,而我们的场景 sysbench 模拟的也是线程的调度问题,那么,是不是 pidstat 忽略了线程的数据呢?
通过运行 man pidstat ,你会发现,pidstat 默认显示进程的指标数据,加上 -t 参数后,才会输出线程的指标。
所以,我们可以在第三个终端里, Ctrl+C 停止刚才的 pidstat 命令,再加上 -t 参数,重试一下看看:
lighthouse@VM-24-16-ubuntu:~$ pidstat -wt -u 1
Linux 5.15.0-106-generic (VM-24-16-ubuntu) 06/07/2024 _x86_64_ (2 CPU)
10:33:49 AM UID TGID TID %usr %system %guest %wait %CPU CPU Command
10:33:50 AM 0 13 13 0.00 0.97 0.00 0.00 0.97 0 (ksoftirqd/0)__ksoftirqd/0
10:33:50 AM 0 8467 - 0.97 0.97 0.00 0.00 1.94 0 barad_agent
10:33:50 AM 0 8793 8793 0.97 0.00 0.00 0.00 0.97 1 (tat_agent)__tat_agent
10:33:50 AM 0 273925 - 2.91 0.97 0.00 0.00 3.88 1 YDService
10:33:50 AM 0 - 273929 0.97 0.00 0.00 0.00 0.97 1 |__YDService
10:33:50 AM 1001 701275 - 0.00 0.97 0.00 0.00 0.97 0 orca-data.sh
10:33:50 AM 1001 - 701275 0.00 0.97 0.00 0.00 0.97 0 |__orca-data.sh
10:33:50 AM 1001 787291 - 47.57 133.98 0.00 0.00 181.55 0 sysbench
10:33:50 AM 1001 - 787292 3.88 14.56 0.00 63.11 18.45 1 |__sysbench
10:33:50 AM 1001 - 787293 3.88 14.56 0.00 56.31 18.45 0 |__sysbench
10:33:50 AM 1001 - 787294 4.85 12.62 0.00 58.25 17.48 0 |__sysbench
10:33:50 AM 1001 - 787295 4.85 13.59 0.00 55.34 18.45 1 |__sysbench
10:33:50 AM 1001 - 787296 5.83 12.62 0.00 56.31 18.45 0 |__sysbench
10:33:50 AM 1001 - 787297 4.85 15.53 0.00 54.37 20.39 1 |__sysbench
10:33:50 AM 1001 - 787298 2.91 15.53 0.00 59.22 18.45 1 |__sysbench
10:33:50 AM 1001 - 787299 4.85 10.68 0.00 66.99 15.53 0 |__sysbench
10:33:50 AM 1001 - 787300 5.83 13.59 0.00 47.57 19.42 0 |__sysbench
10:33:50 AM 1001 - 787301 5.83 11.65 0.00 61.17 17.48 0 |__sysbench
10:33:50 AM 1001 788056 - 0.97 0.97 0.00 4.85 1.94 0 pidstat
10:33:50 AM 1001 - 788056 0.97 0.97 0.00 4.85 1.94 0 |__pidstat
10:33:50 AM 1001 3591512 3591513 0.97 0.97 0.00 0.00 1.94 0 (supervisord)__supervisord
10:33:49 AM UID TGID TID cswch/s nvcswch/s Command
10:33:50 AM 0 13 - 20.39 0.00 ksoftirqd/0
10:33:50 AM 0 - 13 20.39 0.00 |__ksoftirqd/0
10:33:50 AM 0 14 - 51.46 0.00 rcu_sched
10:33:50 AM 0 - 14 51.46 0.00 |__rcu_sched
10:33:50 AM 0 15 - 3.88 0.00 migration/0
10:33:50 AM 0 - 15 3.88 0.00 |__migration/0
10:33:50 AM 0 21 - 0.97 0.00 migration/1
10:33:50 AM 0 - 21 0.97 0.00 |__migration/1
10:33:50 AM 0 22 - 3.88 0.00 ksoftirqd/1
10:33:50 AM 0 - 22 3.88 0.00 |__ksoftirqd/1
10:33:50 AM 0 31 - 1.94 0.00 kcompactd0
10:33:50 AM 0 - 31 1.94 0.00 |__kcompactd0
10:33:50 AM 0 404 - 1.94 0.00 multipathd
10:33:50 AM 0 - 404 1.94 0.00 |__multipathd
10:33:50 AM 0 - 413 0.97 0.00 |__multipathd
10:33:50 AM 0 8459 - 0.97 0.00 barad_agent
10:33:50 AM 0 - 8459 0.97 0.00 |__barad_agent
10:33:50 AM 0 8466 - 4.85 0.97 barad_agent
10:33:50 AM 0 - 8466 4.85 0.97 |__barad_agent
10:33:50 AM 0 8467 8522 71.84 0.00 (barad_agent)__barad_agent
10:33:50 AM 0 - 8757 7.77 0.00 |__barad_agent
10:33:50 AM 0 - 788023 29.13 0.00 |__barad_agent
10:33:50 AM 0 - 788126 54.37 0.00 |__barad_agent
10:33:50 AM 0 8793 - 3.88 0.97 tat_agent
10:33:50 AM 0 - 8793 3.88 0.97 |__tat_agent
10:33:50 AM 0 - 8796 0.97 0.00 |__event_slot_defa
10:33:50 AM 0 - 8797 0.97 0.00 |__tat_agent
10:33:50 AM 0 - 8798 0.97 3.88 |__tokio-runtime-w
10:33:50 AM 0 - 8799 0.97 2.91 |__tokio-runtime-w
10:33:50 AM 0 - 701266 0.97 0.00 |__tokio-runtime-w
10:33:50 AM 0 - 703400 0.97 0.00 |__tokio-runtime-w
10:33:50 AM 0 273925 273928 112.62 0.00 (YDService)__YDService
10:33:50 AM 0 - 273929 228.16 5.83 |__YDService
10:33:50 AM 0 - 273930 0.97 0.00 |__YDService
10:33:50 AM 0 - 273933 2.91 0.00 |__YDService
10:33:50 AM 0 - 273934 3.88 0.00 |__YDService
10:33:50 AM 0 - 273935 9.71 0.00 |__YDService
10:33:50 AM 0 - 273961 195.15 26.21 |__YDService
10:33:50 AM 0 - 273962 0.97 0.00 |__YDService
10:33:50 AM 0 - 273969 10.68 0.00 |__YDService
10:33:50 AM 0 - 273985 55.34 0.00 |__YDService
10:33:50 AM 0 - 273986 55.34 0.00 |__YDService
10:33:50 AM 0 - 273995 9.71 0.00 |__YDService
10:33:50 AM 0 - 273996 10.68 0.00 |__YDService
10:33:50 AM 0 - 273997 0.97 0.00 |__YDService
10:33:50 AM 0 - 274025 0.97 0.00 |__YDService
10:33:50 AM 0 - 274174 110.68 0.00 |__YDService
10:33:50 AM 0 273974 273976 3.88 0.00 (YDLive)__YDLive
10:33:50 AM 0 - 273978 0.97 0.00 |__YDLive
10:33:50 AM 0 - 273982 2.91 0.00 |__YDLive
10:33:50 AM 0 - 273983 1.94 0.00 |__YDLive
10:33:50 AM 0 445371 - 10.68 0.00 kworker/1:0-events
10:33:50 AM 0 - 445371 10.68 0.00 |__kworker/1:0-events
10:33:50 AM 0 445373 - 28.16 0.00 kworker/0:3-events
10:33:50 AM 0 - 445373 28.16 0.00 |__kworker/0:3-events
10:33:50 AM 1001 701275 - 12.62 10.68 orca-data.sh
10:33:50 AM 1001 - 701275 12.62 10.68 |__orca-data.sh
10:33:50 AM 0 780906 - 6.80 0.00 kworker/u4:3-events_power_efficient
10:33:50 AM 0 - 780906 6.80 0.00 |__kworker/u4:3-events_power_efficient
10:33:50 AM 1001 787291 787292 13300.97 72615.53 (sysbench)__sysbench
10:33:50 AM 1001 - 787293 16263.11 54025.24 |__sysbench
10:33:50 AM 1001 - 787294 17087.38 62891.26 |__sysbench
10:33:50 AM 1001 - 787295 17756.31 59978.64 |__sysbench
10:33:50 AM 1001 - 787296 15847.57 61746.60 |__sysbench
10:33:50 AM 1001 - 787297 17067.96 53992.23 |__sysbench
10:33:50 AM 1001 - 787298 12371.84 66788.35 |__sysbench
10:33:50 AM 1001 - 787299 10993.20 59652.43 |__sysbench
10:33:50 AM 1001 - 787300 21085.44 56203.88 |__sysbench
10:33:50 AM 1001 - 787301 13402.91 58401.94 |__sysbench
10:33:50 AM 1001 788056 - 0.97 5.83 pidstat
10:33:50 AM 1001 - 788056 0.97 5.83 |__pidstat
10:33:50 AM 1001 788118 - 6.80 4.85 orca-data.sh
10:33:50 AM 1001 - 788118 6.80 4.85 |__orca-data.sh
10:33:50 AM 1001 788132 - 0.97 56.31 orca-data.sh
10:33:50 AM 1001 - 788132 0.97 56.31 |__orca-data.sh
10:33:50 AM 1001 788133 - 0.97 491.26 top
10:33:50 AM 1001 - 788133 0.97 491.26 |__top
10:33:50 AM 1001 788134 - 0.97 44.66 grep
10:33:50 AM 1001 - 788134 0.97 44.66 |__grep
10:33:50 AM 1001 788135 - 0.97 0.97 sed
10:33:50 AM 1001 - 788135 0.97 0.97 |__sed
10:33:50 AM 1001 788136 - 0.97 27.18 awk
10:33:50 AM 1001 - 788136 0.97 27.18 |__awk
10:33:50 AM 113 3129416 - 0.97 0.00 ntpd
10:33:50 AM 113 - 3129416 0.97 0.00 |__ntpd
10:33:50 AM 1001 3591512 3591513 6.80 0.00 (supervisord)__supervisord
10:33:50 AM 1001 - 3591516 7.77 0.00 |__supervisord
10:33:50 AM 1001 - 3591520 2.91 0.00 |__supervisord
10:33:50 AM 65534 4008121 - 0.97 0.00 openresty
10:33:50 AM 65534 - 4008121 0.97 0.00 |__openresty
现在你就能看到了,虽然 sysbench 进程(也就是主线程)的上下文切换次数看起来并不多,但它的子线程的上下文切换次数却有很多。
看来,上下文切换罪魁祸首,还是过多的 sysbench 线程。我们已经找到了上下文切换次数增多的根源,那是不是到这儿就可以结束了呢?
当然不是。不知道你还记不记得,前面在观察系统指标时,除了上下文切换频率骤然升高,还有一个指标也有很大的变化。
是的,正是中断次数。中断次数也上升到了 1 万,但到底是什么类型的中断上升了,现在还不清楚。
我们接下来继续抽丝剥茧找源头。既然是中断,我们都知道,它只发生在内核态,而 pidstat 只是一个进程的性能分析工具,并不提供任何关于中断的详细信息,怎样才能知道中断发生的类型呢?
没错,那就是从 /proc/interrupts 这个只读文件中读取。/proc 实际上是 Linux 的一个虚拟文件系统,用于内核空间与用户空间之间的通信。/proc/interrupts 就是这种通信机制的一部分,提供了一个只读的中断使用情况。
我们还是在第三个终端里, Ctrl+C 停止刚才的 pidstat 命令,然后运行下面的命令,观察中断的变化情况:
lighthouse@VM-24-16-ubuntu:~$ cat /proc/interrupts
CPU0 CPU1
1: 0 9 IO-APIC 1-edge i8042
4: 7 0 IO-APIC 4-edge ttyS0
6: 0 3 IO-APIC 6-edge floppy
8: 0 0 IO-APIC 8-edge rtc0
9: 0 0 IO-APIC 9-fasteoi acpi
11: 0 0 IO-APIC 11-fasteoi virtio2, uhci_hcd:usb1
12: 15 0 IO-APIC 12-edge i8042
14: 753461 0 IO-APIC 14-edge ata_piix
15: 0 0 IO-APIC 15-edge ata_piix
24: 0 0 PCI-MSI 98304-edge virtio1-config
25: 0 5243824 PCI-MSI 98305-edge virtio1-req.0
26: 0 0 PCI-MSI 81920-edge virtio0-config
27: 1318237 0 PCI-MSI 81921-edge virtio0-input.0
28: 1495570 1 PCI-MSI 81922-edge virtio0-output.0
29: 1 1763577 PCI-MSI 81923-edge virtio0-input.1
30: 0 1840032 PCI-MSI 81924-edge virtio0-output.1
NMI: 0 0 Non-maskable interrupts
LOC: 187617676 179581754 Local timer interrupts
SPU: 0 0 Spurious interrupts
PMI: 0 0 Performance monitoring interrupts
IWI: 33 35 IRQ work interrupts
RTR: 0 0 APIC ICR read retries
RES: 8789931 8847784 Rescheduling interrupts
CAL: 85778183 86451181 Function call interrupts
TLB: 2613506 2658317 TLB shootdowns
TRM: 0 0 Thermal event interrupts
THR: 0 0 Threshold APIC interrupts
DFR: 0 0 Deferred Error APIC interrupts
MCE: 0 0 Machine check exceptions
MCP: 2425 2425 Machine check polls
ERR: 0
MIS: 0
PIN: 0 0 Posted-interrupt notification event
NPI: 0 0 Nested posted-interrupt event
PIW: 0 0 Posted-interrupt wakeup event
观察一段时间,你可以发现,变化速度最快的是重调度中断(RES),这个中断类型表示,唤醒空闲状态的 CPU 来调度新的任务运行。这是多处理器系统(SMP)中,调度器用来分散任务到不同 CPU 的机制,通常也被称为处理器间中断(Inter-Processor Interrupts,IPI)。所以,这里的中断升高还是因为过多任务的调度问题,跟前面上下文切换次数的分析结果是一致的。
通过这个案例,你应该也发现了多工具、多方面指标对比观测的好处。如果最开始时,我们只用了 pidstat 观测,这些很严重的上下文切换线程,压根儿就发现不了了。
现在再回到最初的问题,每秒上下文切换多少次才算正常呢?这个数值其实取决于系统本身的 CPU 性能。在我看来,如果系统的上下文切换次数比较稳定,那么从数百到一万以内,都应该算是正常的。
但当上下文切换次数超过一万次,或者切换次数出现数量级的增长时,就很可能已经出现了性能问题。
这时,你还需要根据上下文切换的类型,再做具体分析。比方说:
- 自愿上下文切换变多了,说明进程都在等待资源,有可能发生了 I/O 等其他问题;
- 非自愿上下文切换变多了,说明进程都在被强制调度,也就是都在争抢 CPU,说明 CPU 的确成了瓶颈;
- 中断次数变多了,说明 CPU 被中断处理程序占用,还需要通过查看 /proc/interrupts 文件来分析具体的中断类型。
小结今天,我通过一个 sysbench 的案例,给你讲了上下文切换问题的分析思路。碰到上下文切换次数过多的问题时,我们可以借助 vmstat 、 pidstat 和 /proc/interrupts 等工具,来辅助排查性能问题的根源。