Re: Ideas to measure kernel function execution time using perf

[Qu Wenruo <quwenruo@cn.fujitsu.com>]

Masami Hiramatsu wrote on 2016/04/20 08:37 +0900:
> On Tue, 19 Apr 2016 09:42:49 +0800
> Qu Wenruo <quwenruo@cn.fujitsu.com> wrote:
>
>> Hi,
>>
>> Is there any method to measure kernel function execution time for
>> specific functions using perf?
>>
>> Current ftrace events can only record the timestamp when hitting the
>> trace point (along with some other info).
>>
>> I'm OK adding new ftrace events into kernel, but even after adding such
>> ftrace events, is it possible to use perf to calculate the function
>> execution time?
>
> Would you mean "perf probe"? :)
>
> Actually, kprobes on the function entry point (on x86) automatically
> use ftrace and also you can get function parameters, e.g.
>
> # perf probe -a 'YOUR_TARGET_FUNCTION $params'
>
> And with using ftrace, you can get function duration and parameters,
> for example,
>
> # perf probe -a 'vfs_read $params'
> Added new event:
>    probe:vfs_read       (on vfs_read with $params)
>
> You can now use it in all perf tools, such as:
>
> 	perf record -e probe:vfs_read -aR sleep 1
>
> # cd /sys/kernel/debug/tracing/
> # echo vfs_read > set_ftrace_filter
> # echo 1 > events/probe/vfs_read/enable
> # echo function_graph > current_tracer
> # echo 0 > trace
> # less trace
> # tracer: function_graph
> #
> # CPU  DURATION                  FUNCTION CALLS
> # |     |   |                     |   |   |   |
>   2)               |  /* vfs_read: (vfs_read+0x0/0x130) file=0xffff88036a959200 buf=0x7ffe460abb70 count=0x10 pos=0xffff880052d1bf20 */
>   3)               |  /* vfs_read: (vfs_read+0x0/0x130) file=0xffff88024524b900 buf=0x7ffcdee7ec57 count=0x1 pos=0xffff88023942ff20 */
>   2)   0.538 us    |  vfs_read();
>   3)               |  vfs_read() {
>   2)               |  /* vfs_read: (vfs_read+0x0/0x130) file=0xffff8803c24ba400 buf=0xd8efdc count=0x1ff0 pos=0xffff880052d1bf20 */
>   2)   0.979 us    |  vfs_read();
> ...
>
> Thanks,
>
Wow, that's cool.

Thanks for the info, I think it would be good enough for my use case.

Thanks,
Qu