perf probe: Support $params special probe argument
authorMasami Hiramatsu <masami.hiramatsu.pt@hitachi.com>
Wed, 6 May 2015 12:46:53 +0000 (21:46 +0900)
committerArnaldo Carvalho de Melo <acme@redhat.com>
Fri, 8 May 2015 19:05:03 +0000 (16:05 -0300)
$params is similar to $vars but matches only function parameters not
local variables.

Thus, this is useful for tracing function parameter changing or tracing
function call with parameters.

Testing it:

 # perf probe tcp_sendmsg '$params'
 Added new event:
  probe:tcp_sendmsg    (on tcp_sendmsg with $params)

 You can now use it in all perf tools, such as:

perf record -e probe:tcp_sendmsg -aR sleep 1

 # perf probe -l
  probe:tcp_sendmsg    (on tcp_sendmsg@acme/git/linux/net/ipv4/tcp.c with iocb sk msg size)
 # perf record -a -e probe:*
 press some random letters to generate TCP (sshd) traffic...

 ^C[ perf record: Woken up 1 times to write data ]
 [ perf record: Captured and wrote 0.223 MB perf.data (6 samples) ]

 # perf script
   sshd 6385 [2] 3.907529: probe:tcp_sendmsg: iocb=0xffff8800ac4cfe70 sk=0xffff88042196c140 msg=0xffff8800ac4cfda8 size=0x24
   sshd 6385 [2] 4.138973: probe:tcp_sendmsg: iocb=0xffff8800ac4cfe70 sk=0xffff88042196c140 msg=0xffff8800ac4cfda8 size=0x24
   sshd 6385 [2] 4.378966: probe:tcp_sendmsg: iocb=0xffff8800ac4cfe70 sk=0xffff88042196c140 msg=0xffff8800ac4cfda8 size=0x24
   sshd 6385 [2] 4.603681: probe:tcp_sendmsg: iocb=0xffff8800ac4cfe70 sk=0xffff88042196c140 msg=0xffff8800ac4cfda8 size=0x24
   sshd 6385 [2] 4.818455: probe:tcp_sendmsg: iocb=0xffff8800ac4cfe70 sk=0xffff88042196c140 msg=0xffff8800ac4cfda8 size=0x24
   sshd 6385 [2] 5.043603: probe:tcp_sendmsg: iocb=0xffff8800ac4cfe70 sk=0xffff88042196c140 msg=0xffff8800ac4cfda8 size=0x24
 # cat /sys/kernel/debug/tracing/events/probe/tcp_sendmsg/format
 name: tcp_sendmsg
 ID: 1927
 format:
   field:unsigned short common_type; offset:0; size:2; signed:0;
   field:unsigned char common_flags; offset:2; size:1; signed:0;
   field:unsigned char common_preempt_count; offset:3; size:1; signed:0;
   field:int common_pid; offset:4; size:4; signed:1;

   field:unsigned long __probe_ip; offset:8; size:8; signed:0;
   field:u64 iocb; offset:16; size:8; signed:0;
   field:u64 sk; offset:24; size:8; signed:0;
   field:u64 msg; offset:32; size:8; signed:0;
   field:u64 size; offset:40; size:8; signed:0;

 print fmt: "(%lx) iocb=0x%Lx sk=0x%Lx msg=0x%Lx size=0x%Lx", REC->__probe_ip, REC->iocb, REC->sk, REC->msg, REC->size
 #

 Do some system wide tracing of this probe + write syscalls:

 # perf trace -e write --ev probe:* --filter-pids 6385
  462.612 (0.010 ms): bash/19153 write(fd: 1</dev/pts/1>, buf: 0x7f7556c78000, count: 29               ) = 29
  462.701 (0.027 ms): sshd/19152 write(fd: 3<socket:[63117]>, buf: 0x7f78dd12e160, count: 68           ) ...
  462.701 (        ): probe:tcp_sendmsg:(ffffffff8163db30) iocb=0xffff8803ebec7e70 sk=0xffff88042196ab80 msg=0xffff8803ebec7da8 size=0x44)
  462.710 (0.035 ms): sshd/19152  ... [continued]: write()) = 68
  462.787 (0.009 ms): bash/19153 write(fd: 2</dev/pts/1>, buf: 0x7f7556c77000, count: 22               ) = 22
  462.865 (0.002 ms): sshd/19152 write(fd: 3<socket:[63117]>, buf: 0x7f78dd12e160, count: 68           ) ...
  462.865 (        ): probe:tcp_sendmsg:(ffffffff8163db30) iocb=0xffff8803ebec7e70 sk=0xffff88042196ab80 msg=0xffff8803ebec7da8 size=0x44)
  462.873 (0.010 ms): sshd/19152  ... [continued]: write()) = 68

