Linux Function Call Catcher

I wrote another stupid device driver, 'allie.'

'allie' uses kprobe which is a built-in feature in RHEL4 or later.
If you want to know call trees of a particular in-kernel function such as 'ip6_xmit()' but don't want to recompile the entire kernel, 'allie' will help you very much.
It's available here under GPL2 as usual. :)

When you want to know function call graphs of a particular in-kernel function, for example, 'mpage_bio_submit', then you can see them by installing 'allie' with insmod parameters like the following:

# insmod allie.ko symbol= mpage_bio_submit count=3

Here are several notes.

1. Lines in red below are kprobe and allie origin trace entries.
2. Under Linux(x86 and x86_64) environment, we often see actually unrelated function call entries because of Linux linkage convention as I wrote here. Don't be confused.
3. count=3 means to show only 3 stack traces because in-kernel functions are usually called very frequently and your /var/log/messages could be full.
4. kprobe uses 'int3', thus we cannot catch function calls under interrupt disabled state.
   

The below example is excerpted from a log file included in allie-1.0.tar.gz.
-----
Apr 19 20:06:59 rhel5 syslogd 1.4.1: restart.
[snip]
Apr 19 20:47:14 rhel5 kernel: allie_init: called
Apr 19 20:47:14 rhel5 kernel: allie_init: flags=00000000, action=1, count=3, verbose=0
Apr 19 20:47:14 rhel5 kernel: allie_init: symbol=mpage_bio_submit
Apr 19 20:47:42 rhel5 kernel: [] allie_pre_handler+0x3b/0x61 [allie]
Apr 19 20:47:42 rhel5 kernel: [] kprobe_exceptions_notify+0x187/0x3dc
Apr 19 20:47:42 rhel5 kernel: [] notifier_call_chain+0x19/0x29
Apr 19 20:47:42 rhel5 kernel: [] do_int3+0x39/0x6a
Apr 19 20:47:42 rhel5 kernel: [] int3+0x1e/0x24
Apr 19 20:47:42 rhel5 kernel: [] mpage_bio_submit+0x1/0x1d
Apr 19 20:47:42 rhel5 kernel: [] mpage_readpages+0xec/0xf9
Apr 19 20:47:42 rhel5 kernel: [] get_page_from_freelist+0x96/0x310
Apr 19 20:47:42 rhel5 kernel: [] common_interrupt+0x1a/0x20
Apr 19 20:47:42 rhel5 kernel: [] ext3_readpages+0x0/0x15 [ext3]
Apr 19 20:47:42 rhel5 kernel: [] ext3_readpages+0x0/0x15 [ext3]
Apr 19 20:47:42 rhel5 kernel: [] __do_page_cache_readahead+0x11f/0x1c6
Apr 19 20:47:42 rhel5 kernel: [] ext3_get_block+0x0/0xbd [ext3]
Apr 19 20:47:42 rhel5 kernel: [] blockable_page_cache_readahead+0x46/0x99
Apr 19 20:47:42 rhel5 kernel: [] page_cache_readahead+0xb3/0x178
Apr 19 20:47:42 rhel5 kernel: [] do_generic_mapping_read+0x137/0x468
Apr 19 20:47:42 rhel5 kernel: [] __generic_file_aio_read+0x16f/0x1b6
Apr 19 20:47:42 rhel5 kernel: [] file_read_actor+0x0/0xd1
Apr 19 20:47:43 rhel5 kernel: [] generic_file_aio_read+0x3b/0x42
Apr 19 20:47:43 rhel5 kernel: [] do_sync_read+0xb6/0xf1
Apr 19 20:47:43 rhel5 kernel: [] autoremove_wake_function+0x0/0x2d
Apr 19 20:47:43 rhel5 kernel: [] sched_balance_self+0x1bf/0x208
Apr 19 20:47:43 rhel5 kernel: [] do_sync_read+0x0/0xf1
Apr 19 20:47:43 rhel5 kernel: [] vfs_read+0x9f/0x141
Apr 19 20:47:43 rhel5 kernel: [] kernel_read+0x32/0x43
Apr 19 20:47:43 rhel5 kernel: [] prepare_binprm+0xc7/0xcc
Apr 19 20:47:43 rhel5 kernel: [] do_execve+0xf6/0x1f5
Apr 19 20:47:43 rhel5 kernel: [] sys_execve+0x2a/0x4a
Apr 19 20:47:43 rhel5 kernel: [] syscall_call+0x7/0xb

(Updated slightly on April 29, 2007)