lkml.org 
[lkml]   [2015]   [May]   [8]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
Patch in this message
/
From
Subject[PATCH 06/30] perf probe: Support $params special probe argument
Date
From: Masami Hiramatsu <masami.hiramatsu.pt@hitachi.com>

$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 | 2 +-
tools/perf/util/probe-finder.c | 29 ++++++++++++++++-------------
tools/perf/util/probe-finder.h | 3 +++
3 files changed, 20 insertions(+), 14 deletions(-)

diff --git a/tools/perf/Documentation/perf-probe.txt b/tools/perf/Documentation/perf-probe.txt
index a272f2e..ad3e355 100644
--- a/tools/perf/Documentation/perf-probe.txt
+++ b/tools/perf/Documentation/perf-probe.txt
@@ -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.
diff --git a/tools/perf/util/probe-finder.c b/tools/perf/util/probe-finder.c
index b5bf9d5..63d3389 100644
--- a/tools/perf/util/probe-finder.c
+++ b/tools/perf/util/probe-finder.c
@@ -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;
}
diff --git a/tools/perf/util/probe-finder.h b/tools/perf/util/probe-finder.h
index ebf8c8c..f53553d 100644
--- a/tools/perf/util/probe-finder.h
+++ b/tools/perf/util/probe-finder.h
@@ -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 */
--
2.1.0


\
 
 \ /
  Last update: 2015-05-08 23:21    [W:0.197 / U:40.400 seconds]
©2003-2018 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site