Signed-off-by: Masami Hiramatsu <masami.hiramatsu.pt@hitachi.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Ananth N Mavinakayanahalli <ananth@in.ibm.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Hemant Kumar <hemant@linux.vnet.ibm.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: http://lkml.kernel.org/r/20150506124653.4961.59806.stgit@localhost.localdomain
[ Add some examples to the changelog message showing how to use it ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
tools/perf/Documentation/perf-probe.txt
tools/perf/util/probe-finder.c
tools/perf/util/probe-finder.h

index a272f2e9a1cf12ed26f843c0248646711b738da1..ad3e355adc1f0e2b2c7372b9454165e96c6c2181 100644 (file)
@@ -151,7 +151,7 @@ Each probe argument follows below syntax.
  [NAME=]LOCALVAR|$retval|%REG|@SYMBOL[:TYPE]
 
 'NAME' specifies the name of this argument (optional). You can use the name of local variable, local data structure member (e.g. var->field, var.field2), local array with fixed index (e.g. array[1], var->array[0], var->pointer[2]), or kprobe-tracer argument format (e.g. $retval, %ax, etc). Note that the name of this argument will be set as the last member name if you specify a local data structure member (e.g. field2 for 'var->field1.field2'.)
-'$vars' special argument is also available for NAME, it is expanded to the local variables which can access at given probe point.
+'$vars' and '$params' special arguments are also available for NAME, '$vars' is expanded to the local variables (including function parameters) which can access at given probe point. '$params' is expanded to only the function parameters.
 'TYPE' casts the type of this argument (optional). If omitted, perf probe automatically set the type based on debuginfo. You can specify 'string' type only for the local variable or structure member which is an array of or a pointer to 'char' or 'unsigned char' type.
 
 On x86 systems %REG is always the short form of the register: for example %AX. %RAX or %EAX is not valid.
index b5bf9d5efeaf2dc32317573de059c1d73367cc7c..63d33893d8538315a851a4ad9908e6717a9b857a 100644 (file)
@@ -1087,6 +1087,7 @@ found:
 struct local_vars_finder {
        struct probe_finder *pf;
        struct perf_probe_arg *args;
+       bool vars;
        int max_args;
        int nargs;
        int ret;
@@ -1101,7 +1102,7 @@ static int copy_variables_cb(Dwarf_Die *die_mem, void *data)
 
        tag = dwarf_tag(die_mem);
        if (tag == DW_TAG_formal_parameter ||
-           tag == DW_TAG_variable) {
+           (tag == DW_TAG_variable && vf->vars)) {
                if (convert_variable_location(die_mem, vf->pf->addr,
                                              vf->pf->fb_ops, &pf->sp_die,
                                              NULL) == 0) {
@@ -1127,26 +1128,28 @@ static int expand_probe_args(Dwarf_Die *sc_die, struct probe_finder *pf,
        Dwarf_Die die_mem;
        int i;
        int n = 0;
-       struct local_vars_finder vf = {.pf = pf, .args = args,
+       struct local_vars_finder vf = {.pf = pf, .args = args, .vars = false,
                                .max_args = MAX_PROBE_ARGS, .ret = 0};
 
        for (i = 0; i < pf->pev->nargs; i++) {
                /* var never be NULL */
-               if (strcmp(pf->pev->args[i].var, "$vars") == 0) {
-                       pr_debug("Expanding $vars into:");
-                       vf.nargs = n;
-                       /* Special local variables */
-                       die_find_child(sc_die, copy_variables_cb, (void *)&vf,
-                                      &die_mem);
-                       pr_debug(" (%d)\n", vf.nargs - n);
-                       if (vf.ret < 0)
-                               return vf.ret;
-                       n = vf.nargs;
-               } else {
+               if (strcmp(pf->pev->args[i].var, PROBE_ARG_VARS) == 0)
+                       vf.vars = true;
+               else if (strcmp(pf->pev->args[i].var, PROBE_ARG_PARAMS) != 0) {
                        /* Copy normal argument */
                        args[n] = pf->pev->args[i];
                        n++;
+                       continue;
                }
+               pr_debug("Expanding %s into:", pf->pev->args[i].var);
+               vf.nargs = n;
+               /* Special local variables */
+               die_find_child(sc_die, copy_variables_cb, (void *)&vf,
+                              &die_mem);
+               pr_debug(" (%d)\n", vf.nargs - n);
+               if (vf.ret < 0)
+                       return vf.ret;
+               n = vf.nargs;
        }
        return n;
 }
index ebf8c8c814531ff4efaf5a7461c2ef6a7414df69..f53553d388451b079c3f7d085c6894cfd06a22ce 100644 (file)
@@ -10,6 +10,9 @@
 #define MAX_PROBES              128
 #define MAX_PROBE_ARGS          128
 
+#define PROBE_ARG_VARS         "$vars"
+#define PROBE_ARG_PARAMS       "$params"
+
 static inline int is_c_varname(const char *name)
 {
        /* TODO */