Tuesday, 29 March 2011

How to use perf-probe

Dynamic tracepoints are an observability feature that allows functions
and even arbitrary lines of source code to be instrumented without recompiling
the program. Armed with a copy of the program's source code, tracepoints can
be placed anywhere at runtime and the value of variables can be dumped each
time execution passes the tracepoint. This is an extremely powerful technique
for instrumenting complex systems or code written by someone else.

I recently investigated issues with CD-ROM media change
inside a KVM guest. Using QEMU tracing I was able to
instrument the ATAPI CD-ROM emulation inside QEMU and observe the commands
being sent to the CD-ROM. I complemented this with perf-probe(1) to
instrument the sr and cdrom drivers in the Linux host and
guest kernels. The power of perf-probe(1) was key to understanding the
state of the CD-ROM drivers without recompiling a custom debugging kernel.

Overview of perf-probe(1)

The probe subcommand of perf(1) allows dynamic tracepoints
to be added or removed inside the Linux kernel
. Both core kernel and modules
can be instrumented.

Besides instrumenting locations in the code, a tracepoint can also fetch
values from local variables, globals, registers, the stack, or memory. You can
combine this with perf-record -g callgraph recording to get stack
traces when execution passes probes. This makes perf-probe(1)
extremely powerful.

Requirements

A word of warning: use a recent kernel and perf(1) tool. I was unable
to use function return probes with Fedora 14's 2.6.35-based kernel. It works
fine on with a 2.6.38 perf(1) tool. In general, I have found the
perf(1) tool to be somewhat unstable but this has improved a lot with
recent versions.

Plain function tracing can be done without installing kernel debuginfo
packages but arbitrary source line probes and variable dumping requires the
kernel debuginfo packages. On Debian-based distros the kernel debuginfo
packages are called linux-image-*-dbg and on Red Hat-based distros
they are called kernel-debuginfo.

Tracing function entry

The following command-line syntax adds a new function entry probe:
sudo perf probe <function-name> [<local-variable> ...]

Tracing function return

The following command-line syntax adds a new function return probe and dumps the return value:
sudo perf probe <funtion-name>%return '$retval'
Notice the arg1 return value in this example output for scsi_test_unit_ready():
$ sudo perf record -e probe:scsi_test_unit_ready -aR sleep 10
[...]
$ sudo perf script
     kworker/0:0-3383  [000]  3546.003235: scsi_test_unit_ready: (ffffffffa0208c6d <- ffffffffa0069306) arg1=8000002
 hald-addon-stor-3025  [001]  3546.004431: scsi_test_unit_ready: (ffffffffa0208c6d <- ffffffffa006a143) arg1=8000002
     kworker/0:0-3383  [000]  3548.004531: scsi_test_unit_ready: (ffffffffa0208c6d <- ffffffffa0069306) arg1=8000002
 hald-addon-stor-3025  [001]  3548.005531: scsi_test_unit_ready: (ffffffffa0208c6d <- ffffffffa006a143) arg1=8000002

Listing probes

Existing probes can be listed:
sudo perf probe -l

Removing probes

A probe can be deleted with:
sudo perf probe -d <probe-name<
All probes can be deleted with:
sudo perf probe -d '*'

Further information

See the perf-probe(1) man page for details on command-line syntax and additional features.

The underlying mechanism of perf-probe(1) is kprobe-based event tracing, which is documented here.

I hope that future Linux kernels will add perf-probe(1) for
userspace processes. Nowadays GDB might already include this feature in its
tracing commands but I haven't had a chance to try them out yet.

10 comments:

  1. > I hope that future Linux kernels will add perf-probe(1) for
    > userspace processes. Nowadays GDB might already include this feature in its
    > tracing commands but I haven't had a chance to try them out yet.

    An infrastructure for user space probing is being worked out .

    See the details here -> https://lkml.org/lkml/2011/4/1/177

    ReplyDelete
  2. Thanks for the link, nice to see recent activity. I really hope this gets in.

    ReplyDelete
  3. How can I use perf probe to profile a kernel module function?
    I am observing the following error when using 'perf probe'
    >$ lsmod | grep "lab3_module2"
    lab3_module2 12410 0
    lab3_module1 12534 1 lab3_module2
    >$ sudo perf probe -m lab3_module1.ko --add mod1fun
    Failed to open [vmxnet], continuing without symbols
    Failed to open [vmci], continuing without symbols
    [lab1_kprobes] with build id 28c0767928260cc3c56623c3d730073fd0653c0d not found, continuing without symbols
    [lab3_module2] with build id 5e7c91ba29c5f5b01ef9df91b6102a3c2983fe91 not found, continuing without symbols
    [lab3_module1] with build id 4a54f152a148a9499f7d01535dd679508c03fc03 not found, continuing without symbols
    Failed to open [vsock], continuing without symbols
    [lab2_jprobes] with build id fec45418b20bc15e6c854679eeeb2d3f05f4eb3a not found, continuing without symbols
    [kretprobe_example] with build id 5f75d949275f88418b4d408607b9d5f978a22423 not found, continuing without symbols
    Failed to open [vmhgfs], continuing without symbols
    Kernel symbol 'mod1fun' not found.
    Error: Failed to add events. (-2)

    # mod1fun is called from lab3_module2.ko (it's defined in lab3_module1.ko). The module is loaded at the time above command is run.

    It'd be great if you could locate where am going wrong.
    Thanks!

    ReplyDelete
    Replies
    1. Try installing the symbols (debuginfo) in the correct place so perf can look up mod1fun. The error messages tell you that perf cannot get symbols for your custom modules.

      Delete
    2. Thanks!
      Is it possible to give opcode of the function obtained from kallsyms? I use that method to probe using kprobes.
      I am not that familiar with installing symbols.

      Delete
    3. A quick look at the perf-probe(1) man page suggests you cannot give an address. It must be a function name.

      Delete
  4. Ok. Had tried. Will do some more study how to install debug symbols of custom modules. Thanks again.

    ReplyDelete
  5. How to install debuginfo for loadable moduels? In gdb I know how.
    But I am not able to understand how to do so for perf-probe.
    Thanks!

    ReplyDelete
  6. Even I am stuck here. What are the custom modules ?
    I tried compiling with some config options on: but still they did not solve. Am I missing anything ?
    Source: http://www.brendangregg.com/perf.html

    # for perf_events:
    CONFIG_PERF_EVENTS=y
    # for stack traces:
    CONFIG_FRAME_POINTER=y
    # kernel symbols:
    CONFIG_KALLSYMS=y
    # tracepoints:
    CONFIG_TRACEPOINTS=y
    # kernel function trace:
    CONFIG_FTRACE=y
    # kernel-level dynamic tracing:
    CONFIG_KPROBES=y
    CONFIG_KPROBE_EVENTS=y
    # user-level dynamic tracing:
    CONFIG_UPROBES=y
    CONFIG_UPROBE_EVENTS=y
    # full kernel debug info:
    CONFIG_DEBUG_INFO=y
    # kernel lock tracing:
    CONFIG_LOCKDEP=y
    # kernel lock tracing:
    CONFIG_LOCK_STAT=y
    # kernel dynamic tracepoint variables:
    CONFIG_DEBUG_INFO=y

    ReplyDelete
    Replies
    1. perf-probe(1) works on Fedora without compiling a custom kernel. I'm not sure about other distros.

      You haven't explained what the problem is. Please email linux-trace-users@vger.kernel.org with your question and include the perf-probe(1) command-line and error message you are seeing.

      Delete