[hellogcc] Re: [hellogcc] Re: [投稿]一个用KGTP分析应用程序性能瓶颈的例子
- From: Hui Zhu <teawater@xxxxxxxxx>
- To: hellogcc@xxxxxxxxxxxxx
- Date: Sun, 8 Apr 2012 16:45:46 +0800
2012/4/8 Yao Qi <qiyaoltc@xxxxxxxxx>:
> On Sat, Apr 07, 2012 at 09:06:06PM +0800, Hui Zhu wrote:
>> http://code.google.com/p/kgtp/wiki/hotcode
>>
>> 概述
>> 从KGTP (http://code.google.com/p/kgtp/)
>> 20120319开始，其包含了一个通过记录并分析中断处理时候的取得的PC值从而得到Linux
>> kernel或者用户层程序的热点代码。本篇文档就是一个使用它分析程序性能瓶颈的一个例子。
>> 这个例子需要KGTP 20120406 或者以上的版本。
>>
>> 性能问题描述
>> KGTP包含了一个脚本getmod.py。如果一个正在调试Linux kernel的GDB调用这个脚本，其将自动装载所有插入这个Linux
>> kernel的内核模块的调试信息，这样GDB可以更好的对这些模块进行调试。这个脚本既能在连接到KGTP上的GDB上使用，也可以和连接上其他东西例如QEMU的GDB一起用。(请到
>> http://code.google.com/p/kgtp/wiki/HOWTO#How_to_use_getmod.py
>> 去访问关于这个脚本的更多信息)
>> 这个脚本有一个问题就是执行速度很不理想，这介绍使用KGTP分析这个问题。
>>
>> 分析过程和结果
>> #插入KGTP模块
>> sudo insmod gtp.ko
>> #打开要分析的GDB
>> sudo gdb ./vmlinux
>> #打开另一个终端并取得这个GDB的pid
>> ps -e | grep gdb
>> 14632 pts/1 00:00:00 gdb
>> #调用hotcode.py。只需要输入PID，其他选项直接回车即可。
>> sudo gdb ./vmlinux -x ~/kernel/svn/trunk/add-ons/hotcode.py
>> Which part of code you want trace? [(b)oth], (u)ser, (k)ernel:
>> Please input the pid of task that you want to trace - one per line.
>> If not set any task, will trace all code in the Linux kernel.
>> task pid (use empty to stop pid input):14632
>> Please input the debug binary of task if you want to change it
>> [/usr/local/bin/gdb]:
>> task pid (use empty to stop pid input):
>> Which way you want to output hotcode info when ctrl-c? [(h)tml], (t)ty:
>> Which file you want to save the html output? [./hotcode.html]:
>> Show line number (0 meas all)? [20]:
>> Remote debugging using /sys/kernel/debug/gtp
>> 0x0000000000000000 in irq_stack_union ()
>> Do you load the symbol from LKM? (y)es, [(n)o]:
>> #在GDB这边连接KGTP然后调用getmod.py
>> target remote /sys/kernel/debug/gtp
>> source ~/kernel/svn/trunk/getmod.py
>> #getmod.py结束后，到hotcode.py那边输入ctrl-c。
>> 于是可以在当前命令取得hotcode.html，我将其发布在http://teawater.users.sourceforge.net/hotcode/normal.html。;
>>
>> 用浏览器打开这个文件，我们可以看到getmod.py的代码热点信息。
>> "User space hotcode list" (37716) 和 "Kernel space hotcode list" (903)
>> 后面的数字是用户空间代码和内核空间代码被中断的次数。从这些数字，我们可以知道执行用户空间代码花去了更多的时间。
>> 从"User space hotcode list"的"Hot functions
>> list"，我们可以看到函数"/usr/local/bin/gdb:strcmp_iw"
>> (12776)和函数"/usr/local/bin/gdb:lookup_partial_symbol"
>> (9059)是最热的函数。如果需要，我们还可以点函数名来详细更详细的信息。查一下代码我们就可以知道这两个函数大部分的调用都和符号分析有关。符号分析是这个脚本执行速度的一个瓶颈。
>> 解决方案和结果
>> 因为我们已经有了函数名，所以我们可以取得stack dump：
>
> 这句不是很明白。 为什么有了"函数名"，就可以取得"stack dump" 呢？
嘿嘿 果然是行家一伸手就发现了问题的重点
其实这里我是想打马虎眼糊弄过去的 因为要运行程序设置断点 然后BT 我是很阴暗的觉得如果写上会淡化了KGTP随时分析 随时停止的概念
不过回头我会加上去 :)
>
>
>>
>> #0 strcmp_iw (string1=0x7f4685d5611c "pgd_t", string2=0x3fed870
>> "attrs") at ../../src/gdb/utils.c:2627
>> #1 0x000000000063ebaa in lookup_partial_symbol (pst=<optimized out>,
>> name=<optimized out>, global=<optimized out>, domain=VAR_DOMAIN)
>> at ../../src/gdb/psymtab.c:749
>> #2 0x00000000006400af in lookup_symbol_aux_psymtabs
>> (objfile=<optimized out>, block_index=1, name=0x4041d80 "attrs",
>> domain=VAR_DOMAIN)
>> at ../../src/gdb/psymtab.c:510
>> #3 0x000000000063af95 in lookup_symbol_aux_quick (objfile=0x2f28d90,
>> kind=1, name=0x4041d80 "attrs", domain=VAR_DOMAIN)
>> at ../../src/gdb/symtab.c:1522
>> #4 0x000000000063b183 in lookup_static_symbol_aux (name=0x4041d80
>> "attrs", domain=VAR_DOMAIN) at ../../src/gdb/symtab.c:1336
>> #5 0x000000000063b53b in lookup_symbol_aux (is_a_field_of_this=0x0,
>> language=<optimized out>, domain=VAR_DOMAIN, block=0x0,
>> name=0x4041d80 "attrs") at ../../src/gdb/symtab.c:1316
>> #6 lookup_symbol_in_language (name=<optimized out>, block=0x0,
>> domain=VAR_DOMAIN, lang=<optimized out>, is_a_field_of_this=0x0)
>> at ../../src/gdb/symtab.c:1200
>> #7 0x00000000005e125f in classify_name (block=0x0) at
>> ../../src/gdb/c-exp.y:2438
>> #8 0x00000000005e3483 in c_lex () at ../../src/gdb/c-exp.y:2563
>> 函数classify_name将返回一个名字的类型，而大部分时候getmod.py分析的名字都不是一个符号，所以函数lookup_symbol大部分时候返回的都是NULL。所以我在函数lookup_symbol中加了一个哈希表。如果lookup_symbol返回NULL，就将函数参数加入哈希表。在这个函数开始的地方检查哈希表，如果参数和一个哈希表项相同，则直接返回NULL。可以到
>> http://teawater.users.sourceforge.net/hotcode/speedup.txt 取得这个临时PATCH。
>> 在修改之前，我在一个插入了67个模块的Linux kernel上调用getmod.py，时间记录是：
>>
>> 239.275789976
>> 242.414674997
>> 234.347954035
>> 237.436943054
>> 244.659180164
>> 修改之后：
>>
>> 110.593796968
>> 109.023880005
>> 107.977679014
>> 108.905900002
>> 108.117362976
>> 速度提高大约是54%。
>> 你可以从 http://teawater.users.sourceforge.net/hotcode/speedup.html
>> 得到新的htocode.html。可以看到 strcmp_iw 和 lookup_partial_symbol 不像之前那么热了。
>>
>
> 这是一个很好的story :)
>
>> hotcode.py的优势
>> 从前面的分析我们可以知道hotcode.py可以取得一个应用程序(也支持多个应用程序)的热代码信息而不需要重新编译这个程序连接特殊库什么的。
>> 而且hotcode.py可以同时显示用户空间代码和内核空间代码的信息。
>
> 现在bt能 cross user-space/kernel space 吗，现在？就是能把程序从user
> space 的stack 一直dump的kernel space？ 现在gdb应该做不了吧？
不能 热度分析没有做BT 那样的力度太大 分析的力度过大 怕会影响效率了
我只是根据CS的不同 对不同的镜像查PC信息 multi-inferior在其中起了很大作用
>
>> 和其他KGTP的功能一样，hotcode.py的trace是可以动态的开始和结束而且不需要停止应用程序。所以其对例如线上服务的程序会更友好。
>> 普通GDB和hotcode.py一起使用的时间记录是：
>>
>> 255.329950094
>> 252.469471931
>> 255.546139002
>> 252.384520054
>> 255.049283028
>> 速度降低大约6%。
>
> 你的base是什么？6%已经是个很不错的数字了。
原始的数据在上面 就是做速度比较那里
这主要仰仗于 kprobes-optimization 的强悍实力 如果是不支持 kprobes-optimization 的环境 速度至少下去一半
当然我自己做的gtp_rb buffer也有些小功劳 嘿嘿
>
> --
> Yao Qi <qiyaoltc AT gmail DOT com>
>
> You should emulate your heros, but don't carry it too far. Especially
> if they are dead.
>
Other related posts:
- » [hellogcc] Re: [hellogcc] Re: [投稿]一个用KGTP分析应用程序性能瓶颈的例子 - Hui Zhu
