aboutsummaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorArnaldo Carvalho de Melo <acme@redhat.com>2015-08-04 21:30:09 -0400
committerArnaldo Carvalho de Melo <acme@redhat.com>2015-08-05 09:52:45 -0400
commitf994592d9386548d15cea597cde37a858b61c762 (patch)
tree6f14b7b8925e3504e5a202e57729104991d02d89
parente4d44e830a4bbeb0cf6fdd24c24794a2e599e26d (diff)
perf trace: Deref sys_enter pointer args with contents from probe:vfs_getname
To work like strace and dereference syscall pointer args we need to insert probes (or tracepoints) right after we copy those bytes from userspace. Since we're formatting the syscall args at raw_syscalls:sys_enter time, we need to have a formatter that just stores the position where, later, when we get the probe:vfs_getname, we can insert the pointer contents. Now, if a probe:vfs_getname with this format is in place: # perf probe -l probe:vfs_getname (on getname_flags:72@/home/git/linux/fs/namei.c with pathname) That was, in this case, put in place with: # perf probe 'vfs_getname=getname_flags:72 pathname=filename:string' Added new event: probe:vfs_getname (on getname_flags:72 with pathname=filename:string) You can now use it in all perf tools, such as: perf record -e probe:vfs_getname -aR sleep 1 # Then 'perf trace' will notice that and do the pointer -> contents expansion: # trace -e open touch /tmp/bla 0.165 (0.010 ms): touch/17752 open(filename: /etc/ld.so.cache, flags: CLOEXEC) = 3 0.195 (0.011 ms): touch/17752 open(filename: /lib64/libc.so.6, flags: CLOEXEC) = 3 0.512 (0.012 ms): touch/17752 open(filename: /usr/lib/locale/locale-archive, flags: CLOEXEC) = 3 0.582 (0.012 ms): touch/17752 open(filename: /tmp/bla, flags: CREAT|NOCTTY|NONBLOCK|WRONLY, mode: 438) = 3 # Roughly equivalent to strace's output: # strace -rT -e open touch /tmp/bla 0.000000 open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3 <0.000039> 0.000317 open("/lib64/libc.so.6", O_RDONLY|O_CLOEXEC) = 3 <0.000102> 0.001461 open("/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) = 3 <0.000072> 0.000405 open("/tmp/bla", O_WRONLY|O_CREAT|O_NOCTTY|O_NONBLOCK, 0666) = 3 <0.000055> 0.000641 +++ exited with 0 +++ # Now we need to either look for at all syscalls that are marked as pointers and have some well known names ("filename", "pathname", etc) and set the arg formatter to the one used for the "open" syscall in this patch. This implementation works for syscalls with just a string being copied from userspace, for matching syscalls with more than one string being copied via the same probe/trace point (vfs_getname) we need to extend the vfs_getname probe spec to include the pointer too, but there are some problems with that in 'perf probe' or the kernel kprobes code, need to investigate before considering supporting multiple strings per syscall. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Borislav Petkov <bp@suse.de> Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Milian Wolff <mail@milianw.de> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-xvuwx6nuj8cf389kf9s2ue2s@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
-rw-r--r--tools/perf/builtin-trace.c76
1 files changed, 75 insertions, 1 deletions
diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c
index 12d6fc0227b1..0255dd892662 100644
--- a/tools/perf/builtin-trace.c
+++ b/tools/perf/builtin-trace.c
@@ -744,6 +744,11 @@ static size_t syscall_arg__scnprintf_access_mode(char *bf, size_t size,
744 744
745#define SCA_ACCMODE syscall_arg__scnprintf_access_mode 745#define SCA_ACCMODE syscall_arg__scnprintf_access_mode
746 746
747static size_t syscall_arg__scnprintf_filename(char *bf, size_t size,
748 struct syscall_arg *arg);
749
750#define SCA_FILENAME syscall_arg__scnprintf_filename
751
747static size_t syscall_arg__scnprintf_open_flags(char *bf, size_t size, 752static size_t syscall_arg__scnprintf_open_flags(char *bf, size_t size,
748 struct syscall_arg *arg) 753 struct syscall_arg *arg)
749{ 754{
@@ -1088,7 +1093,8 @@ static struct syscall_fmt {
1088 { .name = "newfstatat", .errmsg = true, 1093 { .name = "newfstatat", .errmsg = true,
1089 .arg_scnprintf = { [0] = SCA_FDAT, /* dfd */ }, }, 1094 .arg_scnprintf = { [0] = SCA_FDAT, /* dfd */ }, },
1090 { .name = "open", .errmsg = true, 1095 { .name = "open", .errmsg = true,
1091 .arg_scnprintf = { [1] = SCA_OPEN_FLAGS, /* flags */ }, }, 1096 .arg_scnprintf = { [0] = SCA_FILENAME, /* filename */
1097 [1] = SCA_OPEN_FLAGS, /* flags */ }, },
1092 { .name = "open_by_handle_at", .errmsg = true, 1098 { .name = "open_by_handle_at", .errmsg = true,
1093 .arg_scnprintf = { [0] = SCA_FDAT, /* dfd */ 1099 .arg_scnprintf = { [0] = SCA_FDAT, /* dfd */
1094 [2] = SCA_OPEN_FLAGS, /* flags */ }, }, 1100 [2] = SCA_OPEN_FLAGS, /* flags */ }, },
@@ -1208,6 +1214,11 @@ static size_t fprintf_duration(unsigned long t, FILE *fp)
1208 return printed + fprintf(fp, "): "); 1214 return printed + fprintf(fp, "): ");
1209} 1215}
1210 1216
1217/**
1218 * filename.ptr: The filename char pointer that will be vfs_getname'd
1219 * filename.entry_str_pos: Where to insert the string translated from
1220 * filename.ptr by the vfs_getname tracepoint/kprobe.
1221 */
1211struct thread_trace { 1222struct thread_trace {
1212 u64 entry_time; 1223 u64 entry_time;
1213 u64 exit_time; 1224 u64 exit_time;
@@ -1216,6 +1227,10 @@ struct thread_trace {
1216 unsigned long pfmaj, pfmin; 1227 unsigned long pfmaj, pfmin;
1217 char *entry_str; 1228 char *entry_str;
1218 double runtime_ms; 1229 double runtime_ms;
1230 struct {
1231 unsigned long ptr;
1232 int entry_str_pos;
1233 } filename;
1219 struct { 1234 struct {
1220 int max; 1235 int max;
1221 char **table; 1236 char **table;
@@ -1418,6 +1433,27 @@ static size_t syscall_arg__scnprintf_close_fd(char *bf, size_t size,
1418 return printed; 1433 return printed;
1419} 1434}
1420 1435
1436static void thread__set_filename_pos(struct thread *thread, const char *bf,
1437 unsigned long ptr)
1438{
1439 struct thread_trace *ttrace = thread__priv(thread);
1440
1441 ttrace->filename.ptr = ptr;
1442 ttrace->filename.entry_str_pos = bf - ttrace->entry_str;
1443}
1444
1445static size_t syscall_arg__scnprintf_filename(char *bf, size_t size,
1446 struct syscall_arg *arg)
1447{
1448 unsigned long ptr = arg->val;
1449
1450 if (!arg->trace->vfs_getname)
1451 return scnprintf(bf, size, "%#x", ptr);
1452
1453 thread__set_filename_pos(arg->thread, bf, ptr);
1454 return 0;
1455}
1456
1421static bool trace__filter_duration(struct trace *trace, double t) 1457static bool trace__filter_duration(struct trace *trace, double t)
1422{ 1458{
1423 return t < (trace->duration_filter * NSEC_PER_MSEC); 1459 return t < (trace->duration_filter * NSEC_PER_MSEC);
@@ -1938,7 +1974,45 @@ static int trace__vfs_getname(struct trace *trace, struct perf_evsel *evsel,
1938 union perf_event *event __maybe_unused, 1974 union perf_event *event __maybe_unused,
1939 struct perf_sample *sample) 1975 struct perf_sample *sample)
1940{ 1976{
1977 struct thread *thread = machine__findnew_thread(trace->host, sample->pid, sample->tid);
1978 struct thread_trace *ttrace;
1979 size_t filename_len, entry_str_len, to_move;
1980 ssize_t remaining_space;
1981 char *pos;
1982 const char *filename;
1983
1941 trace->last_vfs_getname = perf_evsel__rawptr(evsel, sample, "pathname"); 1984 trace->last_vfs_getname = perf_evsel__rawptr(evsel, sample, "pathname");
1985
1986 if (!thread)
1987 goto out;
1988
1989 ttrace = thread__priv(thread);
1990 if (!ttrace)
1991 goto out;
1992
1993 if (!ttrace->filename.ptr)
1994 goto out;
1995
1996 entry_str_len = strlen(ttrace->entry_str);
1997 remaining_space = trace__entry_str_size - entry_str_len - 1; /* \0 */
1998 if (remaining_space <= 0)
1999 goto out;
2000
2001 filename = trace->last_vfs_getname;
2002 filename_len = strlen(filename);
2003 if (filename_len > (size_t)remaining_space) {
2004 filename += filename_len - remaining_space;
2005 filename_len = remaining_space;
2006 }
2007
2008 to_move = entry_str_len - ttrace->filename.entry_str_pos + 1; /* \0 */
2009 pos = ttrace->entry_str + ttrace->filename.entry_str_pos;
2010 memmove(pos + filename_len, pos, to_move);
2011 memcpy(pos, filename, filename_len);
2012
2013 ttrace->filename.ptr = 0;
2014 ttrace->filename.entry_str_pos = 0;
2015out:
1942 return 0; 2016 return 0;
1943} 2017}
1944 2018