Call graph tracing
Problem
An early step in understanding a piece of software is to trace function calls coming and going.
Scripts
Elaborated from the systemtap tutorial, here is a dynamic call graph trace. It uses the thread_indent tapset function for per-thread nesting, and
function trace(entry_p) { if(tid() in trace) printf("%s%s%s\n",thread_indent(entry_p), (entry_p>0?"->":"<-"), probefunc()) } global trace probe kernel.function(@1).call { if (execname() == "stapio") next # skip our own helper process trace[tid()] = 1 trace(1) } probe kernel.function(@1).return { trace(-1) delete trace[tid()] } probe kernel.function(@2).call { trace(1) } probe kernel.function(@2).return { trace(-1) }
Output
This script is parametrized with two strings. The first is the name of the trigger function: its lifetime on the call stack enables or disables tracing on a per-thread basis. The second is a pattern of probe functions whose entry/exit we want to trace. This script needs to be interrupted by hand when your curiosity is satisfied.
# stap para-callgraph.stp sys_read '*@fs/*.c' [...] 0 klogd(1391):->sys_read 14 klogd(1391): ->fget_light 22 klogd(1391): <-fget_light 27 klogd(1391): ->vfs_read 35 klogd(1391): ->rw_verify_area 43 klogd(1391): <-rw_verify_area 49 klogd(1391): ->kmsg_read 0 sendmail(1696):->sys_read 17 sendmail(1696): ->fget_light 26 sendmail(1696): <-fget_light 34 sendmail(1696): ->vfs_read 44 sendmail(1696): ->rw_verify_area 52 sendmail(1696): <-rw_verify_area 58 sendmail(1696): ->proc_file_read 70 sendmail(1696): ->loadavg_read_proc 84 sendmail(1696): ->proc_calc_metrics 92 sendmail(1696): <-proc_calc_metrics 95 sendmail(1696): <-loadavg_read_proc 101 sendmail(1696): <-proc_file_read 106 sendmail(1696): ->dnotify_parent 115 sendmail(1696): <-dnotify_parent 119 sendmail(1696): ->inotify_dentry_parent_queue_event 127 sendmail(1696): <-inotify_dentry_parent_queue_event 133 sendmail(1696): ->inotify_inode_queue_event 141 sendmail(1696): <-inotify_inode_queue_event 146 sendmail(1696): <-vfs_read 151 sendmail(1696):<-sys_read [...] ^C
Lessons
Convenient functionality like per-thread nesting and timekeeping is easily stored in the tapset library (the thread_indent function). It would be easy to add filtering predicates on process name, user name, or whatnot. One may also use much broader wildcards for selecting target modules to trace, but the data can quickly become overwhelming (both to you, the user, and to the system).
See also http://sourceware.org/systemtap/examples/keyword-index.html#CALLGRAPH.