这个实验用来学习上下文切换

1
apt install sysbench
1
2
3
4
root@perf:/home/ykg# vmstat 1 1
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 7365884 25792 440260 0 0 17 542 97 543 13 1 81 5 0
1
2
# 以 10 个线程运行 5 分钟的基准测试,模拟多线程切换的问题
sysbench --threads=10 --max-time=300 threads run
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
ykg@perf:~$ 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
0 0 0 7363852 25852 440316 0 0 17 533 95 533 13 1 82 5 0
0 0 0 7363844 25852 440316 0 0 0 4 20 89 0 0 100 0 0
...
0 0 0 7363512 25860 440324 0 0 0 4 20 99 0 0 100 0 0
0 0 0 7363520 25860 440324 0 0 0 20 12 47 0 0 100 0 0
0 0 0 7363520 25860 440324 0 0 0 0 14 55 0 0 100 0 0
0 0 0 7363520 25860 440324 0 0 0 4 23 100 0 0 100 0 0
0 0 0 7363636 25860 440324 0 0 0 0 29 107 1 0 100 0 0
8 0 0 7361156 25860 440580 0 0 256 0 13510 806968 21 53 27 0 0
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 7361156 25860 440580 0 0 0 4 11897 1146131 35 66 0 0 0
7 0 0 7361156 25860 440580 0 0 0 0 15220 1143409 33 67 0 0 0
6 0 0 7361156 25860 440580 0 0 0 0 11226 1131061 36 64 0 0 0
8 0 0 7360256 25860 440580 0 0 0 4 17465 1075562 35 65 0 0 0
5 0 0 7360288 25860 440580 0 0 0 0 17061 1100762 30 70 0 0 0

可以看到cs/in的值明显飙升

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
# pidstat -w -u 1
04:59:18 UID PID %usr %system %guest %wait %CPU CPU Command
04:59:19 0 28388 71.00 100.00 0.00 0.00 100.00 0 sysbench

04:59:18 UID PID cswch/s nvcswch/s Command
04:59:19 0 9 1.00 0.00 ksoftirqd/0
04:59:19 0 10 13.00 0.00 rcu_sched
04:59:19 0 13 1.00 0.00 watchdog/0
04:59:19 0 16 1.00 0.00 watchdog/1
04:59:19 0 212 1.00 0.00 kworker/0:3-events
04:59:19 0 498 1.00 0.00 hv_balloon
04:59:19 0 1118 1.00 0.00 irqbalance
04:59:19 0 27306 124.00 0.00 kworker/u256:3-events_power_efficient
04:59:19 1000 27872 110.00 0.00 sshd
04:59:19 1000 28365 1.00 3.00 vmstat
04:59:19 0 28671 1.00 108.00 pidstat

可以看到sysbench占用了100% cpu(不过很奇怪%usr + %sys == 171%是什么情况?)。pidstat的值加起来也不高,明显达不到vmstat输出的情况。

因为pidstat统计的是按照进程切换,-t参数显示线程

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
# pidstat -w -u 1 -t # -t Also display statistics for threads associated with selected tasks.
05:08:58 UID TGID TID %usr %system %guest %wait %CPU CPU Command
05:08:59 0 - 1326 0.00 1.00 0.00 0.00 1.00 1 |__python3
05:08:59 1000 27872 - 1.00 0.00 0.00 0.00 1.00 0 sshd
05:08:59 1000 - 27872 1.00 0.00 0.00 0.00 1.00 0 |__sshd
05:08:59 0 29185 - 72.00 100.00 0.00 0.00 100.00 1 sysbench
05:08:59 0 - 29186 9.00 11.00 0.00 53.00 20.00 1 |__sysbench
05:08:59 0 - 29187 8.00 11.00 0.00 49.00 19.00 0 |__sysbench
05:08:59 0 - 29188 7.00 13.00 0.00 47.00 20.00 0 |__sysbench
05:08:59 0 - 29189 5.00 14.00 0.00 38.00 19.00 0 |__sysbench
05:08:59 0 - 29190 8.00 12.00 0.00 54.00 20.00 1 |__sysbench
05:08:59 0 - 29191 8.00 12.00 0.00 56.00 20.00 1 |__sysbench
05:08:59 0 - 29192 6.00 14.00 0.00 57.00 20.00 0 |__sysbench
05:08:59 0 - 29193 7.00 13.00 0.00 48.00 20.00 1 |__sysbench
05:08:59 0 - 29194 8.00 13.00 0.00 57.00 21.00 0 |__sysbench
05:08:59 0 - 29195 6.00 12.00 0.00 54.00 18.00 1 |__sysbench
05:08:59 0 29209 - 0.00 1.00 0.00 7.00 1.00 1 pidstat
05:08:59 0 - 29209 0.00 1.00 0.00 7.00 1.00 1 |__pidstat

