当前位置: 首页 > 工具软件 > uftrace > 使用案例 >

基于uftrace的应用性能侧写

况庆
2023-12-01

常用的应用侧写方法

开源编译器gcc提供了-pg编译选项,会修改生成的目柡文件,在各个函数入口处加入对函数_mcount的调用。通过实现不同的_mcout函数,该机制可以对应用运行时进行侧写(profiling),生成侧写文件(文件名通常是gmon.out);之后调用gprof等工具读取侧写文件,从而可以得到程序运行时的代码覆盖率、各函数调用的次数以及各函数的运行时间等:

echo 'int hello(int x, int y) { return x * y; }' | gcc -fPIC -c -ggdb -pg -O2 -o a.out -x c -
objdump -d a.out

上面对目柡文件a.out的反汇编结果如下,可看到编译器在hello函数代码里插入了对_mcount函数的调用:

Disassembly of section .text:
0000000000000000 <hello>:
   0:	a9be7bfd 	stp	x29, x30, [sp, #-32]!
   4:	910003fd 	mov	x29, sp
   8:	a90153f3 	stp	x19, x20, [sp, #16]
   c:	2a0103f3 	mov	w19, w1
  10:	d50320ff 	xpaclri
  14:	2a0003f4 	mov	w20, w0
  18:	aa1e03e0 	mov	x0, x30
  1c:	94000000 	bl	0 <_mcount>
  20:	1b137e80 	mul	w0, w20, w19
  24:	a94153f3 	ldp	x19, x20, [sp, #16]
  28:	a8c27bfd 	ldp	x29, x30, [sp], #32
  2c:	d65f03c0 	ret

该应用性能的探测方法的弊端是,生成的可执行文件、动态库在默认运行环境下也会生成gmon.out侧写文件(构建结果只能用于测试,不能用于发布),而且需要glibc库的支持(glibc提供了默认的_mcount函数实现)。例如对于musl库,因其未定义_mcount函数且缺少相关的侧写运行时功能(由目柡文件gcrt1.o提供),若开发者未定义_mcount函数,编译链接会失败:

$ mipsel-openwrt-linux-musl-gcc -pg -o hello hello.c    
/opt/toolchain-mipsel_24kc_gcc-7.3.0_musl/bin/../lib/gcc/mipsel-openwrt-linux-musl/7.3.0/../../../../mipsel-openwrt-linux-musl/bin/ld: cannot find gcrt1.o: No such file or directory
collect2: error: ld returned 1 exit status

另一种常用的应用性能探测方法是使用perf,长期以来它是Linux内核中重要的性能分析工具。它不仅仅可以对内核性能进行记录,也可以通过--all-user-p参数指定对某个用户态的进程进行性能采样、记录,并生成性能分析数据。与本文介绍的uftrace工具相近,perf也依赖elfutils库,可以对可执行应用和动态库的符号解析,在呈现性能汇报结果时,可以直接定位到耗时久、调用频繁的函数,方便应用开发人员对应用进行必要的性能优化;其用法这里不讨论。

uftrace工具的编译

这里简要记录笔者编译uftrace的操作,方便以后参考。其中忽略了luajit的编译过程,因为本文不关注uftrace内置的对侧写数据使用lua脚本的解析功能。首先,笔者编译了elfutils开源库:

~/elfutils-0.187$ export PREFIX_DIR=/opt/uftrace
~/elfutils-0.187$ ./configure --prefix=${PREFIX_DIR} CC=gcc CFLAGS='-Wall -fPIC -O2 -m64 -D_GNU_SOURCE' --disable-nls --with-zlib --enable-libdebuginfod=dummy --disable-debuginfod --with-zlib LDFLAGS="-Wl,-rpath=${PREFIX_DIR}/lib -L${PREFIX_DIR}/lib"

接下来,编译uftrace的配置如下:

~/uftrace$ ./configure --prefix=${PREFIX_DIR} --with-elfutils=${PREFIX_DIR} --cflags="-I${PREFIX_DIR}/include/luajit-2.1 -I${PREFIX_DIR}/include -Wall -fPIC -O3 -ggdb -m64 -D_GNU_SOURCE" --ldflags="-L${PREFIX_DIR}/lib -Wl,-rpath=${PREFIX_DIR}/lib -lluajit-5.1" --with-libluajit=${PREFIX_DIR} --without-libpython --with-libdw=${PREFIX_DIR} --with-libelf=${PREFIX_DIR}

uftrace detected system features:
...         prefix: /opt/uftrace
...         libelf: [ on  ] - more flexible ELF data handling
...          libdw: [ on  ] - DWARF debug info support
...      libpython: [ OFF ] - python scripting support
...      libluajit: [ on  ] - luajit scripting support
...    libncursesw: [ OFF ] - TUI support
...   cxa_demangle: [ on  ] - full demangler support with libstdc++
...     perf_event: [ on  ] - perf (PMU) event support
...       schedule: [ on  ] - scheduler event support
...       capstone: [ OFF ] - full dynamic tracing support
...      libunwind: [ OFF ] - libunwind support

之后执行make installuftrace就安装完成了。

djpeg进行性能分析

为了演示uftrace的性能分析效果,笔者四次编译了jpegsrc.v9e.tar.gz,编译的配置不同,安装的路径也不同。选择该开源软件做为应用性能跟踪的对象,主要其代码量少,且性能瓶颈较为明确。首先,笔者以静态链接的方式,不加侧写(profiling)相关的编译选项(本文后面会作说明):

./configure --prefix=${PREFIX_DIR}/jpeg_default CC=gcc \
    CFLAGS='-Wall -fPIC -O2 -m64 -D_GNU_SOURCE -ggdb -fno-omit-frame-pointer' \
    --enable-static=yes --enable-shared=no

第二次编译jpegsrc.v9e.tar.gz,以静态链接,但带有可补丁函数入口patchable-function-entry)编译选项(这一编译选项仅8.1.0版本及以上的gcc编译器支持):

./configure --prefix=${PREFIX_DIR}/jpeg_static CC=gcc \
    CFLAGS='-Wall -fPIC -O2 -D_GNU_SOURCE -ggdb -fno-omit-frame-pointer -fpatchable-function-entry=5' \
    --enable-static=yes --enable-shared=no

第三次编译,使能动态链接,且带有-finstrument-functions编译选项:

./configure --prefix=${PREFIX_DIR}/jpeg_inst CC=gcc \
    CFLAGS='-Wall -fPIC -O2 -D_GNU_SOURCE -ggdb -fno-omit-frame-pointer -finstrument-functions' \
    --enable-static=no --enable-shared=yes \
    LDFLAGS="-Wl,-rpath=${PREFIX_DIR}/jpeg_inst/lib -L${PREFIX_DIR}/jpeg_inst/lib"

第四次编译,使能动态链接,且带有-fpatchable-function-entry编译选项:

./configure --prefix=${PREFIX_DIR}/jpeg_patch CC=gcc \
    CFLAGS='-Wall -fPIC -O2 -D_GNU_SOURCE -ggdb -fno-omit-frame-pointer -fpatchable-function-entry=5' \
    --enable-static=no --enable-shared=yes \
    LDFLAGS="-Wl,-rpath=${PREFIX_DIR}/jpeg_patch/lib -L${PREFIX_DIR}/jpeg_patch/lib"

之后笔者编写了以下简单脚本(uftrace-djpeg.sh),使用一张图片对djpeg解码JPEG的性能进行侧写。该脚本会生成uftrace的告文件以及Flamegraphsvg格式的图片文件,以图形化的方式展示侧写结果,以直观地对比各种不同的编译方式的性能报告:

#!/bin/bash
# uftrace-djpeg.sh
export PREFIX_DIR=/opt/uftrace
IMG_FILE=input.jpeg
profile_djpeg() {
	local pdir="$1"
	shift 1 # remove first argument
	local traceargs="$@"

	echo -n "profiling \${PREFIX_DIR}/${pdir}/bin/djpeg, time spent: "
	command time -f '%U' ${PREFIX_DIR}/${pdir}/bin/djpeg \
		-dct float -outfile /dev/null "${IMG_FILE}"

	rm -rf "${pdir}.data"
	uftrace record -a -l ${traceargs} -d "${pdir}.data" \
		${PREFIX_DIR}/${pdir}/bin/djpeg \
		-dct float -outfile /dev/null "${IMG_FILE}"

	uftrace report -d "${pdir}.data" > "${pdir}.report"
	echo "    Number of functions traced: `wc -l ${pdir}.report | awk '{print $1}'`"
	uftrace dump -d "${pdir}.data" --flame-graph | perl ./flamegraph.pl > "${pdir}.svg"
	return $?
}

PATCH_FUNCS="-P jpeg_read_scanlines -P process_data_simple_main"
PATCH_FUNCS="${PATCH_FUNCS} -P decompress_onepass -P decode_mcu"
PATCH_FUNCS="${PATCH_FUNCS} -P jpeg_idct_float -P jpeg_fill_bit_buffer"
PATCH_FUNCS="${PATCH_FUNCS} -P sep_upsample -P ycc_rgb_convert -P memset"
PATCH_FUNCS="${PATCH_FUNCS} -P put_pixel_rows -P fwrite -P jpeg_huff_decode"
profile_djpeg jpeg_default --force ${PATCH_FUNCS}
profile_djpeg jpeg_static --force ${PATCH_FUNCS}
profile_djpeg jpeg_inst
profile_djpeg jpeg_patch --force ${PATCH_FUNCS}

以上脚本执行的结果如下:

$ ./uftrace-djpeg.sh
profiling ${PREFIX_DIR}/jpeg_default/bin/djpeg, time spent: 0.10
    Number of functions traced: 15
profiling ${PREFIX_DIR}/jpeg_static/bin/djpeg, time spent: 0.10
    Number of functions traced: 25
profiling ${PREFIX_DIR}/jpeg_inst/bin/djpeg, time spent: 0.10
    Number of functions traced: 112
profiling ${PREFIX_DIR}/jpeg_patch/bin/djpeg, time spent: 0.10
    Number of functions traced: 50

可见,四种编译方案的djpeg对同一图片解码的耗时几乎相同(正常运行时,侧写的编译选项引入的性能损失可以忽略不计)。第一次和第二次编译的djpeg(都以静态链接,第二次编译带有-fpatchable-function-entry=5选项),前者跟踪到了15个函数,后者跟踪到了25个函数;而第三次编译和第四次编译的djpeg分别跟踪到了112个函数和50个函数(都以动态链接,但前者有-finstrument-functions编译选项,后者有-fpatchable-function-entry编译选项)。下面对比四次性能跟踪分析的结果;笔者为了简单直观,使用Flamegraph图来展示(在最上层的函数越宽,其占用的CPU时间越多),四个Flamegraph图分别为:

第一,jpeg_default:默认编译选项-fPIC -O2 -ggdb、静态链接,djpeg性能瓶颈:

[外链图片转存失败,源站可能有防盗链机制,建议将图片保存下来直接上传(img-xvg5R6s2-1654242317687)(./jpeg_default.png)]

第二,jpeg_static:编译选项-fPIC -O2 -ggdb -fpatchable-function-entry=5,静态链接,djpeg性能瓶颈:

[外链图片转存失败,源站可能有防盗链机制,建议将图片保存下来直接上传(img-ieMWVRo9-1654242317693)(./jpeg_static.png)]

第三,jpeg_inst:编译选项-fPIC -O2 -ggdb -finstrument-functions,动态链接,djpeg性能瓶颈:

[外链图片转存失败,源站可能有防盗链机制,建议将图片保存下来直接上传(img-rx34OmX3-1654242317696)(./jpeg_inst.png)]

上面这张图展示的侧写结果是四者中最为精确的;与其相应的侧写文本结果部分如下,主要是性能瓶颈(overhead)相关函数的调用次数及执行的时间:

  Total time   Self time       Calls  Function
  ==========  ==========  ==========  ====================
  720.544 ms    1.405 ms        3332  jpeg_read_scanlines
  367.390 ms    1.222 ms           1  main
  359.295 ms  613.673 us        1666  process_data_simple_main
  335.405 ms   89.070 ms         209  decompress_onepass
  144.469 ms  113.088 ms       65417  decode_mcu
   84.341 ms   84.341 ms      196251  jpeg_idct_float
   29.041 ms   27.710 ms      246069  jpeg_fill_bit_buffer
   23.276 ms    2.200 ms        1666  sep_upsample
   20.651 ms   20.651 ms        1666  ycc_rgb_convert
   17.505 ms   17.505 ms       65417  memset
    4.799 ms    1.037 ms        1666  put_pixel_rows
    3.761 ms    3.761 ms        1666  fwrite
    2.482 ms    2.339 ms       15488  jpeg_huff_decode
    1.353 ms  216.535 us         183  fill_input_buffer
    1.137 ms    1.137 ms         183  fread
  592.879 us    9.939 us           2  jpeg_CreateDecompress
  424.047 us  424.047 us        4998  fullsize_upsample
  281.349 us    6.659 us           1  jinit_memory_mgr

第四,jpeg_patch,编译选项-fPIC -O2 -ggdb -fpatchable-funtion-entry=5,动态链接,djpeg性能瓶颈:

[外链图片转存失败,源站可能有防盗链机制,建议将图片保存下来直接上传(img-N3BFAay3-1654242317699)(./jpeg_patch.png)]

可见,第三种djpeg的编译的方式,可以得到最精细的Flamegraph,第二种编译方式的侧写细节次之,二者都指出了对JPEG文件解码时,执行时间最长的四个函数分别为decompress_onepass/decode_mcu/jpeg_fill_bit_buffer以及jpeg_idct_float。第一种和第四种djpeg的编译方式得了不到可靠的结果。

Instrumentation (profiling,侧写)相关的编译选项

gcc编译器提供了多种不同的侧写相关的编译选项,侧写常常需要动态地修改运行中的内核、应用的代码,这个过程称为Instrumentation官方文档对这些编译选项作了说明,感兴趣的可以参考。笔者在上面提到了在函数入口外插入_mcount函数调用的-pg编译选项,之后又提到-finstrument-functions编译选项。与前者不同的是,后者在函数入口和退出前都会插入对特定函数的调用:

echo 'int hello(int x, int y) { return x * y; }' | gcc -fPIC -c -ggdb -finstrument-functions -O2 -o a.out -x c -
objdump -d a.out

反汇编的结果如下,可见这两个函数分别为__cyg_profile_func_enter/__cyg_profile_func_exit

0000000000000000 <hello>:
   0:	a9bd7bfd 	stp	x29, x30, [sp, #-48]!
   4:	910003fd 	mov	x29, sp
   8:	a90153f3 	stp	x19, x20, [sp, #16]
   c:	90000013 	adrp	x19, 0 <hello>
  10:	2a0103f4 	mov	w20, w1
  14:	f9400273 	ldr	x19, [x19]
  18:	a9025bf5 	stp	x21, x22, [sp, #32]
  1c:	aa1e03f6 	mov	x22, x30
  20:	d50320ff 	xpaclri
  24:	2a0003f5 	mov	w21, w0
  28:	aa1e03e1 	mov	x1, x30
  2c:	aa1303e0 	mov	x0, x19
  30:	94000000 	bl	0 <__cyg_profile_func_enter>
  34:	aa1603fe 	mov	x30, x22
  38:	d50320ff 	xpaclri
  3c:	aa1303e0 	mov	x0, x19
  40:	aa1e03e1 	mov	x1, x30
  44:	94000000 	bl	0 <__cyg_profile_func_exit>
  48:	1b147ea0 	mul	w0, w21, w20
  4c:	a94153f3 	ldp	x19, x20, [sp, #16]
  50:	a9425bf5 	ldp	x21, x22, [sp, #32]
  54:	a8c37bfd 	ldp	x29, x30, [sp], #48
  58:	d65f03c0 	ret

在基于glibcarm64/Linux系统环境下,glibc动态库提供了这两个函数的定义,但都是空函数:

$ gdb -q /usr/lib/aarch64-linux-gnu/libc-2.31.so 
Reading symbols from /usr/lib/aarch64-linux-gnu/libc-2.31.so...
Reading symbols from /usr/lib/debug/.build-id/c9/6a2b76aab47831ed75a76aaa29d573768329f0.debug...
(gdb) disassemble __cyg_profile_func_enter
Dump of assembler code for function __cyg_profile_func_enter:
   0x00000000000e3670 <+0>:	ret
End of assembler dump.
(gdb) disassemble __cyg_profile_func_exit
Dump of assembler code for function __cyg_profile_func_enter:
   0x00000000000e3670 <+0>:	ret
End of assembler dump.

同样的,一些C语言库未定义这两个函数(或者开发未自定义),通常编译链接会失败。例如,截止目前,musl库未提供这两个函数的定义:

$ mipsel-openwrt-linux-musl-gcc -finstrument-functions -o hello hello.c
/tmp/ccAXFV8u.o: In function `main':
hello.c:(.text+0x34): undefined reference to `__cyg_profile_func_enter'
hello.c:(.text+0x78): undefined reference to `__cyg_profile_func_exit'
collect2: error: ld returned 1 exit status

uftrace正是通过向被跟踪的应用(通常为子进程)加载自已提供动态库重新定义了这两个函数,实现了高效的应用性能的跟踪。这种方案(增加编译选项-finstrument-functions)可以避免如以-pg选项编译的应用在正常运行时生成不必要的侧写(profiling)文件的问题,但因其要频繁时调用这两个函数,也会带来一定的性能损失。另一个很有用的方案是使用-fpatchable-function-entry=N编译选项(详见此处的底部的官方文档),它会在所有函数(似乎除了main函数)的入口处增加指定的Nnop机器指令,这样uftrace在跟踪时(需通过-P指定函数名称)动态地给函数打上补丁,实现一个跳转,从而进入uftrace的性能监测代码中:

$ echo 'int hello(int x, int y) { return x * y; }' | gcc -fPIC -c -ggdb -fpatchable-function-entry=2 -O2 -o a.out -x c -
$ objdump -d a.out
0000000000000000 <hello>:
   0:	d503201f 	nop
   4:	d503201f 	nop
   8:	1b017c00 	mul	w0, w0, w1
   c:	d65f03c0 	ret

值得注意的是,该编译选项需要8.1.0及以上的gcc版本才能够支持。与编译选项-pg-finstrument-functions相比,这种方案是最不影响应用运行效率的方案,生成的应用可作发行版本。笔者在此前的一篇文章提到,SystemtapUSDT是在应用加增加一个nop指令,运行时会将该nop指令替换了陷入内核(trap-into-kernel)的中断指令(例如 int 3brk机器指令等);而对于uftrace而言,它会将函数入口处的nop指令替换为跳转到其他应用代码的指令,因此uftrace的跟踪效率要高一些,因为都是在应户态完成的,不用进行userspace-to-kernelspace的上下文切换。此外,笔者也曾实现了动态修改函数入口的指令的方案(详见该文章),用于应用的内存泄露问题的分析;不过由malloc/free等函数入口没有nop指令,笔者的操作要复杂很多,感兴趣的可以了解一下。

总结

uftrace的应用性能侧写,几乎都需要增加Instrumentation相关的编译选项。uftrace可以基于capstone实现对于没有Instrumentation编译选项的应用的性能跟踪,但笔者未尝试过。此外,Linux内核中的perf也不要求应用使用-pg/-finstrument-functions/fpatchable-function-entry=N编译选项;但以笔者的经验,被跟踪的应用应是带有(调试)符号表的,因为不论是uftrace还是perf,都会用到elfutils库对应用进行符号解析,从而一步到位地确定应用的性能瓶颈相关的函数。

 类似资料: