【发布时间】:2019-06-11 09:07:08
【问题描述】:
背景: 我有 2 台服务器,所有操作系统内核版本都是 4.18.7,它有 CONFIG_BPF_SYSCALL=y
我创建了一个 shell 脚本 'x.sh'
i=0
while (( i < 1000000 ))
do (( i ++ ))
done
并运行命令:perf stat ./x.sh
所有的shell版本都是“4.2.6(1)-release”
S1: CPU——Intel(R) Xeon(R) CPU E5-2630 v4 @ 2.20GHz,微码——0xb00002e 和性能统计结果
5391.653531 task-clock (msec) # 1.000 CPUs utilized
4 context-switches # 0.001 K/sec
0 cpu-migrations # 0.000 K/sec
107 page-faults # 0.020 K/sec
12,910,036,202 cycles # 2.394 GHz
27,055,073,385 instructions # 2.10 insn per cycle
6,527,267,657 branches # 1210.624 M/sec
34,787,686 branch-misses # 0.53% of all branches
5.392121575 seconds time elapsed
S2: CPU——Intel(R) Xeon(R) CPU E5-2620 v4 @ 2.10GHz,微码——0xb00002e 和性能统计结果
10688.669439 task-clock (msec) # 1.000 CPUs utilized
6 context-switches # 0.001 K/sec
0 cpu-migrations # 0.000 K/sec
105 page-faults # 0.010 K/sec
24,583,857,467 cycles # 2.300 GHz
27,117,299,405 instructions # 1.10 insn per cycle
6,571,204,123 branches # 614.782 M/sec
32,996,513 branch-misses # 0.50% of all branches
10.688907278 seconds time elapsed
问题: 我们可以看到cpu相似,os内核相同,但是为什么perf stat的cycles差异如此之大!
编辑: 我修改了shell和命令: x.sh,将循环时间变小以减少花费时间
i=0
while (( i < 10000 ))
do
(( i ++))
done
命令,添加更多细节并重复
perf stat -d -d -d -r 100 ~/1.sh
结果 S1:
54.007015 task-clock (msec) # 0.993 CPUs utilized ( +- 0.09% )
0 context-switches # 0.002 K/sec ( +- 29.68% )
0 cpu-migrations # 0.000 K/sec ( +-100.00% )
106 page-faults # 0.002 M/sec ( +- 0.12% )
128,380,832 cycles # 2.377 GHz ( +- 0.09% ) (30.52%)
252,497,672 instructions # 1.97 insn per cycle ( +- 0.01% ) (39.75%)
60,741,861 branches # 1124.703 M/sec ( +- 0.01% ) (40.63%)
451,011 branch-misses # 0.74% of all branches ( +- 0.29% ) (40.72%)
66,621,188 L1-dcache-loads # 1233.565 M/sec ( +- 0.01% ) (40.76%)
52,248 L1-dcache-load-misses # 0.08% of all L1-dcache hits ( +- 4.55% ) (39.86%)
1,568 LLC-loads # 0.029 M/sec ( +- 9.58% ) (29.75%)
168 LLC-load-misses # 21.47% of all LL-cache hits ( +- 3.87% ) (29.66%)
<not supported> L1-icache-loads
672,212 L1-icache-load-misses ( +- 0.85% ) (29.62%)
67,630,589 dTLB-loads # 1252.256 M/sec ( +- 0.01% ) (29.62%)
1,051 dTLB-load-misses # 0.00% of all dTLB cache hits ( +- 33.11% ) (29.62%)
13,929 iTLB-loads # 0.258 M/sec ( +- 17.85% ) (29.62%)
44,327 iTLB-load-misses # 318.24% of all iTLB cache hits ( +- 8.12% ) (29.62%)
<not supported> L1-dcache-prefetches
<not supported> L1-dcache-prefetch-misses
0.054370018 seconds time elapsed ( +- 0.08% )
S2:
106.405511 task-clock (msec) # 0.996 CPUs utilized ( +- 0.07% )
0 context-switches # 0.002 K/sec ( +- 18.92% )
0 cpu-migrations # 0.000 K/sec
106 page-faults # 0.994 K/sec ( +- 0.09% )
242,242,714 cycles # 2.277 GHz ( +- 0.07% ) (30.55%)
260,394,910 instructions # 1.07 insn per cycle ( +- 0.01% ) (39.00%)
62,877,430 branches # 590.923 M/sec ( +- 0.01% ) (39.65%)
407,887 branch-misses # 0.65% of all branches ( +- 0.25% ) (39.81%)
68,137,265 L1-dcache-loads # 640.355 M/sec ( +- 0.01% ) (39.84%)
70,330 L1-dcache-load-misses # 0.10% of all L1-dcache hits ( +- 2.91% ) (39.38%)
3,526 LLC-loads # 0.033 M/sec ( +- 7.33% ) (30.28%)
153 LLC-load-misses # 8.69% of all LL-cache hits ( +- 6.29% ) (30.12%)
<not supported> L1-icache-loads
878,021 L1-icache-load-misses ( +- 0.43% ) (30.09%)
68,442,021 dTLB-loads # 643.219 M/sec ( +- 0.01% ) (30.07%)
9,518 dTLB-load-misses # 0.01% of all dTLB cache hits ( +- 2.58% ) (30.07%)
233,190 iTLB-loads # 2.192 M/sec ( +- 3.73% ) (30.07%)
17,837 iTLB-load-misses # 7.65% of all iTLB cache hits ( +- 13.21% ) (30.07%)
<not supported> L1-dcache-prefetches
<not supported> L1-dcache-prefetch-misses
0.106858870 seconds time elapsed ( +- 0.07% )
编辑:
我检查了/usr/bin/sh md5sum是否相同,并添加bash脚本头#! /usr/bin/sh,结果和以前一样
编辑:
我发现了一些有价值的差异使用命令perf diff perf.data.s2 perf.data.s1
首先显示一些警告:
/usr/lib64/ld-2.17.so with build id 93d2e4a501823d041413eeb652b89044d1f680ee not found, continuing without symbols
/usr/lib64/libc-2.17.so with build id b04a54c443d36058702ab4060c63f4ab3273eae9 not found, continuing without symbols
发现rpm版本不同。
性能差异展示:
# Event 'cycles'
#
# Baseline Delta Shared Object Symbol
# ........ ....... ................. ..............................................
#
21.20% +3.83% bash [.] 0x000000000002c0f0
10.22% libc-2.17.so [.] _int_free
9.11% libc-2.17.so [.] _int_malloc
7.97% libc-2.17.so [.] malloc
4.09% libc-2.17.so [.] __gconv_transform_utf8_internal
3.71% libc-2.17.so [.] __mbrtowc
3.48% -1.63% bash [.] execute_command_internal
3.48% +1.18% [unknown] [k] 0xfffffe0000032000
3.25% -1.87% bash [.] xmalloc
3.12% libc-2.17.so [.] __strcpy_sse2_unaligned
2.44% +2.22% [kernel.kallsyms] [k] syscall_return_via_sysret
2.09% -0.24% bash [.] evalexp
2.09% libc-2.17.so [.] __ctype_get_mb_cur_max
1.92% libc-2.17.so [.] free
1.41% -0.95% bash [.] dequote_string
1.19% +0.23% bash [.] stupidly_hack_special_variables
1.16% libc-2.17.so [.] __strlen_sse2_pminub
1.16% libc-2.17.so [.] __memcpy_ssse3_back
1.16% libc-2.17.so [.] __strcmp_sse42
0.93% -0.01% bash [.] mbschr
0.93% -0.47% bash [.] hash_search
0.70% libc-2.17.so [.] __sigprocmask
0.70% -0.23% bash [.] dispose_words
0.70% -0.23% bash [.] execute_command
0.70% -0.23% bash [.] set_pipestatus_array
0.70% bash [.] run_pending_traps
0.47% bash [.] malloc@plt
0.47% bash [.] var_lookup
0.47% bash [.] fmtumax
0.47% bash [.] do_redirections
0.46% bash [.] dispose_word
0.46% -0.00% bash [.] alloc_word_desc
0.46% -0.00% [kernel.kallsyms] [k] _copy_to_user
0.46% libc-2.17.so [.] __ctype_b_loc
0.46% bash [.] new_fd_bitmap
0.46% bash [.] add_unwind_protect
0.46% -0.00% bash [.] discard_unwind_frame
0.46% bash [.] memcpy@plt
0.46% bash [.] __ctype_get_mb_cur_max@plt
0.46% bash [.] signal_in_progress
0.40% libc-2.17.so [.] _IO_vfscanf
0.40% ld-2.17.so [.] do_lookup_x
0.27% bash [.] mbrtowc@plt
0.24% +1.60% [kernel.kallsyms] [k] __x64_sys_rt_sigprocmask
0.23% bash [.] list_append
0.23% bash [.] bind_variable
0.23% +0.69% [kernel.kallsyms] [k] entry_SYSCALL_64_stage2
0.23% +0.69% [kernel.kallsyms] [k] do_syscall_64
0.23% libc-2.17.so [.] _dl_mcount_wrapper_check
0.23% +0.69% bash [.] make_word_list
0.23% +0.69% [kernel.kallsyms] [k] copy_user_generic_unrolled
0.23% [kernel.kallsyms] [k] unmap_page_range
0.23% libc-2.17.so [.] __sigjmp_save
0.23% +0.23% [kernel.kallsyms] [k] entry_SYSCALL_64_after_hwframe
0.20% [kernel.kallsyms] [k] swapgs_restore_regs_and_return_to_usermode
0.03% [kernel.kallsyms] [k] page_fault
0.00% [kernel.kallsyms] [k] xfs_bmapi_read
0.00% [kernel.kallsyms] [k] xfs_release
0.00% +0.00% [kernel.kallsyms] [k] native_write_msr
+45.33% libc-2.17.so [.] 0x0000000000027cc6
+0.52% [kernel.kallsyms] [k] __mod_node_page_state
+0.46% bash [.] free@plt
+0.46% [kernel.kallsyms] [k] copy_user_enhanced_fast_string
+0.46% bash [.] begin_unwind_frame
+0.46% bash [.] make_bare_word
+0.46% bash [.] find_variable_internal
+0.37% ld-2.17.so [.] 0x0000000000009b13
也许 glibc 的区别就是答案!
编辑: 最后,我检查了BIOS的配置,看到S2 Server使用了省电模式,这才是真正的答案!
但是,BIOS 的配置让我感到困惑,MONITOR-MWAIT,即使使用“Max Performance Mode”和“MONITOR-MWAIT”enable,性能S2的也很差。并使用命令cpupower idle-info -o,查看cpu 使用“C-state”,它已经在“Max Performance Mode”中被禁用。必须禁用加上“Max Performance Mode”,性能才能更好。
“MONITOR-MWAIT”的描述说一些操作系统会检查这个选项来恢复“C-state”,我找不到Linux内核如何使用它来改变“C-state”......
【问题讨论】:
-
您确定这是上述脚本的输出吗?它仅包含 1M 次非常简单的迭代,但输出列出了数十亿个分支和 5 秒的总时间。
-
是的,我确定!我认为,这个脚本是一个shell脚本,所以它会被编译成更多的指令,因为它会调用内核并且内核有更多的分支。
-
请提供一个minimal reproducible example,其中包括编译选项和编译器版本以及特定的
perf命令行。 -
shell 脚本不是可重复基准测试的良好基础...至少您必须提供 shell 及其版本...请edit您的帖子包含该信息,不要将它(仅)放在 cmets 中。
-
进行更多的系统调用当然可以解释它。启用 Spectre/Meltdown 缓解后,系统调用会产生大量开销,由于 TLB 驱逐,在返回后一切都会变慢。也许 bash 正在分配/释放内存,并且在慢速机器上,它决定每次都将该内存返回给操作系统,而不是将其保存在空闲列表中。如果您为 libc 安装调试符号,您能否分析在 libc 中花费的大量时间?
标签: linux-kernel cpu perf branch-prediction