Ftrace: Fedora Mini-Conf Session at FOSS.in’10
I gave a talk on Ftrace in Fedora Mini-Conf at FOSS.in’10.
The slides are at https://fedoraproject.org/wiki/File:Fedora_Ftrace.pdf
I started my presentation with an example. I setup function_ftrace as current_tracer and set
the trace filter for all the ext3 functions and started the tracing:
$ echo function_ftrace > /sys/kernel/debug/tracing/current_tracer $ echo ext3* > /sys/kernel/debug/tracing/set_ftrace_filter $ echo 1 > /sys/kernel/debug/tracing/tracing_on
Then after creating a ext3 filesystem, I created a directory on it.
We got a trace in the /sys/kernel/debug/tracing/trace file. A snippet from it :-
1) ! 23988.06 us | } /* ext3_new_inode */ 1) | ext3_bread() { 1) | ext3_getblk() { 1) | ext3_get_blocks_handle() { 1) 0.461 us | ext3_block_to_path(); 1) 0.365 us | ext3_get_branch(); 1) | ext3_new_blocks() { 1) | ext3_dirty_inode() { 1) 0.602 us | ext3_journal_start_sb(); 1) | ext3_mark_inode_dirty() { 1) | ext3_reserve_inode_write() {
This kind of stuff helps when you try to understand the kernel code because you know what functions are getting called.
Second example I took to get the function trace when the system system OOPs. I did following setting to get the trace:-
echo function_graph > /sys/kernel/debug/tracing/current_tracer echo 5 > /sys/kernel/debug/tracing/buffer_size_kb echo 1 > /sys/kernel/debug/tracing/tracing_on echo 1 > /proc/sys/kernel/ftrace_dump_on_oops
I used one simple character driver for that. It can be downloaded from
http://neependra.net/kernel/char-dev-read-write-oop.tar.gz
I had following for the read operation
static ssize_t mycdrv1_read (struct file *file, char __user * buf, size_t lbuf, loff_t * ppos) { *(int *)0 = 0; }
After inserting the module I created the character device
insmod char-read-write.ko mknod /dev/mycdrv1 c 700 0
Just after doing the read to the device OOPs happened and got following in the in the /var/log/messages file
mycdrv1_read() { raw_local_irq_enable(); ........... find_vma(); bad_area() { up_read(); ............ is_prefetch.clone.13() { convert_ip_to_linear(); pagefault_disable(); pagefault_enable(); } oops_enter() {
Then I showed an example with sched_switch tracer and showed how we can trace all the function of a particular module.
</pre> $ echo sched_switch > /sys/kernel/debug/tracing/current_tracer $ echo :mod:zfs > /sys/kernel/debug/tracing/set_ftrace_filter
I also also showed how to look at the stack usage. To enable stack strace
echo 1 > /proc/sys/kernel/stack_tracer_enabled
and look at /sys/kernel/debug/tracing/stack_trace file, which will have something like.
Depth Size Location (15 entries) ----- ---- -------- 0) 1544 352 ext3_get_blocks_handle+0xa0/0x920 1) 1192 0 return_to_handler+0x0/0x2f 2) 1192 96 ext3_get_block+0xbb/0xf8 3) 1096 0 return_to_handler+0x0/0x2f 4) 1096 128 generic_block_bmap+0x3c/0x42
It tells you how much kernel stack is used and usage from each function. This was very helpful for me while doing the port
of ZFS on Linux. We have limited kernel stack on Linux but this not the case in Solaris.
I then talked about trace-cmd and kernelshark.
Pingback: Tweets that mention » Ftrace: Fedora Mini-Conf Session at FOSS.in’10 neependra -- Topsy.com
Thank you, I have recently been searching for information about this topic for ages and yours is the best I have discovered so far.
Pingback: » FOSS.in’10 Experience neependra
Pingback: » 2010.. The year it was. neependra