Gprof在Zynq-7000开发板上的实验： - 如何使用gprof对软件做profiling （一）

四．Gprof在Zynq-7000开发板上的实验：

Hardware: ZC706 evaluation board(其他开发板亦可，只是细节上会略有不同)
Software: Xilinx 14.7 Linux pre-built
Tool chain: PetaLinux 2013.04 tool chain

为了简单起见，笔者没有重新编译Linux，而是使用的Xilinx 14.7 Linux pre-built。

在Linux Host上下载libjpeg后执行以下命令即可完成编译：
cd
tar zxvf /path/to/jpegsrc.v9.tar.gz
cd jpeg-9
./configure --prefix=/home/wave/xilinx/libjpeg/jpeg-bin --host=arm-xilinx-linux-gnueabi
Note: 参数--prefix指明编译结果的安装位置，参数--host指明交叉编译工具链的前缀。在使用PetaLinux 2013.04 tool chain之前需要先到其目录下source settings.sh
这里需要编辑Makefile，在CFLAGS和LDFLAGS中增加-pg选项。
make
make install

这时编译完成后的可执行程序cjpeg和djpeg使用到了.so文件，不适合用gprof。关于这一点可以用ldd命令确认。所以还需要用以下命令手工编译出statically linked binary，拷贝到libjpeg安装目录下的bin目录下，方便后期的profiling。这些命令可以通过观察libjpeg的make过程得到。

arm-xilinx-linux-gnueabi-gcc -std=gnu99 -g -O2 -pg -o djpeg-s djpeg.c wrppm.c wrgif.c wrtarga.c wrrle.c wrbmp.c rdcolmap.c cdjpeg.c ../jpeg-bin/lib/libjpeg.a
arm-xilinx-linux-gnueabi-gcc -std=gnu99 -g -O2 -pg -o cjpeg-s cjpeg.c rdppm.c rdgif.c rdtarga.c rdrle.c rdbmp.c rdswitch.c cdjpeg.c ../jpeg-bin/lib/libjpeg.a

然后将jpeg-bin下的所有内容打包，和Xilinx 14.7 Linux pre-built image files，以及数据文件park-2880x1800.jpg拷贝到SD卡中，从SD卡启动ZC706开发板。

在开发板的console上，执行以下命令
mount /dev/mmcblk0p1 /mnt
mkdir work
cd work
tar zxvf /mnt/jpeg-bin.tar.gz
cd jpeg-bin/bin
cp /mnt/park-2880x1800.jpg .
export LD_LIBRARY_PATH=/home/root/work/jpeg-bin/lib

time ./djpeg-s -bmp park-2880x1800.jpg > result.bmp
mv gmon.out gmon-ds.out
time ./cjpeg-s ./result.bmp > ./result.jpg
mv gmon.out gmon-cs.out

对于djpeg-s和cjpeg-s，执行时间如下所示。我们可以看到这两个应用程序的主要执行时间实在用户空间的，还是比较适合用gprof来做profiling的。
real 0m4.258s
user 0m4.200s
sys 0m0.050s

real 0m4.289s
user 0m4.230s
sys 0m0.050s

然后我们可以把执行结果拷贝到SD卡中，准备拿到Linux Host上进行分析。
cp result.* /mnt
cp gmon*.out /mnt
umount /mnt

在Linux Host上，我们可以通过以下命令看到profiling的结果：
gprof -b djpeg-s gmon-ds.out >report-ds.txt
gprof -b cjpeg-s gmon-cs.out >report-cs.txt

关于JPEG解码Profiling结果的主要部分如下：
Flat profile:

Each sample counts as 0.01 seconds.
% cumulative self self total
time seconds seconds calls ms/call ms/call name
20.95 0.31 0.31 1800 0.17 0.17 ycc_rgb_convert
19.60 0.60 0.29 40680 0.01 0.01 jpeg_idct_16x16
17.57 0.86 0.26 20340 0.01 0.02 decode_mcu
14.87 1.08 0.22 81000 0.00 0.00 jpeg_idct_islow
13.51 1.28 0.20 finish_output_bmp
6.08 1.37 0.09 1175224 0.00 0.00 jpeg_fill_bit_buffer
5.41 1.45 0.08 put_pixel_rows
2.03 1.48 0.03 127506 0.00 0.00 jpeg_huff_decode

关于JPEG编码Profiling结果的主要部分如下：
Flat profile:

Each sample counts as 0.01 seconds.
% cumulative self self total
time seconds seconds calls ms/call ms/call name
24.63 0.50 0.50 preload_image
21.18 0.93 0.43 20340 0.02 0.02 encode_mcu_huff
13.79 1.21 0.28 40680 0.01 0.01 jpeg_fdct_16x16
12.81 1.47 0.26 81180 0.00 0.01 forward_DCT
8.87 1.65 0.18 81000 0.00 0.00 jpeg_fdct_islow
8.37 1.82 0.17 1800 0.09 0.09 rgb_ycc_convert
5.42 1.93 0.11 1 110.00 110.00 get_24bit_row
3.45 2.00 0.07 __divsi3
0.49 2.01 0.01 113 0.09 10.27 compress_data
0.49 2.02 0.01 __aeabi_uidivmod
0.49 2.03 0.01 jpeg_fdct_ifast

怎么样？是不是很容易？

如果反复profiling几次，就会注意到profiling结果里面的顺序会有所变化。主要原因还是采样的时间太短，只有4.2秒，如果延长profiling的时间，得到的结果会更加逼近真实值。

五．关于sprof：

sprof主要用于Gprof的补充，分析程序的共享库(需要-g编译)。一般的使用步骤：
1. export LD_PROFILE_OUTPUT=${PWD}
2. export LD_PROFILE=abc.so.A.B
3. export LD_LIBRARY_PATH=/path/to/lib/
4. 执行使用该so的主程序
5. 执行sprof so_file_name.so so_file_name.so.profile
注意：在实际执行时发现LD_PROFILE指向的文件名后有可能需要加上实际的数字才可以。

在本次实验中，在生成profiling report的时候会发生错误：
sprof libjpeg.so.9 libjpeg.so.9.profile
Inconsistency detected by ld.so: dl-open.c: 611: _dl_open: Assertion `_dl_debug_initialize (0, args.nsid)->r_state == RT_CONSISTENT' failed!

按照Google Search Result的说法，在老版本的glibc里面会有这个问题，新版本有可能已经解决了。不过因为oprofile完全可以profiling shared library，所以只是简单的尝试了一下，没有继续深入研究这个话题。上面的经验或许会对有兴趣的开发者有所借鉴。

六．小结:

尽管gprof有各种这样那样的限制和不足，如果能够合理规避，对于代码执行时间大部分是在用户空间的计算密集型的应用程序，gprof还是非常方便好用的。