{"id":6,"date":"2009-10-07T11:41:50","date_gmt":"2009-10-07T01:41:50","guid":{"rendered":"http:\/\/anton.ozlabs.org\/blog\/?p=6"},"modified":"2010-10-21T09:13:56","modified_gmt":"2010-10-20T23:13:56","slug":"linux-static-tracepoints","status":"publish","type":"post","link":"https:\/\/anton.ozlabs.org\/blog\/2009\/10\/07\/linux-static-tracepoints\/","title":{"rendered":"Linux Static Tracepoints"},"content":{"rendered":"

Linux has had dynamic trace functionality for a long time in the form of kprobes. Kprobes provides a kernel API for placing probes on kernel instructions and they can be exploited directly via a kernel module, or via systemtap<\/a> which provides a high level scripting language. Dynamic tracing has a number of advantages – it has zero overhead when disabled and probes can be placed on almost any instruction in the kernel, not just where a kernel developer thinks you should.<\/p>\n

All this flexibility does have some downsides. An executed kprobe has a significant overhead since it uses breakpoints and exception handlers. Having said that, there are patches<\/a> that avoid the breakpoint and instead branch directly to the handler. Another issue is probe placement; kprobes are easily placed at function entry and exit but if you need to probe inside a function or probe local variables then you really need systemtap and a kernel compiled with CONFIG_DEBUG_INFO. On the other hand a static tracepoint can be placed anywhere in a function and can be passed any important local variables. Various static tracepoint patches have been available for Linux, but as of 2.6.32 a complete implementation is in mainline.<\/p>\n

Adding a static tracepoint is very simple, an example can be found here<\/a>. In this case I am adding to an existing trace group (irq), so I only need the tracepoint definitions and the tracepoints themselves. An explanation of the 5 parts of a tracepoint definition can be found in linux\/samples\/trace_events\/trace-events-sample.h<\/a>. For more complicated scenarios, refer to the files in linux\/samples\/trace_events\/<\/a><\/p>\n

Using static tracepoints<\/h2>\n

There are only a few steps to make use of static tracepoints. First ensure that debugfs is mounted. Most distros mount it on \/sys\/kernel\/debug:<\/p>\n

# mount | grep debugfs\r\n\r\ndebugfs on \/sys\/kernel\/debug type debugfs (rw)<\/pre>\n
A list of available tracepoints can be found in tracing\/available_events:<\/p>\n
# cat \/sys\/kernel\/debug\/tracing\/available_events\r\n\r\nskb:skb_copy_datagram_iovec\r\nskb:kfree_skb\r\nblock:block_rq_remap\r\nblock:block_remap\r\nblock:block_split\r\nblock:block_unplug_io\r\nblock:block_unplug_timer\r\n...<\/pre>\n
Since we added our tracepoints to the irq group, we can find them in tracing\/events\/irq:<\/p>\n
# ls \/sys\/kernel\/debug\/tracing\/events\/irq\/\r\n\r\nenable  irq_handler_entry  softirq_entry  tasklet_entry\r\nfilter  irq_handler_exit   softirq_exit   tasklet_exit<\/pre>\n
Enable the tasklet tracepoints:<\/p>\n
# echo 1 >  \/sys\/kernel\/debug\/tracing\/events\/irq\/tasklet_entry\/enable\r\n# echo 1 >  \/sys\/kernel\/debug\/tracing\/events\/irq\/tasklet_exit\/enable<\/pre>\n
And the output is available in the trace buffer:<\/p>\n
# cat \/sys\/kernel\/debug\/tracing\/trace\r\n\r\n# tracer: nop\r\n#\r\n#           TASK-PID    CPU#    TIMESTAMP  FUNCTION\r\n#              | |       |          |         |\r\n-0     [000]   327.349213: tasklet_entry: func=.rpavscsi_task\r\n-0     [000]   327.349217: tasklet_exit: func=.rpavscsi_task<\/pre>\n
When finished, we can disable the tracepoints. There are enable files at all levels of the hierarchy, so we can disable all tracepoints in one go:<\/p>\n
# echo 0 > \/sys\/kernel\/debug\/tracing\/events\/enable<\/pre>\n
Using static tracepoints in kernel modules<\/h2>\n
Kernel modules can also make use of static tracepoints. A simple module that hooks the tasklet_entry tracepoint and printks the function name of the tasklet might look like (I’ve called it tracepoint-example.c):<\/p>\n
#include <linux\/module.h>\r\n#include <trace\/events\/irq.h>\r\n\r\nstatic void probe_tasklet_entry(struct tasklet_struct *t)\r\n{\r\n        printk(\"tasklet_entry %pf\\n\", t->func);\r\n}\r\n\r\nstatic int __init trace_init(void)\r\n{\r\n        WARN_ON(register_trace_tasklet_entry(probe_tasklet_entry));\r\n        return 0;\r\n}\r\n\r\nstatic void __exit trace_exit(void)\r\n{\r\n        unregister_trace_tasklet_entry(probe_tasklet_entry);\r\n}\r\n\r\nmodule_init(trace_init)\r\nmodule_exit(trace_exit)\r\nMODULE_LICENSE(\"GPL\");<\/pre>\n
If you are wondering, %pf is a printk formatter trick to pretty print a function name so you don’t have to go searching for the address in System.map.<\/p>\n
Here is a Makefile to go with it:<\/p>\n
obj-m := tracepoint-example.o\r\nKDIR := \/lib\/modules\/$(shell uname -r)\/build\r\nPWD := $(shell pwd)\r\ndefault:\r\n        $(MAKE) -C $(KDIR) SUBDIRS=$(PWD) modules<\/pre>\n","protected":false},"excerpt":{"rendered":"
Linux has had dynamic trace functionality for a long time in the form of kprobes. Kprobes provides a kernel API for placing probes on kernel instructions and they can be exploited directly via a kernel module, or via systemtap which provides a high level scripting language. Dynamic tracing has a number of advantages – it … Continue reading “Linux Static Tracepoints”<\/span><\/a><\/p>\n","protected":false},"author":1,"featured_media":0,"comment_status":"closed","ping_status":"open","sticky":false,"template":"","format":"standard","meta":[],"categories":[3],"tags":[5],"_links":{"self":[{"href":"https:\/\/anton.ozlabs.org\/blog\/wp-json\/wp\/v2\/posts\/6"}],"collection":[{"href":"https:\/\/anton.ozlabs.org\/blog\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/anton.ozlabs.org\/blog\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/anton.ozlabs.org\/blog\/wp-json\/wp\/v2\/users\/1"}],"replies":[{"embeddable":true,"href":"https:\/\/anton.ozlabs.org\/blog\/wp-json\/wp\/v2\/comments?post=6"}],"version-history":[{"count":69,"href":"https:\/\/anton.ozlabs.org\/blog\/wp-json\/wp\/v2\/posts\/6\/revisions"}],"predecessor-version":[{"id":241,"href":"https:\/\/anton.ozlabs.org\/blog\/wp-json\/wp\/v2\/posts\/6\/revisions\/241"}],"wp:attachment":[{"href":"https:\/\/anton.ozlabs.org\/blog\/wp-json\/wp\/v2\/media?parent=6"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/anton.ozlabs.org\/blog\/wp-json\/wp\/v2\/categories?post=6"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/anton.ozlabs.org\/blog\/wp-json\/wp\/v2\/tags?post=6"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}