05:08:58 UID TGID TID cswch/s nvcswch/s Command
05:08:59 0 9 - 1.00 0.00 ksoftirqd/0
05:08:59 0 - 9 1.00 0.00 |__ksoftirqd/0
05:08:59 0 10 - 23.00 0.00 rcu_sched
05:08:59 0 - 10 23.00 0.00 |__rcu_sched
05:08:59 0 18 - 3.00 0.00 ksoftirqd/1
05:08:59 0 - 18 3.00 0.00 |__ksoftirqd/1
05:08:59 0 123 - 1.00 0.00 kworker/0:1H-kblockd
05:08:59 0 - 123 1.00 0.00 |__kworker/0:1H-kblockd
05:08:59 0 212 - 1.00 0.00 kworker/0:3-mm_percpu_wq
05:08:59 0 - 212 1.00 0.00 |__kworker/0:3-mm_percpu_wq
05:08:59 0 498 - 1.00 0.00 hv_balloon
05:08:59 0 - 498 1.00 0.00 |__hv_balloon
05:08:59 0 1326 - 9.00 0.00 python3
05:08:59 0 - 1326 9.00 0.00 |__python3
05:08:59 0 27305 - 1.00 0.00 kworker/1:1-mm_percpu_wq
05:08:59 0 - 27305 1.00 0.00 |__kworker/1:1-mm_percpu_wq
05:08:59 0 27306 - 51.00 0.00 kworker/u256:3-events_power_efficient
05:08:59 0 - 27306 51.00 0.00 |__kworker/u256:3-events_power_efficient
05:08:59 1000 27872 - 278.00 59.00 sshd
05:08:59 1000 - 27872 278.00 59.00 |__sshd
05:08:59 0 28931 - 304.00 0.00 kworker/u256:1-events_unbound
05:08:59 0 - 28931 304.00 0.00 |__kworker/u256:1-events_unbound
05:08:59 0 - 29186 18792.00 98414.00 |__sysbench
05:08:59 0 - 29187 18737.00 97043.00 |__sysbench
05:08:59 0 - 29188 23418.00 95042.00 |__sysbench
05:08:59 0 - 29189 23430.00 82341.00 |__sysbench
05:08:59 0 - 29190 18268.00 95634.00 |__sysbench
05:08:59 0 - 29191 14390.00 104050.00 |__sysbench
05:08:59 0 - 29192 19305.00 97544.00 |__sysbench
05:08:59 0 - 29193 20488.00 92663.00 |__sysbench
05:08:59 0 - 29194 18648.00 102499.00 |__sysbench
05:08:59 0 - 29195 14792.00 103681.00 |__sysbench
05:08:59 1000 29204 - 1.00 0.00 vmstat
05:08:59 1000 - 29204 1.00 0.00 |__vmstat
05:08:59 0 29209 - 1.00 279.00 pidstat
05:08:59 0 - 29209 1.00 279.00 |__pidstat

大量的interrupt变动发生在RES上,IPI处理器间调度,在SMP中用来将任务分散到不同cpu的机制

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
Every 2.0s: cat /proc/interrupts                                   perf: Sat Aug  3 06:00:55 2019

CPU0 CPU1
0: 46 0 IO-APIC 2-edge timer
1: 0 9 IO-APIC 1-edge i8042
4: 0 1599 IO-APIC 4-edge ttyS0
8: 0 0 IO-APIC 8-edge rtc0
9: 0 0 IO-APIC 9-fasteoi acpi
12: 3 0 IO-APIC 12-edge i8042
14: 0 0 IO-APIC 14-edge ata_piix
15: 0 0 IO-APIC 15-edge ata_piix
NMI: 0 0 Non-maskable interrupts
LOC: 142 89 Local timer interrupts
SPU: 0 0 Spurious interrupts
PMI: 0 0 Performance monitoring interrupts
IWI: 1 0 IRQ work interrupts
RTR: 0 0 APIC ICR read retries
RES: 7839865 9962474 Rescheduling interrupts
CAL: 50752 2521 Function call interrupts
TLB: 0 0 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: 49 49 Machine check polls
HYP: 2631487 82131 Hypervisor callback interrupts
HRE: 0 0 Hyper-V reenlightenment interrupts
HVS: 871419 1002514 Hyper-V stimer0 interrupts
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