查看上下文切换
vmstat 是一个常用的系统性能分析工具，主要用来分析系统的内存使用情况，也常用来分析 CPU 上下文切换和中断的次数。
# 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 0 7420392 14352 522124 0 0 712 169 88 150 1 2 96 0 0
0 0 0 7420392 14360 522124 0 0 0 4 61 83 0 0 100 0 0
cs（context switch）是每秒上下文切换的次数。
in（interrupt）则是每秒中断的次数。
r（Running or Runnable）是就绪队列的长度，也就是正在运行和等待 CPU 的进程数。
b（Blocked）则是处于不可中断睡眠状态的进程数。
pidstat 查看进程的详细情况， -w 选项可以查看每个进程上下文切换的情况
# pidstat -w 5
Linux 4.15.0-213-generic (huahui) 09/05/2024 _x86_64_ (2 CPU)
01:39:23 AM UID PID cswch/s nvcswch/s Command
01:39:28 AM 0 8 11.60 0.00 rcu_sched
01:39:28 AM 0 11 0.20 0.00 watchdog/0
01:39:28 AM 0 14 0.20 0.00 watchdog/1
01:39:28 AM 0 33 7.80 0.00 kworker/1:1
01:39:28 AM 0 319 6.20 0.00 kworker/u256:29
01:39:28 AM 0 326 0.60 0.00 kworker/1:1H
01:39:28 AM 0 468 0.60 0.00 jbd2/dm-0-8
01:39:28 AM 0 801 12.00 0.00 vmtoolsd
01:39:28 AM 0 1104 0.40 0.00 kworker/0:3
01:39:28 AM 0 2215 0.20 0.00 pidstat
## -w 查看上下文切换 -u 查看CPU使用率 -t 查看线程（默认只查看进程）
# pidstat -w -u -t 2
cswch 表示每秒自愿上下文切换（voluntary context switches）的次数
nvcswch ，表示每秒非自愿上下文切换（non voluntary context switches）的次数。
自愿上下文切换，是指进程无法获取所需资源，导致的上下文切换。比如说， I/O、内存等系统资源不足时，就会发生自愿上下文切换。
非自愿上下文切换，则是指进程由于时间片已到等原因，被系统强制调度，进而发生的上下文切换。比如说，大量进程都在争抢 CPU 时，就容易发生非自愿上下文切换。
自愿上下文切换变多了，说明进程都在等待资源，有可能发生了 I/O 等其他问题；
非自愿上下文切换变多了，说明进程都在被强制调度，也就是都在争抢 CPU，说明 CPU 的确成了瓶颈；
中断次数变多了，说明 CPU 被中断处理程序占用，还需要通过查看 /proc/interrupts 文件来分析具体的中断类型。 cat /proc/interrupts | sort -nr -k 2 ## -nr 数字逆序 -k 2 以第二列排序
查看cpu使用率
内核节拍率 HZ
# grep 'CONFIG_HZ=' /boot/config-$(uname -r)
CONFIG_HZ=250
user（通常缩写为 us），代表用户态 CPU 时间。注意，它不包括下面的 nice 时间，但包括了 guest 时间。
nice（通常缩写为 ni），代表低优先级用户态 CPU 时间，也就是进程的 nice 值被调整为 1-19 之间时的 CPU 时间。这里注意，nice 可取值范围是 -20 到 19，数值越大，优先级反而越低。
system（通常缩写为 sys），代表内核态 CPU 时间。
idle（通常缩写为 id），代表空闲时间。注意，它不包括等待 I/O 的时间（iowait）。
iowait（通常缩写为 wa），代表等待 I/O 的 CPU 时间。
irq（通常缩写为 hi），代表处理硬中断的 CPU 时间。
softirq（通常缩写为 si），代表处理软中断的 CPU 时间。
steal（通常缩写为 st），代表当系统运行在虚拟机中的时候，被其他虚拟机占用的 CPU 时间。
guest（通常缩写为 guest），代表通过虚拟化运行其他操作系统的时间，也就是运行虚拟机的 CPU 时间。
guest_nice（通常缩写为 gnice），代表以低优先级运行虚拟机的时间。
性能分析工具给出的都是间隔一段时间的平均 CPU 使用率，所以要注意间隔时间的设置，特别是用多个工具对比分析时，你一定要保证它们用的是相同的间隔时间。
如何找到占用 CPU 的进程中到底是代码里的哪个函数呢
模拟高并发请求，-c 10 10个并发请求 -n 10000 10000的请求
# ab -c 10 -n 10000 http://192.168.16.148:10000/
通过top命令找到进程占用高的进程
top - 07:04:38 up 4:00, 3 users, load average: 6.39, 4.58, 2.73
Tasks: 187 total, 6 running, 103 sleeping, 0 stopped, 0 zombie
%Cpu0 : 99.0 us, 0.7 sy, 0.0 ni, 0.0 id, 0.0 wa, 0.0 hi, 0.3 si, 0.0 st
%Cpu1 : 98.7 us, 1.0 sy, 0.0 ni, 0.0 id, 0.0 wa, 0.0 hi, 0.3 si, 0.0 st
KiB Mem : 8142012 total, 6300452 free, 304272 used, 1537288 buff/cache
KiB Swap: 4194300 total, 4194300 free, 0 used. 7524084 avail Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
5982 daemon 20 0 336696 13272 5600 R 40.4 0.2 1:08.64 php-fpm
5983 daemon 20 0 336696 13272 5600 R 39.7 0.2 1:08.55 php-fpm
5984 daemon 20 0 336696 13272 5600 R 39.7 0.2 1:08.56 php-fpm
5980 daemon 20 0 336696 13336 5664 R 39.4 0.2 1:08.56 php-fpm
5981 daemon 20 0 336696 13336 5664 R 38.1 0.2 1:08.74 php-fpm
通过perf进一步分析，调用关系最终到了 sqrt-人-r-
# perf top -g -p 5984
Samples: 56K of event 'cpu-clock', Event count (approx.): 4726376989
Children Self Shared Object Symbol ◆
+ 99.48% 75.13% php-fpm [.] zend_execute ▒
- 96.59% 3.66% php-fpm [.] execute_ex ▒
- 63.05% execute_ex ▒
- 89.92% zend_execute ▒
16.31% zend_execute ▒
11.81% _php_math_round ▒
4.54% sqrt ▒
- 3.66% 0x6cb6258d4c544155 ▒
__libc_start_main ▒
php_register_internal_extensions ▒
php_execute_script ▒
zend_execute_scripts ▒
+ 95.87% 0.02% php-fpm [.] php_register_internal_extensions ▒
+ 89.60% 0.00% php-fpm [.] php_execute_script ▒
+ 11.93% 0.00% [unknown] [.] 0x6cb6258d4c544155 ▒
+ 11.93% 0.00% libc-2.24.so [.] __libc_start_main ▒
+ 11.86% 0.00% php-fpm [.] zend_execute_scripts ▒
+ 11.82% 11.70% php-fpm [.] _php_math_round ▒
+ 4.54% 4.51% libm-2.24.so [.] sqrt ▒
+ 3.47% 3.43% php-fpm [.] add_function
查看源码
# grep sqrt -r app/
app/index.php: $x += sqrt($x);
# cat app/index.php
<?php
// test only.
$x = 0.0001;
for ($i = 0; $i <= 1000000; $i++) {
$x += sqrt($x);
}
echo "It works!"
?>
查看短时/瞬时进程占用CPU使用率高
模拟压力
# ab -c 5 -t 600 192.168.16.148:10000/
通过 top 命令查看，明显没有CPU高的进程
top - 01:17:47 up 20 min, 1 user, load average: 4.99, 2.71, 1.15
Tasks: 190 total, 6 running, 105 sleeping, 0 stopped, 1 zombie
%Cpu0 : 62.0 us, 26.6 sy, 0.0 ni, 6.1 id, 0.0 wa, 0.0 hi, 5.4 si, 0.0 st
%Cpu1 : 63.8 us, 26.8 sy, 0.0 ni, 5.0 id, 0.0 wa, 0.0 hi, 4.4 si, 0.0 st
KiB Mem : 8142020 total, 6907320 free, 286756 used, 947944 buff/cache
KiB Swap: 4194300 total, 4194300 free, 0 used. 7572832 avail Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
2628 systemd+ 20 0 33136 3744 2360 S 4.3 0.0 0:11.26 nginx
2559 root 20 0 712744 10016 7792 S 3.3 0.1 0:06.58 containerd-shim
5769 daemon 20 0 336696 16156 8476 S 3.3 0.2 0:07.20 php-fpm
5774 daemon 20 0 336696 16092 8412 S 3.3 0.2 0:07.25 php-fpm
5781 daemon 20 0 336696 16156 8476 R 3.3 0.2 0:07.13 php-fpm
5786 daemon 20 0 336696 16092 8412 S 3.3 0.2 0:07.19 php-fpm
5795 daemon 20 0 336696 16092 8412 S 3.0 0.2 0:07.12 php-fpm
1474 root 20 0 1489892 70224 47880 S 2.3 0.9 0:08.82 dockerd
通过 pidstat 命令查看，明显没有CPU高的进程
# pidstat 1
Linux 4.15.0-213-generic (huahui) 09/06/2024 _x86_64_ (2 CPU)
01:21:07 AM UID PID %usr %system %guest %wait %CPU CPU Command
01:21:08 AM 0 16 0.00 2.00 0.00 1.00 2.00 1 ksoftirqd/1
01:21:08 AM 0 812 0.00 1.00 0.00 0.00 1.00 1 vmtoolsd
01:21:08 AM 0 1474 1.00 2.00 0.00 0.00 3.00 0 dockerd
01:21:08 AM 0 2559 0.00 4.00 0.00 0.00 4.00 1 containerd-shim
01:21:08 AM 101 2628 0.00 6.00 0.00 3.00 6.00 1 nginx
01:21:08 AM 1 5769 0.00 4.00 0.00 3.00 4.00 0 php-fpm
01:21:08 AM 1 5774 0.00 4.00 0.00 1.00 4.00 0 php-fpm
01:21:08 AM 1 5781 1.00 1.00 0.00 2.00 2.00 1 php-fpm
01:21:08 AM 1 5786 0.00 3.00 0.00 2.00 3.00 0 php-fpm
01:21:08 AM 1 5795 0.00 3.00 0.00 2.00 3.00 0 php-fpm
01:21:08 AM 0 91938 0.00 1.00 0.00 0.00 1.00 0 pidstat
返回 top 命令查看，发现有6个running进程数，通过 ps -aux 查看进行信息，发现stress进程运行，并且PID是不断变化的，说明该进程在不断重启
# ps -aux | grep R
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
daemon 92513 0.0 0.0 8196 1580 pts/0 R+ 01:25 0:00 /usr/local/bin/stress -t 1 -d 1
daemon 92519 0.0 0.0 8188 100 pts/0 R+ 01:25 0:00 /usr/local/bin/stress -t 1 -d 1
daemon 92524 0.0 0.0 8180 1104 pts/0 R+ 01:25 0:00 /usr/local/bin/stress -t 1 -d 1
daemon 92525 0.0 0.0 8188 104 pts/0 R+ 01:25 0:00 /usr/local/bin/stress -t 1 -d 1
查找父进程，stress 是被 php-fpm 调用的子进程，经查看源码确实调用了stress
# pstree | grep stress
|-containerd-shim-+-php-fpm-+-4*[php-fpm---sh---stress---stress]
使用perf分析CPU性能事件
# perf record -g
# perf report
Samples: 101K of event 'cpu-clock', Event count (approx.): 25497250000
Children Self Command Shared Object Symbol
+ 61.46% 0.00% stress stress [.] 0x000000000000168d
+ 6.45% 0.00% swapper [kernel.kallsyms] [k] secondary_startup_64
+ 6.45% 0.00% swapper [kernel.kallsyms] [k] cpu_startup_entry
+ 6.45% 0.00% swapper [kernel.kallsyms] [k] do_idle
+ 6.42% 0.00% swapper [kernel.kallsyms] [k] default_idle_call
+ 6.42% 0.00% swapper [kernel.kallsyms] [k] arch_cpu_idle
+ 6.42% 0.00% swapper [kernel.kallsyms] [k] __cpuidle_text_start
+ 6.42% 6.32% swapper [kernel.kallsyms] [k] native_safe_halt
+ 6.23% 0.00% stress [kernel.kallsyms] [k] entry_SYSCALL_64_after_hwframe
+ 6.21% 0.03% stress [kernel.kallsyms] [k] do_syscall_64
+ 6.14% 0.00% php-fpm [kernel.kallsyms] [k] entry_SYSCALL_64_after_hwframe
+ 6.14% 0.02% php-fpm [kernel.kallsyms] [k] do_syscall_64
+ 5.65% 0.00% php-fpm [unknown] [k] 0x6cb6258d4c544155
+ 5.65% 0.00% php-fpm libc-2.24.so [.] 0x00000000000202e1
+ 5.65% 0.05% php-fpm php-fpm [.] php_register_internal_extensions
+ 5.03% 4.56% stress libc-2.24.so [.] 0x0000000000036387
+ 4.92% 4.77% stress [kernel.kallsyms] [k] exit_to_usermode_loop
+ 4.89% 0.00% stress [kernel.kallsyms] [k] swapgs_restore_regs_and_return_to_usermode
+ 4.89% 0.00% stress [kernel.kallsyms] [k] prepare_exit_to_usermode
+ 4.83% 2.30% stress stress [.] 0x0000000000002f25
execsnoop 就是一个专为短时进程设计的工具。它通过 ftrace 实时监控进程的 exec() 行为，并输出短时进程的基本信息，包括进程 PID、父进程 PID、命令行参数以及执行的结果。
不可中断进程
通过 dstat 命令分析，发现iowait升高，磁盘的读请求都会很大，说明 iowait 的升高跟磁盘的读请求有关，很可能就是磁盘读导致的
# dstat 1 10
--total-cpu-usage-- -dsk/total- -net/total- ---paging-- ---system--
usr sys idl wai stl| read writ| recv send| in out | int csw
26 10 62 1 0| 70M 159k| 0 0 | 0 0 |1992 4290
0 0 100 0 0| 0 0 | 60B 778B| 0 0 | 75 122
14 17 53 16 0| 940M 0 | 60B 330B| 0 0 |1286 359
46 17 10 27 0|1516M 0 | 60B 330B| 0 0 |2053 260
2 1 95 3 0| 104M 0 | 60B 330B| 0 0 | 246 145
0 1 100 0 0| 0 0 | 60B 330B| 0 0 | 78 126
0 0 100 0 0| 0 0 | 60B 420B| 0 0 | 63 108
8 26 51 15 0| 939M 0 | 60B 420B| 0 0 |1276 365
20 37 3 41 0|1588M 0 | 60B 330B| 0 0 |2218 320
0 2 98 0 0| 33M 0 | 60B 330B| 0 0 | 126 124
通过 pidstat 查看进程读写情况
# pidstat -d 1
Linux 4.15.0-213-generic (huahui) 09/06/2024 _x86_64_ (2 CPU)
02:12:51 AM UID PID kB_rd/s kB_wr/s kB_ccwr/s iodelay Command
02:12:52 AM 0 103961 257003.92 0.00 0.00 38 app
02:12:52 AM 0 103962 321254.90 0.00 0.00 38 app
strace 是最常用的跟踪进程系统调用的工具。
使用 strace 工具进一步分析
# strace -p 104050
strace: Could not attach to process. If your uid matches the uid of the target process, check the setting of /proc/sys/kernel/yama/ptrace_scope, or try again as the root user. For more details, see /etc/sysctl.d/10-ptrace.conf: Operation not permitted
strace: attach: ptrace(PTRACE_SEIZE, 104050): Operation not permitted
## 该进程已经变成僵尸进程
# ps -ef |grep 104050
root 104050 103286 0 02:16 pts/0 00:00:00 [app] <defunct>
使用 perf 分析，可以发现， app 的确在通过系统调用 sys_read() 读取数据。并且从 new_sync_read 和 blkdev_direct_IO 能看出，进程正在对磁盘进行直接读，也就是绕过了系统缓存，每个读请求都会从磁盘直接读，这就可以解释我们观察到的 iowait 升高了。
# perf record -g
# perf report
Samples: 41K of event 'cpu-clock', Event count (approx.): 10368000000
Children Self Command Shared Object Symbol
+ 40.41% 0.00% swapper [kernel.kallsyms] [k] rest_init
+ 8.09% 0.00% app [kernel.kallsyms] [k] entry_SYSCALL_64_after_hwframe
+ 8.09% 0.00% app [kernel.kallsyms] [k] do_syscall_64
- 8.09% 0.00% app [unknown] [k] 0x0b96258d4c544155
0xb96258d4c544155
__libc_init_first
- main
- 8.04% read
entry_SYSCALL_64_after_hwframe
do_syscall_64
sys_read
vfs_read
__vfs_read
new_sync_read
blkdev_read_iter
generic_file_read_iter
+ blkdev_direct_IO
+ 8.09% 0.00% app libc-2.27.so [.] __libc_init_first
+ 8.09% 0.00% app app [.] main
+ 8.04% 0.00% app libc-2.27.so [.] read
僵尸进程
查看僵尸进程的父进程，然后查看父进程的应用程序的代码，看看子进程结束的处理是否正确
# pstree -aps 104490
systemd,1 maybe-ubiquity
└─containerd-shim,104397 -namespace moby -id 9a2c56c0ca2b230ead8abe9112c74b0d62ce1ea979e1ca3fe047b7f71721abed -address/run/contain
└─app,104427
└─(app,104490)
软中断
模拟软中断导致CPU高的情况
hping3 是一个可以构造 TCP/IP 协议数据包的工具，可以对系统进行安全审计、防火墙测试等。
-S参数表示设置TCP协议的SYN（同步序列号），-p表示目的端口为80， -i u100表示每隔100微秒发送一个网络帧
# docker run -itd --name=nginx -p 80:80 nginx
# hping3 -S -p 80 -i u10 192.168.16.148
通过 top 查看CPU，软中断CPU数值较高
top - 03:19:20 up 2:22, 1 user, load average: 0.25, 0.22, 0.19
Tasks: 174 total, 1 running, 95 sleeping, 0 stopped, 0 zombie
%Cpu(s): 0.0 us, 14.0 sy, 0.0 ni, 62.1 id, 0.0 wa, 0.0 hi, 23.9 si, 0.0 st
KiB Mem : 8142020 total, 5001552 free, 286360 used, 2854108 buff/cache
KiB Swap: 4194300 total, 4194300 free, 0 used. 7548908 avail Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
16 root 20 0 0 0 0 S 3.7 0.0 1:46.80 ksoftirqd/1
8 root 20 0 0 0 0 I 0.3 0.0 0:03.46 rcu_sched
2398 huahui 20 0 107996 5680 4676 S 0.3 0.1 0:03.51 sshd
查看软中断次数变化，/proc/softirqs 是系统运行以来的累积中断次数。
# watch -d "cat /proc/softirqs | awk 'NR==1 {printf \"%10s %10s %10s\n\",\" \",\$1,\$2};NR>1 {printf \"%10s %10s %10s\n\",\$1,\$2,\$3}'"
Every 2.0s: cat /proc/softirqs | awk 'NR==1 {printf "%10s %10s %10s\n"," ",$1,$2};NR>1 {printf "%10s %10s %10s\n",$1,$2,$3}' huahui: Fri Sep 6 06:03:10 2024
CPU0 CPU1
HI: 0 1
TIMER: 7256 21480
NET_TX: 3 83
NET_RX: 6 179703
BLOCK: 4047 5593
IRQ_POLL: 0 0
TASKLET: 81 76
SCHED: 6276 20697
HRTIMER: 0 0
RCU: 23776 41016
TIMER（定时中断）、NET_RX（网络接收）、SCHED（内核调度）、RCU（RCU 锁）等这几个软中断都在不停变化。其中，NET_RX，也就是网络数据包接收软中断的变化速率最快。而其他几种类型的软中断，是保证 Linux 调度、时钟和临界区保护这些正常工作所必需的，所以它们有一定的变化倒是正常的。
通过sar查看网络情况，684.61 * 1024/11684=60B ，每个网络贞数大约是60字节，大量的发送的小数据包
# sar -n DEV 1
Linux 4.15.0-213-generic (huahui) 09/06/2024 _x86_64_ (2 CPU)
06:07:47 AM IFACE rxpck/s txpck/s rxkB/s txkB/s rxcmp/s txcmp/s rxmcst/s %ifutil
06:07:48 AM ens33 11684.00 11684.00 684.61 684.61 0.00 0.00 0.00 0.56
06:07:48 AM lo 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
第一列：表示报告的时间。
第二列：IFACE 表示网卡。
第三、四列：rxpck/s 和 txpck/s 分别表示每秒接收、发送的网络帧数，也就是 PPS。
第五、六列：rxkB/s 和 txkB/s 分别表示每秒接收、发送的千字节数，也就是 BPS。
最后通过tcpdump抓包具体分析来源IP地址
标签：分析,fpm,0.0,性能,AM,CPU,php,0.00 From： https://www.cnblogs.com/zbc230/p/18400448