linux/tools/perf/builtin-trace.c

686 lines
18 KiB
C
Raw Normal View History

perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
#include "builtin.h"
perf trace: Support interrupted syscalls Using the same strategies as in the tmp.perf/trace2, i.e. the 'trace' tool implemented by tglx, just updated to the current codebase. Example: [root@sandy linux]# perf trace usleep 1 | tail 2.003: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128396288 2.017: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128400384 2.029: arch_prctl(option: 4098, arg2: 140146949441280, arg3: 140146949435392, arg4: 34, arg5: 4294967295) = 0 2.084: mprotect(start: 208741634048, len: 16384, prot: 1 ) = 0 2.098: mprotect(start: 208735956992, len: 4096, prot: 1 ) = 0 2.122: munmap(addr: 140146949447680, len: 91882 ) = 0 2.359: brk(brk: 0 ) = 28987392 2.371: brk(brk: 29122560 ) = 29122560 2.490: nanosleep(rqtp: 140735694241504, rmtp: 0 ) = 0 2.507: exit_group(error_code: 0 [root@sandy linux]# For now the timestamp and duration are always on, will be selectable. Also if multiple threads are being monitored, its tid will appear. The ret output continues to be interpreted a la strace. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ly9ulroru4my5isn0xe9gr0m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-06 21:43:19 +00:00
#include "util/color.h"
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
#include "util/evlist.h"
perf trace: Support interrupted syscalls Using the same strategies as in the tmp.perf/trace2, i.e. the 'trace' tool implemented by tglx, just updated to the current codebase. Example: [root@sandy linux]# perf trace usleep 1 | tail 2.003: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128396288 2.017: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128400384 2.029: arch_prctl(option: 4098, arg2: 140146949441280, arg3: 140146949435392, arg4: 34, arg5: 4294967295) = 0 2.084: mprotect(start: 208741634048, len: 16384, prot: 1 ) = 0 2.098: mprotect(start: 208735956992, len: 4096, prot: 1 ) = 0 2.122: munmap(addr: 140146949447680, len: 91882 ) = 0 2.359: brk(brk: 0 ) = 28987392 2.371: brk(brk: 29122560 ) = 29122560 2.490: nanosleep(rqtp: 140735694241504, rmtp: 0 ) = 0 2.507: exit_group(error_code: 0 [root@sandy linux]# For now the timestamp and duration are always on, will be selectable. Also if multiple threads are being monitored, its tid will appear. The ret output continues to be interpreted a la strace. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ly9ulroru4my5isn0xe9gr0m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-06 21:43:19 +00:00
#include "util/machine.h"
#include "util/thread.h"
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
#include "util/parse-options.h"
#include "util/thread_map.h"
#include "event-parse.h"
#include <libaudit.h>
#include <stdlib.h>
static struct syscall_fmt {
const char *name;
const char *alias;
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
bool errmsg;
bool timeout;
} syscall_fmts[] = {
{ .name = "access", .errmsg = true, },
{ .name = "arch_prctl", .errmsg = true, .alias = "prctl", },
{ .name = "fstat", .errmsg = true, .alias = "newfstat", },
{ .name = "fstatat", .errmsg = true, .alias = "newfstatat", },
{ .name = "futex", .errmsg = true, },
{ .name = "open", .errmsg = true, },
{ .name = "poll", .errmsg = true, .timeout = true, },
{ .name = "ppoll", .errmsg = true, .timeout = true, },
{ .name = "read", .errmsg = true, },
{ .name = "recvfrom", .errmsg = true, },
{ .name = "select", .errmsg = true, .timeout = true, },
{ .name = "socket", .errmsg = true, },
{ .name = "stat", .errmsg = true, .alias = "newstat", },
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
};
static int syscall_fmt__cmp(const void *name, const void *fmtp)
{
const struct syscall_fmt *fmt = fmtp;
return strcmp(name, fmt->name);
}
static struct syscall_fmt *syscall_fmt__find(const char *name)
{
const int nmemb = ARRAY_SIZE(syscall_fmts);
return bsearch(name, syscall_fmts, nmemb, sizeof(struct syscall_fmt), syscall_fmt__cmp);
}
struct syscall {
struct event_format *tp_format;
const char *name;
struct syscall_fmt *fmt;
};
static size_t fprintf_duration(unsigned long t, FILE *fp)
{
double duration = (double)t / NSEC_PER_MSEC;
size_t printed = fprintf(fp, "(");
if (duration >= 1.0)
printed += color_fprintf(fp, PERF_COLOR_RED, "%6.3f ms", duration);
else if (duration >= 0.01)
printed += color_fprintf(fp, PERF_COLOR_YELLOW, "%6.3f ms", duration);
else
printed += color_fprintf(fp, PERF_COLOR_NORMAL, "%6.3f ms", duration);
return printed + fprintf(stdout, "): ");
}
perf trace: Support interrupted syscalls Using the same strategies as in the tmp.perf/trace2, i.e. the 'trace' tool implemented by tglx, just updated to the current codebase. Example: [root@sandy linux]# perf trace usleep 1 | tail 2.003: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128396288 2.017: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128400384 2.029: arch_prctl(option: 4098, arg2: 140146949441280, arg3: 140146949435392, arg4: 34, arg5: 4294967295) = 0 2.084: mprotect(start: 208741634048, len: 16384, prot: 1 ) = 0 2.098: mprotect(start: 208735956992, len: 4096, prot: 1 ) = 0 2.122: munmap(addr: 140146949447680, len: 91882 ) = 0 2.359: brk(brk: 0 ) = 28987392 2.371: brk(brk: 29122560 ) = 29122560 2.490: nanosleep(rqtp: 140735694241504, rmtp: 0 ) = 0 2.507: exit_group(error_code: 0 [root@sandy linux]# For now the timestamp and duration are always on, will be selectable. Also if multiple threads are being monitored, its tid will appear. The ret output continues to be interpreted a la strace. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ly9ulroru4my5isn0xe9gr0m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-06 21:43:19 +00:00
struct thread_trace {
u64 entry_time;
u64 exit_time;
bool entry_pending;
unsigned long nr_events;
perf trace: Support interrupted syscalls Using the same strategies as in the tmp.perf/trace2, i.e. the 'trace' tool implemented by tglx, just updated to the current codebase. Example: [root@sandy linux]# perf trace usleep 1 | tail 2.003: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128396288 2.017: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128400384 2.029: arch_prctl(option: 4098, arg2: 140146949441280, arg3: 140146949435392, arg4: 34, arg5: 4294967295) = 0 2.084: mprotect(start: 208741634048, len: 16384, prot: 1 ) = 0 2.098: mprotect(start: 208735956992, len: 4096, prot: 1 ) = 0 2.122: munmap(addr: 140146949447680, len: 91882 ) = 0 2.359: brk(brk: 0 ) = 28987392 2.371: brk(brk: 29122560 ) = 29122560 2.490: nanosleep(rqtp: 140735694241504, rmtp: 0 ) = 0 2.507: exit_group(error_code: 0 [root@sandy linux]# For now the timestamp and duration are always on, will be selectable. Also if multiple threads are being monitored, its tid will appear. The ret output continues to be interpreted a la strace. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ly9ulroru4my5isn0xe9gr0m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-06 21:43:19 +00:00
char *entry_str;
perf trace: Use sched:sched_stat_runtime to provide a thread summary [root@sandy ~]# perf trace --sched --duration 0.100 --pid `pidof firefox` <SNIP> 17079.847 ( 0.009 ms): 17643 poll(ufds: 140037623086496, nfds: 11, timeout_msecs: 0) = 0 Timeout 17079.892 ( 0.010 ms): 17643 read(fd: 4, buf: 140038178943092, count: 4096 ) = -1 EAGAIN Resource temporarily unavailable 17079.921 ( 0.013 ms): 17643 poll(ufds: 140037623086496, nfds: 11, timeout_msecs: 0) = 0 Timeout 17079.949 ( 0.009 ms): 17643 read(fd: 4, buf: 140038178943092, count: 4096 ) = -1 EAGAIN Resource temporarily unavailable ^C _____________________________________________________________________ __) Summary of events (__ [ task - pid ] [ events ] [ ratio ] [ runtime ] _____________________________________________________________________ firefox - 17643 : 18013 [ 72.2% ] 359.110 ms firefox - 17663 : 41 [ 0.2% ] 21.439 ms firefox - 17664 : 6840 [ 27.4% ] 133.642 ms firefox - 17667 : 46 [ 0.2% ] 0.682 ms [root@sandy ~]# This is equivalent to the 'perf trace summary' subcomand in the tmp.perf/trace2 branch. Another example, setting a huge duration filter to get just a system wide summary: [root@sandy ~]# perf trace --duration 10000.0 --sched ^C _____________________________________________________________________ __) Summary of events (__ [ task - pid ] [ events ] [ ratio ] [ runtime ] _____________________________________________________________________ scsi_eh_1 - 258 : 15 [ 0.0% ] 0.133 ms kworker/0:1H - 322 : 13 [ 0.0% ] 0.032 ms jbd2/dm-0-8 - 384 : 4 [ 0.0% ] 0.115 ms flush-253:0 - 470 : 1 [ 0.0% ] 0.027 ms firefox - 950 : 4783 [ 0.1% ] 24.863 ms firefox - 992 : 1883 [ 0.1% ] 6.808 ms firefox - 995 : 35 [ 0.0% ] 0.111 ms ksoftirqd/6 - 4362 : 2 [ 0.0% ] 0.005 ms ksoftirqd/7 - 4365 : 1 [ 0.0% ] 0.007 ms Xorg - 4671 : 148 [ 0.0% ] 0.912 ms gnome-settings- - 4846 : 14 [ 0.0% ] 0.086 ms seahorse-daemon - 4847 : 14 [ 0.0% ] 0.092 ms gnome-panel - 4875 : 46 [ 0.0% ] 0.159 ms gnome-power-man - 4918 : 16 [ 0.0% ] 0.065 ms gvfs-afc-volume - 4992 : 77 [ 0.0% ] 0.136 ms gnome-screensav - 5114 : 24 [ 0.0% ] 0.128 ms xchat - 8082 : 466 [ 0.0% ] 2.019 ms synergyc - 8369 : 941 [ 0.0% ] 3.291 ms synergyc - 8371 : 85 [ 0.0% ] 1.817 ms jbd2/dm-4-8 - 9352 : 4 [ 0.0% ] 0.109 ms rpcbind - 9786 : 3 [ 0.0% ] 0.017 ms rtkit-daemon - 12802 : 10 [ 0.0% ] 0.038 ms rtkit-daemon - 12803 : 8 [ 0.0% ] 0.000 ms udisks-daemon - 13020 : 27 [ 0.0% ] 0.240 ms kworker/7:0 - 14651 : 669 [ 0.0% ] 2.616 ms kworker/5:1 - 16220 : 2 [ 0.0% ] 0.069 ms kworker/4:0 - 19776 : 13 [ 0.0% ] 0.176 ms openvpn - 20131 : 133 [ 0.0% ] 0.762 ms plugin-containe - 20508 : 60658 [ 1.7% ] 131.153 ms npviewer.bin - 20520 : 72208 [ 2.0% ] 138.945 ms npviewer.bin - 20542 : 35 [ 0.0% ] 0.074 ms npviewer.bin - 20543 : 30 [ 0.0% ] 0.074 ms npviewer.bin - 20547 : 35 [ 0.0% ] 0.092 ms npviewer.bin - 20552 : 35 [ 0.0% ] 0.093 ms sshd - 20645 : 32 [ 0.0% ] 0.071 ms npviewer.bin - 21053 : 35 [ 0.0% ] 0.074 ms npviewer.bin - 21054 : 35 [ 0.0% ] 0.097 ms kworker/0:2 - 21169 : 149 [ 0.0% ] 1.143 ms kworker/3:0 - 22171 : 113 [ 0.0% ] 96.892 ms flush-253:4 - 22410 : 1 [ 0.0% ] 0.028 ms kworker/6:0 - 24581 : 25 [ 0.0% ] 0.275 ms kworker/1:0 - 25572 : 4 [ 0.0% ] 0.103 ms kworker/2:1 - 26299 : 138 [ 0.0% ] 1.440 ms kworker/0:0 - 26325 : 1 [ 0.0% ] 0.003 ms perf - 26330 : 3506967 [ 96.1% ] 6648.310 ms [root@sandy ~]# Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-mzuli0srnxyi1o029py6537x@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-17 20:13:12 +00:00
double runtime_ms;
perf trace: Support interrupted syscalls Using the same strategies as in the tmp.perf/trace2, i.e. the 'trace' tool implemented by tglx, just updated to the current codebase. Example: [root@sandy linux]# perf trace usleep 1 | tail 2.003: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128396288 2.017: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128400384 2.029: arch_prctl(option: 4098, arg2: 140146949441280, arg3: 140146949435392, arg4: 34, arg5: 4294967295) = 0 2.084: mprotect(start: 208741634048, len: 16384, prot: 1 ) = 0 2.098: mprotect(start: 208735956992, len: 4096, prot: 1 ) = 0 2.122: munmap(addr: 140146949447680, len: 91882 ) = 0 2.359: brk(brk: 0 ) = 28987392 2.371: brk(brk: 29122560 ) = 29122560 2.490: nanosleep(rqtp: 140735694241504, rmtp: 0 ) = 0 2.507: exit_group(error_code: 0 [root@sandy linux]# For now the timestamp and duration are always on, will be selectable. Also if multiple threads are being monitored, its tid will appear. The ret output continues to be interpreted a la strace. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ly9ulroru4my5isn0xe9gr0m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-06 21:43:19 +00:00
};
static struct thread_trace *thread_trace__new(void)
{
return zalloc(sizeof(struct thread_trace));
}
static struct thread_trace *thread__trace(struct thread *thread)
{
struct thread_trace *ttrace;
perf trace: Support interrupted syscalls Using the same strategies as in the tmp.perf/trace2, i.e. the 'trace' tool implemented by tglx, just updated to the current codebase. Example: [root@sandy linux]# perf trace usleep 1 | tail 2.003: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128396288 2.017: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128400384 2.029: arch_prctl(option: 4098, arg2: 140146949441280, arg3: 140146949435392, arg4: 34, arg5: 4294967295) = 0 2.084: mprotect(start: 208741634048, len: 16384, prot: 1 ) = 0 2.098: mprotect(start: 208735956992, len: 4096, prot: 1 ) = 0 2.122: munmap(addr: 140146949447680, len: 91882 ) = 0 2.359: brk(brk: 0 ) = 28987392 2.371: brk(brk: 29122560 ) = 29122560 2.490: nanosleep(rqtp: 140735694241504, rmtp: 0 ) = 0 2.507: exit_group(error_code: 0 [root@sandy linux]# For now the timestamp and duration are always on, will be selectable. Also if multiple threads are being monitored, its tid will appear. The ret output continues to be interpreted a la strace. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ly9ulroru4my5isn0xe9gr0m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-06 21:43:19 +00:00
if (thread == NULL)
goto fail;
if (thread->priv == NULL)
thread->priv = thread_trace__new();
perf trace: Support interrupted syscalls Using the same strategies as in the tmp.perf/trace2, i.e. the 'trace' tool implemented by tglx, just updated to the current codebase. Example: [root@sandy linux]# perf trace usleep 1 | tail 2.003: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128396288 2.017: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128400384 2.029: arch_prctl(option: 4098, arg2: 140146949441280, arg3: 140146949435392, arg4: 34, arg5: 4294967295) = 0 2.084: mprotect(start: 208741634048, len: 16384, prot: 1 ) = 0 2.098: mprotect(start: 208735956992, len: 4096, prot: 1 ) = 0 2.122: munmap(addr: 140146949447680, len: 91882 ) = 0 2.359: brk(brk: 0 ) = 28987392 2.371: brk(brk: 29122560 ) = 29122560 2.490: nanosleep(rqtp: 140735694241504, rmtp: 0 ) = 0 2.507: exit_group(error_code: 0 [root@sandy linux]# For now the timestamp and duration are always on, will be selectable. Also if multiple threads are being monitored, its tid will appear. The ret output continues to be interpreted a la strace. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ly9ulroru4my5isn0xe9gr0m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-06 21:43:19 +00:00
if (thread->priv == NULL)
goto fail;
ttrace = thread->priv;
++ttrace->nr_events;
return ttrace;
perf trace: Support interrupted syscalls Using the same strategies as in the tmp.perf/trace2, i.e. the 'trace' tool implemented by tglx, just updated to the current codebase. Example: [root@sandy linux]# perf trace usleep 1 | tail 2.003: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128396288 2.017: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128400384 2.029: arch_prctl(option: 4098, arg2: 140146949441280, arg3: 140146949435392, arg4: 34, arg5: 4294967295) = 0 2.084: mprotect(start: 208741634048, len: 16384, prot: 1 ) = 0 2.098: mprotect(start: 208735956992, len: 4096, prot: 1 ) = 0 2.122: munmap(addr: 140146949447680, len: 91882 ) = 0 2.359: brk(brk: 0 ) = 28987392 2.371: brk(brk: 29122560 ) = 29122560 2.490: nanosleep(rqtp: 140735694241504, rmtp: 0 ) = 0 2.507: exit_group(error_code: 0 [root@sandy linux]# For now the timestamp and duration are always on, will be selectable. Also if multiple threads are being monitored, its tid will appear. The ret output continues to be interpreted a la strace. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ly9ulroru4my5isn0xe9gr0m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-06 21:43:19 +00:00
fail:
color_fprintf(stdout, PERF_COLOR_RED,
"WARNING: not enough memory, dropping samples!\n");
return NULL;
}
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
struct trace {
int audit_machine;
struct {
int max;
struct syscall *table;
} syscalls;
struct perf_record_opts opts;
perf trace: Support interrupted syscalls Using the same strategies as in the tmp.perf/trace2, i.e. the 'trace' tool implemented by tglx, just updated to the current codebase. Example: [root@sandy linux]# perf trace usleep 1 | tail 2.003: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128396288 2.017: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128400384 2.029: arch_prctl(option: 4098, arg2: 140146949441280, arg3: 140146949435392, arg4: 34, arg5: 4294967295) = 0 2.084: mprotect(start: 208741634048, len: 16384, prot: 1 ) = 0 2.098: mprotect(start: 208735956992, len: 4096, prot: 1 ) = 0 2.122: munmap(addr: 140146949447680, len: 91882 ) = 0 2.359: brk(brk: 0 ) = 28987392 2.371: brk(brk: 29122560 ) = 29122560 2.490: nanosleep(rqtp: 140735694241504, rmtp: 0 ) = 0 2.507: exit_group(error_code: 0 [root@sandy linux]# For now the timestamp and duration are always on, will be selectable. Also if multiple threads are being monitored, its tid will appear. The ret output continues to be interpreted a la strace. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ly9ulroru4my5isn0xe9gr0m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-06 21:43:19 +00:00
struct machine host;
u64 base_time;
unsigned long nr_events;
perf trace: Use sched:sched_stat_runtime to provide a thread summary [root@sandy ~]# perf trace --sched --duration 0.100 --pid `pidof firefox` <SNIP> 17079.847 ( 0.009 ms): 17643 poll(ufds: 140037623086496, nfds: 11, timeout_msecs: 0) = 0 Timeout 17079.892 ( 0.010 ms): 17643 read(fd: 4, buf: 140038178943092, count: 4096 ) = -1 EAGAIN Resource temporarily unavailable 17079.921 ( 0.013 ms): 17643 poll(ufds: 140037623086496, nfds: 11, timeout_msecs: 0) = 0 Timeout 17079.949 ( 0.009 ms): 17643 read(fd: 4, buf: 140038178943092, count: 4096 ) = -1 EAGAIN Resource temporarily unavailable ^C _____________________________________________________________________ __) Summary of events (__ [ task - pid ] [ events ] [ ratio ] [ runtime ] _____________________________________________________________________ firefox - 17643 : 18013 [ 72.2% ] 359.110 ms firefox - 17663 : 41 [ 0.2% ] 21.439 ms firefox - 17664 : 6840 [ 27.4% ] 133.642 ms firefox - 17667 : 46 [ 0.2% ] 0.682 ms [root@sandy ~]# This is equivalent to the 'perf trace summary' subcomand in the tmp.perf/trace2 branch. Another example, setting a huge duration filter to get just a system wide summary: [root@sandy ~]# perf trace --duration 10000.0 --sched ^C _____________________________________________________________________ __) Summary of events (__ [ task - pid ] [ events ] [ ratio ] [ runtime ] _____________________________________________________________________ scsi_eh_1 - 258 : 15 [ 0.0% ] 0.133 ms kworker/0:1H - 322 : 13 [ 0.0% ] 0.032 ms jbd2/dm-0-8 - 384 : 4 [ 0.0% ] 0.115 ms flush-253:0 - 470 : 1 [ 0.0% ] 0.027 ms firefox - 950 : 4783 [ 0.1% ] 24.863 ms firefox - 992 : 1883 [ 0.1% ] 6.808 ms firefox - 995 : 35 [ 0.0% ] 0.111 ms ksoftirqd/6 - 4362 : 2 [ 0.0% ] 0.005 ms ksoftirqd/7 - 4365 : 1 [ 0.0% ] 0.007 ms Xorg - 4671 : 148 [ 0.0% ] 0.912 ms gnome-settings- - 4846 : 14 [ 0.0% ] 0.086 ms seahorse-daemon - 4847 : 14 [ 0.0% ] 0.092 ms gnome-panel - 4875 : 46 [ 0.0% ] 0.159 ms gnome-power-man - 4918 : 16 [ 0.0% ] 0.065 ms gvfs-afc-volume - 4992 : 77 [ 0.0% ] 0.136 ms gnome-screensav - 5114 : 24 [ 0.0% ] 0.128 ms xchat - 8082 : 466 [ 0.0% ] 2.019 ms synergyc - 8369 : 941 [ 0.0% ] 3.291 ms synergyc - 8371 : 85 [ 0.0% ] 1.817 ms jbd2/dm-4-8 - 9352 : 4 [ 0.0% ] 0.109 ms rpcbind - 9786 : 3 [ 0.0% ] 0.017 ms rtkit-daemon - 12802 : 10 [ 0.0% ] 0.038 ms rtkit-daemon - 12803 : 8 [ 0.0% ] 0.000 ms udisks-daemon - 13020 : 27 [ 0.0% ] 0.240 ms kworker/7:0 - 14651 : 669 [ 0.0% ] 2.616 ms kworker/5:1 - 16220 : 2 [ 0.0% ] 0.069 ms kworker/4:0 - 19776 : 13 [ 0.0% ] 0.176 ms openvpn - 20131 : 133 [ 0.0% ] 0.762 ms plugin-containe - 20508 : 60658 [ 1.7% ] 131.153 ms npviewer.bin - 20520 : 72208 [ 2.0% ] 138.945 ms npviewer.bin - 20542 : 35 [ 0.0% ] 0.074 ms npviewer.bin - 20543 : 30 [ 0.0% ] 0.074 ms npviewer.bin - 20547 : 35 [ 0.0% ] 0.092 ms npviewer.bin - 20552 : 35 [ 0.0% ] 0.093 ms sshd - 20645 : 32 [ 0.0% ] 0.071 ms npviewer.bin - 21053 : 35 [ 0.0% ] 0.074 ms npviewer.bin - 21054 : 35 [ 0.0% ] 0.097 ms kworker/0:2 - 21169 : 149 [ 0.0% ] 1.143 ms kworker/3:0 - 22171 : 113 [ 0.0% ] 96.892 ms flush-253:4 - 22410 : 1 [ 0.0% ] 0.028 ms kworker/6:0 - 24581 : 25 [ 0.0% ] 0.275 ms kworker/1:0 - 25572 : 4 [ 0.0% ] 0.103 ms kworker/2:1 - 26299 : 138 [ 0.0% ] 1.440 ms kworker/0:0 - 26325 : 1 [ 0.0% ] 0.003 ms perf - 26330 : 3506967 [ 96.1% ] 6648.310 ms [root@sandy ~]# Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-mzuli0srnxyi1o029py6537x@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-17 20:13:12 +00:00
bool sched;
perf trace: Support interrupted syscalls Using the same strategies as in the tmp.perf/trace2, i.e. the 'trace' tool implemented by tglx, just updated to the current codebase. Example: [root@sandy linux]# perf trace usleep 1 | tail 2.003: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128396288 2.017: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128400384 2.029: arch_prctl(option: 4098, arg2: 140146949441280, arg3: 140146949435392, arg4: 34, arg5: 4294967295) = 0 2.084: mprotect(start: 208741634048, len: 16384, prot: 1 ) = 0 2.098: mprotect(start: 208735956992, len: 4096, prot: 1 ) = 0 2.122: munmap(addr: 140146949447680, len: 91882 ) = 0 2.359: brk(brk: 0 ) = 28987392 2.371: brk(brk: 29122560 ) = 29122560 2.490: nanosleep(rqtp: 140735694241504, rmtp: 0 ) = 0 2.507: exit_group(error_code: 0 [root@sandy linux]# For now the timestamp and duration are always on, will be selectable. Also if multiple threads are being monitored, its tid will appear. The ret output continues to be interpreted a la strace. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ly9ulroru4my5isn0xe9gr0m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-06 21:43:19 +00:00
bool multiple_threads;
double duration_filter;
perf trace: Use sched:sched_stat_runtime to provide a thread summary [root@sandy ~]# perf trace --sched --duration 0.100 --pid `pidof firefox` <SNIP> 17079.847 ( 0.009 ms): 17643 poll(ufds: 140037623086496, nfds: 11, timeout_msecs: 0) = 0 Timeout 17079.892 ( 0.010 ms): 17643 read(fd: 4, buf: 140038178943092, count: 4096 ) = -1 EAGAIN Resource temporarily unavailable 17079.921 ( 0.013 ms): 17643 poll(ufds: 140037623086496, nfds: 11, timeout_msecs: 0) = 0 Timeout 17079.949 ( 0.009 ms): 17643 read(fd: 4, buf: 140038178943092, count: 4096 ) = -1 EAGAIN Resource temporarily unavailable ^C _____________________________________________________________________ __) Summary of events (__ [ task - pid ] [ events ] [ ratio ] [ runtime ] _____________________________________________________________________ firefox - 17643 : 18013 [ 72.2% ] 359.110 ms firefox - 17663 : 41 [ 0.2% ] 21.439 ms firefox - 17664 : 6840 [ 27.4% ] 133.642 ms firefox - 17667 : 46 [ 0.2% ] 0.682 ms [root@sandy ~]# This is equivalent to the 'perf trace summary' subcomand in the tmp.perf/trace2 branch. Another example, setting a huge duration filter to get just a system wide summary: [root@sandy ~]# perf trace --duration 10000.0 --sched ^C _____________________________________________________________________ __) Summary of events (__ [ task - pid ] [ events ] [ ratio ] [ runtime ] _____________________________________________________________________ scsi_eh_1 - 258 : 15 [ 0.0% ] 0.133 ms kworker/0:1H - 322 : 13 [ 0.0% ] 0.032 ms jbd2/dm-0-8 - 384 : 4 [ 0.0% ] 0.115 ms flush-253:0 - 470 : 1 [ 0.0% ] 0.027 ms firefox - 950 : 4783 [ 0.1% ] 24.863 ms firefox - 992 : 1883 [ 0.1% ] 6.808 ms firefox - 995 : 35 [ 0.0% ] 0.111 ms ksoftirqd/6 - 4362 : 2 [ 0.0% ] 0.005 ms ksoftirqd/7 - 4365 : 1 [ 0.0% ] 0.007 ms Xorg - 4671 : 148 [ 0.0% ] 0.912 ms gnome-settings- - 4846 : 14 [ 0.0% ] 0.086 ms seahorse-daemon - 4847 : 14 [ 0.0% ] 0.092 ms gnome-panel - 4875 : 46 [ 0.0% ] 0.159 ms gnome-power-man - 4918 : 16 [ 0.0% ] 0.065 ms gvfs-afc-volume - 4992 : 77 [ 0.0% ] 0.136 ms gnome-screensav - 5114 : 24 [ 0.0% ] 0.128 ms xchat - 8082 : 466 [ 0.0% ] 2.019 ms synergyc - 8369 : 941 [ 0.0% ] 3.291 ms synergyc - 8371 : 85 [ 0.0% ] 1.817 ms jbd2/dm-4-8 - 9352 : 4 [ 0.0% ] 0.109 ms rpcbind - 9786 : 3 [ 0.0% ] 0.017 ms rtkit-daemon - 12802 : 10 [ 0.0% ] 0.038 ms rtkit-daemon - 12803 : 8 [ 0.0% ] 0.000 ms udisks-daemon - 13020 : 27 [ 0.0% ] 0.240 ms kworker/7:0 - 14651 : 669 [ 0.0% ] 2.616 ms kworker/5:1 - 16220 : 2 [ 0.0% ] 0.069 ms kworker/4:0 - 19776 : 13 [ 0.0% ] 0.176 ms openvpn - 20131 : 133 [ 0.0% ] 0.762 ms plugin-containe - 20508 : 60658 [ 1.7% ] 131.153 ms npviewer.bin - 20520 : 72208 [ 2.0% ] 138.945 ms npviewer.bin - 20542 : 35 [ 0.0% ] 0.074 ms npviewer.bin - 20543 : 30 [ 0.0% ] 0.074 ms npviewer.bin - 20547 : 35 [ 0.0% ] 0.092 ms npviewer.bin - 20552 : 35 [ 0.0% ] 0.093 ms sshd - 20645 : 32 [ 0.0% ] 0.071 ms npviewer.bin - 21053 : 35 [ 0.0% ] 0.074 ms npviewer.bin - 21054 : 35 [ 0.0% ] 0.097 ms kworker/0:2 - 21169 : 149 [ 0.0% ] 1.143 ms kworker/3:0 - 22171 : 113 [ 0.0% ] 96.892 ms flush-253:4 - 22410 : 1 [ 0.0% ] 0.028 ms kworker/6:0 - 24581 : 25 [ 0.0% ] 0.275 ms kworker/1:0 - 25572 : 4 [ 0.0% ] 0.103 ms kworker/2:1 - 26299 : 138 [ 0.0% ] 1.440 ms kworker/0:0 - 26325 : 1 [ 0.0% ] 0.003 ms perf - 26330 : 3506967 [ 96.1% ] 6648.310 ms [root@sandy ~]# Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-mzuli0srnxyi1o029py6537x@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-17 20:13:12 +00:00
double runtime_ms;
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
};
static bool trace__filter_duration(struct trace *trace, double t)
{
return t < (trace->duration_filter * NSEC_PER_MSEC);
}
perf trace: Support interrupted syscalls Using the same strategies as in the tmp.perf/trace2, i.e. the 'trace' tool implemented by tglx, just updated to the current codebase. Example: [root@sandy linux]# perf trace usleep 1 | tail 2.003: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128396288 2.017: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128400384 2.029: arch_prctl(option: 4098, arg2: 140146949441280, arg3: 140146949435392, arg4: 34, arg5: 4294967295) = 0 2.084: mprotect(start: 208741634048, len: 16384, prot: 1 ) = 0 2.098: mprotect(start: 208735956992, len: 4096, prot: 1 ) = 0 2.122: munmap(addr: 140146949447680, len: 91882 ) = 0 2.359: brk(brk: 0 ) = 28987392 2.371: brk(brk: 29122560 ) = 29122560 2.490: nanosleep(rqtp: 140735694241504, rmtp: 0 ) = 0 2.507: exit_group(error_code: 0 [root@sandy linux]# For now the timestamp and duration are always on, will be selectable. Also if multiple threads are being monitored, its tid will appear. The ret output continues to be interpreted a la strace. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ly9ulroru4my5isn0xe9gr0m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-06 21:43:19 +00:00
static size_t trace__fprintf_tstamp(struct trace *trace, u64 tstamp, FILE *fp)
{
double ts = (double)(tstamp - trace->base_time) / NSEC_PER_MSEC;
return fprintf(fp, "%10.3f ", ts);
perf trace: Support interrupted syscalls Using the same strategies as in the tmp.perf/trace2, i.e. the 'trace' tool implemented by tglx, just updated to the current codebase. Example: [root@sandy linux]# perf trace usleep 1 | tail 2.003: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128396288 2.017: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128400384 2.029: arch_prctl(option: 4098, arg2: 140146949441280, arg3: 140146949435392, arg4: 34, arg5: 4294967295) = 0 2.084: mprotect(start: 208741634048, len: 16384, prot: 1 ) = 0 2.098: mprotect(start: 208735956992, len: 4096, prot: 1 ) = 0 2.122: munmap(addr: 140146949447680, len: 91882 ) = 0 2.359: brk(brk: 0 ) = 28987392 2.371: brk(brk: 29122560 ) = 29122560 2.490: nanosleep(rqtp: 140735694241504, rmtp: 0 ) = 0 2.507: exit_group(error_code: 0 [root@sandy linux]# For now the timestamp and duration are always on, will be selectable. Also if multiple threads are being monitored, its tid will appear. The ret output continues to be interpreted a la strace. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ly9ulroru4my5isn0xe9gr0m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-06 21:43:19 +00:00
}
static bool done = false;
static void sig_handler(int sig __maybe_unused)
{
done = true;
}
perf trace: Support interrupted syscalls Using the same strategies as in the tmp.perf/trace2, i.e. the 'trace' tool implemented by tglx, just updated to the current codebase. Example: [root@sandy linux]# perf trace usleep 1 | tail 2.003: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128396288 2.017: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128400384 2.029: arch_prctl(option: 4098, arg2: 140146949441280, arg3: 140146949435392, arg4: 34, arg5: 4294967295) = 0 2.084: mprotect(start: 208741634048, len: 16384, prot: 1 ) = 0 2.098: mprotect(start: 208735956992, len: 4096, prot: 1 ) = 0 2.122: munmap(addr: 140146949447680, len: 91882 ) = 0 2.359: brk(brk: 0 ) = 28987392 2.371: brk(brk: 29122560 ) = 29122560 2.490: nanosleep(rqtp: 140735694241504, rmtp: 0 ) = 0 2.507: exit_group(error_code: 0 [root@sandy linux]# For now the timestamp and duration are always on, will be selectable. Also if multiple threads are being monitored, its tid will appear. The ret output continues to be interpreted a la strace. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ly9ulroru4my5isn0xe9gr0m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-06 21:43:19 +00:00
static size_t trace__fprintf_entry_head(struct trace *trace, struct thread *thread,
u64 duration, u64 tstamp, FILE *fp)
perf trace: Support interrupted syscalls Using the same strategies as in the tmp.perf/trace2, i.e. the 'trace' tool implemented by tglx, just updated to the current codebase. Example: [root@sandy linux]# perf trace usleep 1 | tail 2.003: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128396288 2.017: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128400384 2.029: arch_prctl(option: 4098, arg2: 140146949441280, arg3: 140146949435392, arg4: 34, arg5: 4294967295) = 0 2.084: mprotect(start: 208741634048, len: 16384, prot: 1 ) = 0 2.098: mprotect(start: 208735956992, len: 4096, prot: 1 ) = 0 2.122: munmap(addr: 140146949447680, len: 91882 ) = 0 2.359: brk(brk: 0 ) = 28987392 2.371: brk(brk: 29122560 ) = 29122560 2.490: nanosleep(rqtp: 140735694241504, rmtp: 0 ) = 0 2.507: exit_group(error_code: 0 [root@sandy linux]# For now the timestamp and duration are always on, will be selectable. Also if multiple threads are being monitored, its tid will appear. The ret output continues to be interpreted a la strace. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ly9ulroru4my5isn0xe9gr0m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-06 21:43:19 +00:00
{
size_t printed = trace__fprintf_tstamp(trace, tstamp, fp);
printed += fprintf_duration(duration, fp);
perf trace: Support interrupted syscalls Using the same strategies as in the tmp.perf/trace2, i.e. the 'trace' tool implemented by tglx, just updated to the current codebase. Example: [root@sandy linux]# perf trace usleep 1 | tail 2.003: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128396288 2.017: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128400384 2.029: arch_prctl(option: 4098, arg2: 140146949441280, arg3: 140146949435392, arg4: 34, arg5: 4294967295) = 0 2.084: mprotect(start: 208741634048, len: 16384, prot: 1 ) = 0 2.098: mprotect(start: 208735956992, len: 4096, prot: 1 ) = 0 2.122: munmap(addr: 140146949447680, len: 91882 ) = 0 2.359: brk(brk: 0 ) = 28987392 2.371: brk(brk: 29122560 ) = 29122560 2.490: nanosleep(rqtp: 140735694241504, rmtp: 0 ) = 0 2.507: exit_group(error_code: 0 [root@sandy linux]# For now the timestamp and duration are always on, will be selectable. Also if multiple threads are being monitored, its tid will appear. The ret output continues to be interpreted a la strace. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ly9ulroru4my5isn0xe9gr0m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-06 21:43:19 +00:00
if (trace->multiple_threads)
printed += fprintf(fp, "%d ", thread->pid);
return printed;
}
static int trace__process_event(struct machine *machine, union perf_event *event)
{
int ret = 0;
switch (event->header.type) {
case PERF_RECORD_LOST:
color_fprintf(stdout, PERF_COLOR_RED,
"LOST %" PRIu64 " events!\n", event->lost.lost);
ret = machine__process_lost_event(machine, event);
default:
ret = machine__process_event(machine, event);
break;
}
return ret;
}
static int trace__tool_process(struct perf_tool *tool __maybe_unused,
union perf_event *event,
struct perf_sample *sample __maybe_unused,
struct machine *machine)
{
return trace__process_event(machine, event);
}
static int trace__symbols_init(struct trace *trace, struct perf_evlist *evlist)
{
int err = symbol__init();
if (err)
return err;
machine__init(&trace->host, "", HOST_KERNEL_ID);
machine__create_kernel_maps(&trace->host);
if (perf_target__has_task(&trace->opts.target)) {
err = perf_event__synthesize_thread_map(NULL, evlist->threads,
trace__tool_process,
&trace->host);
} else {
err = perf_event__synthesize_threads(NULL, trace__tool_process,
&trace->host);
}
if (err)
symbol__exit();
return err;
}
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
static int trace__read_syscall_info(struct trace *trace, int id)
{
char tp_name[128];
struct syscall *sc;
const char *name = audit_syscall_to_name(id, trace->audit_machine);
if (name == NULL)
return -1;
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
if (id > trace->syscalls.max) {
struct syscall *nsyscalls = realloc(trace->syscalls.table, (id + 1) * sizeof(*sc));
if (nsyscalls == NULL)
return -1;
if (trace->syscalls.max != -1) {
memset(nsyscalls + trace->syscalls.max + 1, 0,
(id - trace->syscalls.max) * sizeof(*sc));
} else {
memset(nsyscalls, 0, (id + 1) * sizeof(*sc));
}
trace->syscalls.table = nsyscalls;
trace->syscalls.max = id;
}
sc = trace->syscalls.table + id;
sc->name = name;
sc->fmt = syscall_fmt__find(sc->name);
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
snprintf(tp_name, sizeof(tp_name), "sys_enter_%s", sc->name);
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
sc->tp_format = event_format__new("syscalls", tp_name);
if (sc->tp_format == NULL && sc->fmt && sc->fmt->alias) {
snprintf(tp_name, sizeof(tp_name), "sys_enter_%s", sc->fmt->alias);
sc->tp_format = event_format__new("syscalls", tp_name);
}
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
return sc->tp_format != NULL ? 0 : -1;
}
perf trace: Support interrupted syscalls Using the same strategies as in the tmp.perf/trace2, i.e. the 'trace' tool implemented by tglx, just updated to the current codebase. Example: [root@sandy linux]# perf trace usleep 1 | tail 2.003: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128396288 2.017: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128400384 2.029: arch_prctl(option: 4098, arg2: 140146949441280, arg3: 140146949435392, arg4: 34, arg5: 4294967295) = 0 2.084: mprotect(start: 208741634048, len: 16384, prot: 1 ) = 0 2.098: mprotect(start: 208735956992, len: 4096, prot: 1 ) = 0 2.122: munmap(addr: 140146949447680, len: 91882 ) = 0 2.359: brk(brk: 0 ) = 28987392 2.371: brk(brk: 29122560 ) = 29122560 2.490: nanosleep(rqtp: 140735694241504, rmtp: 0 ) = 0 2.507: exit_group(error_code: 0 [root@sandy linux]# For now the timestamp and duration are always on, will be selectable. Also if multiple threads are being monitored, its tid will appear. The ret output continues to be interpreted a la strace. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ly9ulroru4my5isn0xe9gr0m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-06 21:43:19 +00:00
static size_t syscall__scnprintf_args(struct syscall *sc, char *bf, size_t size,
unsigned long *args)
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
{
int i = 0;
size_t printed = 0;
if (sc->tp_format != NULL) {
struct format_field *field;
for (field = sc->tp_format->format.fields->next; field; field = field->next) {
perf trace: Support interrupted syscalls Using the same strategies as in the tmp.perf/trace2, i.e. the 'trace' tool implemented by tglx, just updated to the current codebase. Example: [root@sandy linux]# perf trace usleep 1 | tail 2.003: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128396288 2.017: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128400384 2.029: arch_prctl(option: 4098, arg2: 140146949441280, arg3: 140146949435392, arg4: 34, arg5: 4294967295) = 0 2.084: mprotect(start: 208741634048, len: 16384, prot: 1 ) = 0 2.098: mprotect(start: 208735956992, len: 4096, prot: 1 ) = 0 2.122: munmap(addr: 140146949447680, len: 91882 ) = 0 2.359: brk(brk: 0 ) = 28987392 2.371: brk(brk: 29122560 ) = 29122560 2.490: nanosleep(rqtp: 140735694241504, rmtp: 0 ) = 0 2.507: exit_group(error_code: 0 [root@sandy linux]# For now the timestamp and duration are always on, will be selectable. Also if multiple threads are being monitored, its tid will appear. The ret output continues to be interpreted a la strace. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ly9ulroru4my5isn0xe9gr0m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-06 21:43:19 +00:00
printed += scnprintf(bf + printed, size - printed,
"%s%s: %ld", printed ? ", " : "",
field->name, args[i++]);
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
}
} else {
while (i < 6) {
perf trace: Support interrupted syscalls Using the same strategies as in the tmp.perf/trace2, i.e. the 'trace' tool implemented by tglx, just updated to the current codebase. Example: [root@sandy linux]# perf trace usleep 1 | tail 2.003: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128396288 2.017: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128400384 2.029: arch_prctl(option: 4098, arg2: 140146949441280, arg3: 140146949435392, arg4: 34, arg5: 4294967295) = 0 2.084: mprotect(start: 208741634048, len: 16384, prot: 1 ) = 0 2.098: mprotect(start: 208735956992, len: 4096, prot: 1 ) = 0 2.122: munmap(addr: 140146949447680, len: 91882 ) = 0 2.359: brk(brk: 0 ) = 28987392 2.371: brk(brk: 29122560 ) = 29122560 2.490: nanosleep(rqtp: 140735694241504, rmtp: 0 ) = 0 2.507: exit_group(error_code: 0 [root@sandy linux]# For now the timestamp and duration are always on, will be selectable. Also if multiple threads are being monitored, its tid will appear. The ret output continues to be interpreted a la strace. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ly9ulroru4my5isn0xe9gr0m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-06 21:43:19 +00:00
printed += scnprintf(bf + printed, size - printed,
"%sarg%d: %ld",
printed ? ", " : "", i, args[i]);
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
++i;
}
}
return printed;
}
typedef int (*tracepoint_handler)(struct trace *trace, struct perf_evsel *evsel,
struct perf_sample *sample);
static struct syscall *trace__syscall_info(struct trace *trace,
struct perf_evsel *evsel,
struct perf_sample *sample)
{
int id = perf_evsel__intval(evsel, sample, "id");
if (id < 0) {
printf("Invalid syscall %d id, skipping...\n", id);
return NULL;
}
if ((id > trace->syscalls.max || trace->syscalls.table[id].name == NULL) &&
trace__read_syscall_info(trace, id))
goto out_cant_read;
if ((id > trace->syscalls.max || trace->syscalls.table[id].name == NULL))
goto out_cant_read;
return &trace->syscalls.table[id];
out_cant_read:
printf("Problems reading syscall %d", id);
if (id <= trace->syscalls.max && trace->syscalls.table[id].name != NULL)
printf("(%s)", trace->syscalls.table[id].name);
puts(" information");
return NULL;
}
static int trace__sys_enter(struct trace *trace, struct perf_evsel *evsel,
struct perf_sample *sample)
{
perf trace: Support interrupted syscalls Using the same strategies as in the tmp.perf/trace2, i.e. the 'trace' tool implemented by tglx, just updated to the current codebase. Example: [root@sandy linux]# perf trace usleep 1 | tail 2.003: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128396288 2.017: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128400384 2.029: arch_prctl(option: 4098, arg2: 140146949441280, arg3: 140146949435392, arg4: 34, arg5: 4294967295) = 0 2.084: mprotect(start: 208741634048, len: 16384, prot: 1 ) = 0 2.098: mprotect(start: 208735956992, len: 4096, prot: 1 ) = 0 2.122: munmap(addr: 140146949447680, len: 91882 ) = 0 2.359: brk(brk: 0 ) = 28987392 2.371: brk(brk: 29122560 ) = 29122560 2.490: nanosleep(rqtp: 140735694241504, rmtp: 0 ) = 0 2.507: exit_group(error_code: 0 [root@sandy linux]# For now the timestamp and duration are always on, will be selectable. Also if multiple threads are being monitored, its tid will appear. The ret output continues to be interpreted a la strace. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ly9ulroru4my5isn0xe9gr0m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-06 21:43:19 +00:00
char *msg;
void *args;
perf trace: Support interrupted syscalls Using the same strategies as in the tmp.perf/trace2, i.e. the 'trace' tool implemented by tglx, just updated to the current codebase. Example: [root@sandy linux]# perf trace usleep 1 | tail 2.003: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128396288 2.017: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128400384 2.029: arch_prctl(option: 4098, arg2: 140146949441280, arg3: 140146949435392, arg4: 34, arg5: 4294967295) = 0 2.084: mprotect(start: 208741634048, len: 16384, prot: 1 ) = 0 2.098: mprotect(start: 208735956992, len: 4096, prot: 1 ) = 0 2.122: munmap(addr: 140146949447680, len: 91882 ) = 0 2.359: brk(brk: 0 ) = 28987392 2.371: brk(brk: 29122560 ) = 29122560 2.490: nanosleep(rqtp: 140735694241504, rmtp: 0 ) = 0 2.507: exit_group(error_code: 0 [root@sandy linux]# For now the timestamp and duration are always on, will be selectable. Also if multiple threads are being monitored, its tid will appear. The ret output continues to be interpreted a la strace. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ly9ulroru4my5isn0xe9gr0m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-06 21:43:19 +00:00
size_t printed = 0;
struct thread *thread = machine__findnew_thread(&trace->host, sample->tid);
struct syscall *sc = trace__syscall_info(trace, evsel, sample);
perf trace: Support interrupted syscalls Using the same strategies as in the tmp.perf/trace2, i.e. the 'trace' tool implemented by tglx, just updated to the current codebase. Example: [root@sandy linux]# perf trace usleep 1 | tail 2.003: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128396288 2.017: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128400384 2.029: arch_prctl(option: 4098, arg2: 140146949441280, arg3: 140146949435392, arg4: 34, arg5: 4294967295) = 0 2.084: mprotect(start: 208741634048, len: 16384, prot: 1 ) = 0 2.098: mprotect(start: 208735956992, len: 4096, prot: 1 ) = 0 2.122: munmap(addr: 140146949447680, len: 91882 ) = 0 2.359: brk(brk: 0 ) = 28987392 2.371: brk(brk: 29122560 ) = 29122560 2.490: nanosleep(rqtp: 140735694241504, rmtp: 0 ) = 0 2.507: exit_group(error_code: 0 [root@sandy linux]# For now the timestamp and duration are always on, will be selectable. Also if multiple threads are being monitored, its tid will appear. The ret output continues to be interpreted a la strace. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ly9ulroru4my5isn0xe9gr0m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-06 21:43:19 +00:00
struct thread_trace *ttrace = thread__trace(thread);
perf trace: Support interrupted syscalls Using the same strategies as in the tmp.perf/trace2, i.e. the 'trace' tool implemented by tglx, just updated to the current codebase. Example: [root@sandy linux]# perf trace usleep 1 | tail 2.003: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128396288 2.017: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128400384 2.029: arch_prctl(option: 4098, arg2: 140146949441280, arg3: 140146949435392, arg4: 34, arg5: 4294967295) = 0 2.084: mprotect(start: 208741634048, len: 16384, prot: 1 ) = 0 2.098: mprotect(start: 208735956992, len: 4096, prot: 1 ) = 0 2.122: munmap(addr: 140146949447680, len: 91882 ) = 0 2.359: brk(brk: 0 ) = 28987392 2.371: brk(brk: 29122560 ) = 29122560 2.490: nanosleep(rqtp: 140735694241504, rmtp: 0 ) = 0 2.507: exit_group(error_code: 0 [root@sandy linux]# For now the timestamp and duration are always on, will be selectable. Also if multiple threads are being monitored, its tid will appear. The ret output continues to be interpreted a la strace. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ly9ulroru4my5isn0xe9gr0m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-06 21:43:19 +00:00
if (ttrace == NULL || sc == NULL)
return -1;
args = perf_evsel__rawptr(evsel, sample, "args");
if (args == NULL) {
printf("Problems reading syscall arguments\n");
return -1;
}
perf trace: Support interrupted syscalls Using the same strategies as in the tmp.perf/trace2, i.e. the 'trace' tool implemented by tglx, just updated to the current codebase. Example: [root@sandy linux]# perf trace usleep 1 | tail 2.003: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128396288 2.017: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128400384 2.029: arch_prctl(option: 4098, arg2: 140146949441280, arg3: 140146949435392, arg4: 34, arg5: 4294967295) = 0 2.084: mprotect(start: 208741634048, len: 16384, prot: 1 ) = 0 2.098: mprotect(start: 208735956992, len: 4096, prot: 1 ) = 0 2.122: munmap(addr: 140146949447680, len: 91882 ) = 0 2.359: brk(brk: 0 ) = 28987392 2.371: brk(brk: 29122560 ) = 29122560 2.490: nanosleep(rqtp: 140735694241504, rmtp: 0 ) = 0 2.507: exit_group(error_code: 0 [root@sandy linux]# For now the timestamp and duration are always on, will be selectable. Also if multiple threads are being monitored, its tid will appear. The ret output continues to be interpreted a la strace. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ly9ulroru4my5isn0xe9gr0m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-06 21:43:19 +00:00
ttrace = thread->priv;
if (ttrace->entry_str == NULL) {
ttrace->entry_str = malloc(1024);
if (!ttrace->entry_str)
return -1;
}
ttrace->entry_time = sample->time;
msg = ttrace->entry_str;
printed += scnprintf(msg + printed, 1024 - printed, "%s(", sc->name);
printed += syscall__scnprintf_args(sc, msg + printed, 1024 - printed, args);
if (!strcmp(sc->name, "exit_group") || !strcmp(sc->name, "exit")) {
if (!trace->duration_filter) {
trace__fprintf_entry_head(trace, thread, 1, sample->time, stdout);
printf("%-70s\n", ttrace->entry_str);
}
perf trace: Support interrupted syscalls Using the same strategies as in the tmp.perf/trace2, i.e. the 'trace' tool implemented by tglx, just updated to the current codebase. Example: [root@sandy linux]# perf trace usleep 1 | tail 2.003: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128396288 2.017: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128400384 2.029: arch_prctl(option: 4098, arg2: 140146949441280, arg3: 140146949435392, arg4: 34, arg5: 4294967295) = 0 2.084: mprotect(start: 208741634048, len: 16384, prot: 1 ) = 0 2.098: mprotect(start: 208735956992, len: 4096, prot: 1 ) = 0 2.122: munmap(addr: 140146949447680, len: 91882 ) = 0 2.359: brk(brk: 0 ) = 28987392 2.371: brk(brk: 29122560 ) = 29122560 2.490: nanosleep(rqtp: 140735694241504, rmtp: 0 ) = 0 2.507: exit_group(error_code: 0 [root@sandy linux]# For now the timestamp and duration are always on, will be selectable. Also if multiple threads are being monitored, its tid will appear. The ret output continues to be interpreted a la strace. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ly9ulroru4my5isn0xe9gr0m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-06 21:43:19 +00:00
} else
ttrace->entry_pending = true;
return 0;
}
static int trace__sys_exit(struct trace *trace, struct perf_evsel *evsel,
struct perf_sample *sample)
{
int ret;
u64 duration = 0;
perf trace: Support interrupted syscalls Using the same strategies as in the tmp.perf/trace2, i.e. the 'trace' tool implemented by tglx, just updated to the current codebase. Example: [root@sandy linux]# perf trace usleep 1 | tail 2.003: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128396288 2.017: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128400384 2.029: arch_prctl(option: 4098, arg2: 140146949441280, arg3: 140146949435392, arg4: 34, arg5: 4294967295) = 0 2.084: mprotect(start: 208741634048, len: 16384, prot: 1 ) = 0 2.098: mprotect(start: 208735956992, len: 4096, prot: 1 ) = 0 2.122: munmap(addr: 140146949447680, len: 91882 ) = 0 2.359: brk(brk: 0 ) = 28987392 2.371: brk(brk: 29122560 ) = 29122560 2.490: nanosleep(rqtp: 140735694241504, rmtp: 0 ) = 0 2.507: exit_group(error_code: 0 [root@sandy linux]# For now the timestamp and duration are always on, will be selectable. Also if multiple threads are being monitored, its tid will appear. The ret output continues to be interpreted a la strace. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ly9ulroru4my5isn0xe9gr0m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-06 21:43:19 +00:00
struct thread *thread = machine__findnew_thread(&trace->host, sample->tid);
struct thread_trace *ttrace = thread__trace(thread);
struct syscall *sc = trace__syscall_info(trace, evsel, sample);
perf trace: Support interrupted syscalls Using the same strategies as in the tmp.perf/trace2, i.e. the 'trace' tool implemented by tglx, just updated to the current codebase. Example: [root@sandy linux]# perf trace usleep 1 | tail 2.003: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128396288 2.017: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128400384 2.029: arch_prctl(option: 4098, arg2: 140146949441280, arg3: 140146949435392, arg4: 34, arg5: 4294967295) = 0 2.084: mprotect(start: 208741634048, len: 16384, prot: 1 ) = 0 2.098: mprotect(start: 208735956992, len: 4096, prot: 1 ) = 0 2.122: munmap(addr: 140146949447680, len: 91882 ) = 0 2.359: brk(brk: 0 ) = 28987392 2.371: brk(brk: 29122560 ) = 29122560 2.490: nanosleep(rqtp: 140735694241504, rmtp: 0 ) = 0 2.507: exit_group(error_code: 0 [root@sandy linux]# For now the timestamp and duration are always on, will be selectable. Also if multiple threads are being monitored, its tid will appear. The ret output continues to be interpreted a la strace. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ly9ulroru4my5isn0xe9gr0m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-06 21:43:19 +00:00
if (ttrace == NULL || sc == NULL)
return -1;
ret = perf_evsel__intval(evsel, sample, "ret");
perf trace: Support interrupted syscalls Using the same strategies as in the tmp.perf/trace2, i.e. the 'trace' tool implemented by tglx, just updated to the current codebase. Example: [root@sandy linux]# perf trace usleep 1 | tail 2.003: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128396288 2.017: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128400384 2.029: arch_prctl(option: 4098, arg2: 140146949441280, arg3: 140146949435392, arg4: 34, arg5: 4294967295) = 0 2.084: mprotect(start: 208741634048, len: 16384, prot: 1 ) = 0 2.098: mprotect(start: 208735956992, len: 4096, prot: 1 ) = 0 2.122: munmap(addr: 140146949447680, len: 91882 ) = 0 2.359: brk(brk: 0 ) = 28987392 2.371: brk(brk: 29122560 ) = 29122560 2.490: nanosleep(rqtp: 140735694241504, rmtp: 0 ) = 0 2.507: exit_group(error_code: 0 [root@sandy linux]# For now the timestamp and duration are always on, will be selectable. Also if multiple threads are being monitored, its tid will appear. The ret output continues to be interpreted a la strace. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ly9ulroru4my5isn0xe9gr0m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-06 21:43:19 +00:00
ttrace = thread->priv;
ttrace->exit_time = sample->time;
if (ttrace->entry_time) {
duration = sample->time - ttrace->entry_time;
if (trace__filter_duration(trace, duration))
goto out;
} else if (trace->duration_filter)
goto out;
trace__fprintf_entry_head(trace, thread, duration, sample->time, stdout);
perf trace: Support interrupted syscalls Using the same strategies as in the tmp.perf/trace2, i.e. the 'trace' tool implemented by tglx, just updated to the current codebase. Example: [root@sandy linux]# perf trace usleep 1 | tail 2.003: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128396288 2.017: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128400384 2.029: arch_prctl(option: 4098, arg2: 140146949441280, arg3: 140146949435392, arg4: 34, arg5: 4294967295) = 0 2.084: mprotect(start: 208741634048, len: 16384, prot: 1 ) = 0 2.098: mprotect(start: 208735956992, len: 4096, prot: 1 ) = 0 2.122: munmap(addr: 140146949447680, len: 91882 ) = 0 2.359: brk(brk: 0 ) = 28987392 2.371: brk(brk: 29122560 ) = 29122560 2.490: nanosleep(rqtp: 140735694241504, rmtp: 0 ) = 0 2.507: exit_group(error_code: 0 [root@sandy linux]# For now the timestamp and duration are always on, will be selectable. Also if multiple threads are being monitored, its tid will appear. The ret output continues to be interpreted a la strace. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ly9ulroru4my5isn0xe9gr0m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-06 21:43:19 +00:00
if (ttrace->entry_pending) {
printf("%-70s", ttrace->entry_str);
} else {
printf(" ... [");
color_fprintf(stdout, PERF_COLOR_YELLOW, "continued");
printf("]: %s()", sc->name);
}
if (ret < 0 && sc->fmt && sc->fmt->errmsg) {
char bf[256];
const char *emsg = strerror_r(-ret, bf, sizeof(bf)),
*e = audit_errno_to_name(-ret);
printf(") = -1 %s %s", e, emsg);
} else if (ret == 0 && sc->fmt && sc->fmt->timeout)
printf(") = 0 Timeout");
else
printf(") = %d", ret);
putchar('\n');
out:
perf trace: Support interrupted syscalls Using the same strategies as in the tmp.perf/trace2, i.e. the 'trace' tool implemented by tglx, just updated to the current codebase. Example: [root@sandy linux]# perf trace usleep 1 | tail 2.003: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128396288 2.017: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128400384 2.029: arch_prctl(option: 4098, arg2: 140146949441280, arg3: 140146949435392, arg4: 34, arg5: 4294967295) = 0 2.084: mprotect(start: 208741634048, len: 16384, prot: 1 ) = 0 2.098: mprotect(start: 208735956992, len: 4096, prot: 1 ) = 0 2.122: munmap(addr: 140146949447680, len: 91882 ) = 0 2.359: brk(brk: 0 ) = 28987392 2.371: brk(brk: 29122560 ) = 29122560 2.490: nanosleep(rqtp: 140735694241504, rmtp: 0 ) = 0 2.507: exit_group(error_code: 0 [root@sandy linux]# For now the timestamp and duration are always on, will be selectable. Also if multiple threads are being monitored, its tid will appear. The ret output continues to be interpreted a la strace. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ly9ulroru4my5isn0xe9gr0m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-06 21:43:19 +00:00
ttrace->entry_pending = false;
return 0;
}
perf trace: Use sched:sched_stat_runtime to provide a thread summary [root@sandy ~]# perf trace --sched --duration 0.100 --pid `pidof firefox` <SNIP> 17079.847 ( 0.009 ms): 17643 poll(ufds: 140037623086496, nfds: 11, timeout_msecs: 0) = 0 Timeout 17079.892 ( 0.010 ms): 17643 read(fd: 4, buf: 140038178943092, count: 4096 ) = -1 EAGAIN Resource temporarily unavailable 17079.921 ( 0.013 ms): 17643 poll(ufds: 140037623086496, nfds: 11, timeout_msecs: 0) = 0 Timeout 17079.949 ( 0.009 ms): 17643 read(fd: 4, buf: 140038178943092, count: 4096 ) = -1 EAGAIN Resource temporarily unavailable ^C _____________________________________________________________________ __) Summary of events (__ [ task - pid ] [ events ] [ ratio ] [ runtime ] _____________________________________________________________________ firefox - 17643 : 18013 [ 72.2% ] 359.110 ms firefox - 17663 : 41 [ 0.2% ] 21.439 ms firefox - 17664 : 6840 [ 27.4% ] 133.642 ms firefox - 17667 : 46 [ 0.2% ] 0.682 ms [root@sandy ~]# This is equivalent to the 'perf trace summary' subcomand in the tmp.perf/trace2 branch. Another example, setting a huge duration filter to get just a system wide summary: [root@sandy ~]# perf trace --duration 10000.0 --sched ^C _____________________________________________________________________ __) Summary of events (__ [ task - pid ] [ events ] [ ratio ] [ runtime ] _____________________________________________________________________ scsi_eh_1 - 258 : 15 [ 0.0% ] 0.133 ms kworker/0:1H - 322 : 13 [ 0.0% ] 0.032 ms jbd2/dm-0-8 - 384 : 4 [ 0.0% ] 0.115 ms flush-253:0 - 470 : 1 [ 0.0% ] 0.027 ms firefox - 950 : 4783 [ 0.1% ] 24.863 ms firefox - 992 : 1883 [ 0.1% ] 6.808 ms firefox - 995 : 35 [ 0.0% ] 0.111 ms ksoftirqd/6 - 4362 : 2 [ 0.0% ] 0.005 ms ksoftirqd/7 - 4365 : 1 [ 0.0% ] 0.007 ms Xorg - 4671 : 148 [ 0.0% ] 0.912 ms gnome-settings- - 4846 : 14 [ 0.0% ] 0.086 ms seahorse-daemon - 4847 : 14 [ 0.0% ] 0.092 ms gnome-panel - 4875 : 46 [ 0.0% ] 0.159 ms gnome-power-man - 4918 : 16 [ 0.0% ] 0.065 ms gvfs-afc-volume - 4992 : 77 [ 0.0% ] 0.136 ms gnome-screensav - 5114 : 24 [ 0.0% ] 0.128 ms xchat - 8082 : 466 [ 0.0% ] 2.019 ms synergyc - 8369 : 941 [ 0.0% ] 3.291 ms synergyc - 8371 : 85 [ 0.0% ] 1.817 ms jbd2/dm-4-8 - 9352 : 4 [ 0.0% ] 0.109 ms rpcbind - 9786 : 3 [ 0.0% ] 0.017 ms rtkit-daemon - 12802 : 10 [ 0.0% ] 0.038 ms rtkit-daemon - 12803 : 8 [ 0.0% ] 0.000 ms udisks-daemon - 13020 : 27 [ 0.0% ] 0.240 ms kworker/7:0 - 14651 : 669 [ 0.0% ] 2.616 ms kworker/5:1 - 16220 : 2 [ 0.0% ] 0.069 ms kworker/4:0 - 19776 : 13 [ 0.0% ] 0.176 ms openvpn - 20131 : 133 [ 0.0% ] 0.762 ms plugin-containe - 20508 : 60658 [ 1.7% ] 131.153 ms npviewer.bin - 20520 : 72208 [ 2.0% ] 138.945 ms npviewer.bin - 20542 : 35 [ 0.0% ] 0.074 ms npviewer.bin - 20543 : 30 [ 0.0% ] 0.074 ms npviewer.bin - 20547 : 35 [ 0.0% ] 0.092 ms npviewer.bin - 20552 : 35 [ 0.0% ] 0.093 ms sshd - 20645 : 32 [ 0.0% ] 0.071 ms npviewer.bin - 21053 : 35 [ 0.0% ] 0.074 ms npviewer.bin - 21054 : 35 [ 0.0% ] 0.097 ms kworker/0:2 - 21169 : 149 [ 0.0% ] 1.143 ms kworker/3:0 - 22171 : 113 [ 0.0% ] 96.892 ms flush-253:4 - 22410 : 1 [ 0.0% ] 0.028 ms kworker/6:0 - 24581 : 25 [ 0.0% ] 0.275 ms kworker/1:0 - 25572 : 4 [ 0.0% ] 0.103 ms kworker/2:1 - 26299 : 138 [ 0.0% ] 1.440 ms kworker/0:0 - 26325 : 1 [ 0.0% ] 0.003 ms perf - 26330 : 3506967 [ 96.1% ] 6648.310 ms [root@sandy ~]# Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-mzuli0srnxyi1o029py6537x@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-17 20:13:12 +00:00
static int trace__sched_stat_runtime(struct trace *trace, struct perf_evsel *evsel,
struct perf_sample *sample)
{
u64 runtime = perf_evsel__intval(evsel, sample, "runtime");
double runtime_ms = (double)runtime / NSEC_PER_MSEC;
struct thread *thread = machine__findnew_thread(&trace->host, sample->tid);
struct thread_trace *ttrace = thread__trace(thread);
if (ttrace == NULL)
goto out_dump;
ttrace->runtime_ms += runtime_ms;
trace->runtime_ms += runtime_ms;
return 0;
out_dump:
printf("%s: comm=%s,pid=%u,runtime=%" PRIu64 ",vruntime=%" PRIu64 ")\n",
evsel->name,
perf_evsel__strval(evsel, sample, "comm"),
(pid_t)perf_evsel__intval(evsel, sample, "pid"),
runtime,
perf_evsel__intval(evsel, sample, "vruntime"));
return 0;
}
static int trace__run(struct trace *trace, int argc, const char **argv)
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
{
struct perf_evlist *evlist = perf_evlist__new(NULL, NULL);
struct perf_evsel *evsel;
int err = -1, i;
unsigned long before;
const bool forks = argc > 0;
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
if (evlist == NULL) {
printf("Not enough memory to run!\n");
goto out;
}
if (perf_evlist__add_newtp(evlist, "raw_syscalls", "sys_enter", trace__sys_enter) ||
perf_evlist__add_newtp(evlist, "raw_syscalls", "sys_exit", trace__sys_exit)) {
printf("Couldn't read the raw_syscalls tracepoints information!\n");
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
goto out_delete_evlist;
}
perf trace: Use sched:sched_stat_runtime to provide a thread summary [root@sandy ~]# perf trace --sched --duration 0.100 --pid `pidof firefox` <SNIP> 17079.847 ( 0.009 ms): 17643 poll(ufds: 140037623086496, nfds: 11, timeout_msecs: 0) = 0 Timeout 17079.892 ( 0.010 ms): 17643 read(fd: 4, buf: 140038178943092, count: 4096 ) = -1 EAGAIN Resource temporarily unavailable 17079.921 ( 0.013 ms): 17643 poll(ufds: 140037623086496, nfds: 11, timeout_msecs: 0) = 0 Timeout 17079.949 ( 0.009 ms): 17643 read(fd: 4, buf: 140038178943092, count: 4096 ) = -1 EAGAIN Resource temporarily unavailable ^C _____________________________________________________________________ __) Summary of events (__ [ task - pid ] [ events ] [ ratio ] [ runtime ] _____________________________________________________________________ firefox - 17643 : 18013 [ 72.2% ] 359.110 ms firefox - 17663 : 41 [ 0.2% ] 21.439 ms firefox - 17664 : 6840 [ 27.4% ] 133.642 ms firefox - 17667 : 46 [ 0.2% ] 0.682 ms [root@sandy ~]# This is equivalent to the 'perf trace summary' subcomand in the tmp.perf/trace2 branch. Another example, setting a huge duration filter to get just a system wide summary: [root@sandy ~]# perf trace --duration 10000.0 --sched ^C _____________________________________________________________________ __) Summary of events (__ [ task - pid ] [ events ] [ ratio ] [ runtime ] _____________________________________________________________________ scsi_eh_1 - 258 : 15 [ 0.0% ] 0.133 ms kworker/0:1H - 322 : 13 [ 0.0% ] 0.032 ms jbd2/dm-0-8 - 384 : 4 [ 0.0% ] 0.115 ms flush-253:0 - 470 : 1 [ 0.0% ] 0.027 ms firefox - 950 : 4783 [ 0.1% ] 24.863 ms firefox - 992 : 1883 [ 0.1% ] 6.808 ms firefox - 995 : 35 [ 0.0% ] 0.111 ms ksoftirqd/6 - 4362 : 2 [ 0.0% ] 0.005 ms ksoftirqd/7 - 4365 : 1 [ 0.0% ] 0.007 ms Xorg - 4671 : 148 [ 0.0% ] 0.912 ms gnome-settings- - 4846 : 14 [ 0.0% ] 0.086 ms seahorse-daemon - 4847 : 14 [ 0.0% ] 0.092 ms gnome-panel - 4875 : 46 [ 0.0% ] 0.159 ms gnome-power-man - 4918 : 16 [ 0.0% ] 0.065 ms gvfs-afc-volume - 4992 : 77 [ 0.0% ] 0.136 ms gnome-screensav - 5114 : 24 [ 0.0% ] 0.128 ms xchat - 8082 : 466 [ 0.0% ] 2.019 ms synergyc - 8369 : 941 [ 0.0% ] 3.291 ms synergyc - 8371 : 85 [ 0.0% ] 1.817 ms jbd2/dm-4-8 - 9352 : 4 [ 0.0% ] 0.109 ms rpcbind - 9786 : 3 [ 0.0% ] 0.017 ms rtkit-daemon - 12802 : 10 [ 0.0% ] 0.038 ms rtkit-daemon - 12803 : 8 [ 0.0% ] 0.000 ms udisks-daemon - 13020 : 27 [ 0.0% ] 0.240 ms kworker/7:0 - 14651 : 669 [ 0.0% ] 2.616 ms kworker/5:1 - 16220 : 2 [ 0.0% ] 0.069 ms kworker/4:0 - 19776 : 13 [ 0.0% ] 0.176 ms openvpn - 20131 : 133 [ 0.0% ] 0.762 ms plugin-containe - 20508 : 60658 [ 1.7% ] 131.153 ms npviewer.bin - 20520 : 72208 [ 2.0% ] 138.945 ms npviewer.bin - 20542 : 35 [ 0.0% ] 0.074 ms npviewer.bin - 20543 : 30 [ 0.0% ] 0.074 ms npviewer.bin - 20547 : 35 [ 0.0% ] 0.092 ms npviewer.bin - 20552 : 35 [ 0.0% ] 0.093 ms sshd - 20645 : 32 [ 0.0% ] 0.071 ms npviewer.bin - 21053 : 35 [ 0.0% ] 0.074 ms npviewer.bin - 21054 : 35 [ 0.0% ] 0.097 ms kworker/0:2 - 21169 : 149 [ 0.0% ] 1.143 ms kworker/3:0 - 22171 : 113 [ 0.0% ] 96.892 ms flush-253:4 - 22410 : 1 [ 0.0% ] 0.028 ms kworker/6:0 - 24581 : 25 [ 0.0% ] 0.275 ms kworker/1:0 - 25572 : 4 [ 0.0% ] 0.103 ms kworker/2:1 - 26299 : 138 [ 0.0% ] 1.440 ms kworker/0:0 - 26325 : 1 [ 0.0% ] 0.003 ms perf - 26330 : 3506967 [ 96.1% ] 6648.310 ms [root@sandy ~]# Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-mzuli0srnxyi1o029py6537x@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-17 20:13:12 +00:00
if (trace->sched &&
perf_evlist__add_newtp(evlist, "sched", "sched_stat_runtime",
trace__sched_stat_runtime)) {
printf("Couldn't read the sched_stat_runtime tracepoint information!\n");
goto out_delete_evlist;
}
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
err = perf_evlist__create_maps(evlist, &trace->opts.target);
if (err < 0) {
printf("Problems parsing the target to trace, check your options!\n");
goto out_delete_evlist;
}
perf trace: Support interrupted syscalls Using the same strategies as in the tmp.perf/trace2, i.e. the 'trace' tool implemented by tglx, just updated to the current codebase. Example: [root@sandy linux]# perf trace usleep 1 | tail 2.003: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128396288 2.017: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128400384 2.029: arch_prctl(option: 4098, arg2: 140146949441280, arg3: 140146949435392, arg4: 34, arg5: 4294967295) = 0 2.084: mprotect(start: 208741634048, len: 16384, prot: 1 ) = 0 2.098: mprotect(start: 208735956992, len: 4096, prot: 1 ) = 0 2.122: munmap(addr: 140146949447680, len: 91882 ) = 0 2.359: brk(brk: 0 ) = 28987392 2.371: brk(brk: 29122560 ) = 29122560 2.490: nanosleep(rqtp: 140735694241504, rmtp: 0 ) = 0 2.507: exit_group(error_code: 0 [root@sandy linux]# For now the timestamp and duration are always on, will be selectable. Also if multiple threads are being monitored, its tid will appear. The ret output continues to be interpreted a la strace. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ly9ulroru4my5isn0xe9gr0m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-06 21:43:19 +00:00
err = trace__symbols_init(trace, evlist);
if (err < 0) {
printf("Problems initializing symbol libraries!\n");
goto out_delete_evlist;
}
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
perf_evlist__config_attrs(evlist, &trace->opts);
signal(SIGCHLD, sig_handler);
signal(SIGINT, sig_handler);
if (forks) {
err = perf_evlist__prepare_workload(evlist, &trace->opts, argv);
if (err < 0) {
printf("Couldn't run the workload!\n");
goto out_delete_evlist;
}
}
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
err = perf_evlist__open(evlist);
if (err < 0) {
printf("Couldn't create the events: %s\n", strerror(errno));
goto out_delete_evlist;
}
err = perf_evlist__mmap(evlist, UINT_MAX, false);
if (err < 0) {
printf("Couldn't mmap the events: %s\n", strerror(errno));
goto out_delete_evlist;
}
perf_evlist__enable(evlist);
if (forks)
perf_evlist__start_workload(evlist);
perf trace: Support interrupted syscalls Using the same strategies as in the tmp.perf/trace2, i.e. the 'trace' tool implemented by tglx, just updated to the current codebase. Example: [root@sandy linux]# perf trace usleep 1 | tail 2.003: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128396288 2.017: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128400384 2.029: arch_prctl(option: 4098, arg2: 140146949441280, arg3: 140146949435392, arg4: 34, arg5: 4294967295) = 0 2.084: mprotect(start: 208741634048, len: 16384, prot: 1 ) = 0 2.098: mprotect(start: 208735956992, len: 4096, prot: 1 ) = 0 2.122: munmap(addr: 140146949447680, len: 91882 ) = 0 2.359: brk(brk: 0 ) = 28987392 2.371: brk(brk: 29122560 ) = 29122560 2.490: nanosleep(rqtp: 140735694241504, rmtp: 0 ) = 0 2.507: exit_group(error_code: 0 [root@sandy linux]# For now the timestamp and duration are always on, will be selectable. Also if multiple threads are being monitored, its tid will appear. The ret output continues to be interpreted a la strace. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ly9ulroru4my5isn0xe9gr0m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-06 21:43:19 +00:00
trace->multiple_threads = evlist->threads->map[0] == -1 || evlist->threads->nr > 1;
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
again:
before = trace->nr_events;
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
for (i = 0; i < evlist->nr_mmaps; i++) {
union perf_event *event;
while ((event = perf_evlist__mmap_read(evlist, i)) != NULL) {
const u32 type = event->header.type;
tracepoint_handler handler;
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
struct perf_sample sample;
++trace->nr_events;
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
err = perf_evlist__parse_sample(evlist, event, &sample);
if (err) {
printf("Can't parse sample, err = %d, skipping...\n", err);
continue;
}
perf trace: Support interrupted syscalls Using the same strategies as in the tmp.perf/trace2, i.e. the 'trace' tool implemented by tglx, just updated to the current codebase. Example: [root@sandy linux]# perf trace usleep 1 | tail 2.003: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128396288 2.017: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128400384 2.029: arch_prctl(option: 4098, arg2: 140146949441280, arg3: 140146949435392, arg4: 34, arg5: 4294967295) = 0 2.084: mprotect(start: 208741634048, len: 16384, prot: 1 ) = 0 2.098: mprotect(start: 208735956992, len: 4096, prot: 1 ) = 0 2.122: munmap(addr: 140146949447680, len: 91882 ) = 0 2.359: brk(brk: 0 ) = 28987392 2.371: brk(brk: 29122560 ) = 29122560 2.490: nanosleep(rqtp: 140735694241504, rmtp: 0 ) = 0 2.507: exit_group(error_code: 0 [root@sandy linux]# For now the timestamp and duration are always on, will be selectable. Also if multiple threads are being monitored, its tid will appear. The ret output continues to be interpreted a la strace. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ly9ulroru4my5isn0xe9gr0m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-06 21:43:19 +00:00
if (trace->base_time == 0)
trace->base_time = sample.time;
if (type != PERF_RECORD_SAMPLE) {
trace__process_event(&trace->host, event);
continue;
}
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
evsel = perf_evlist__id2evsel(evlist, sample.id);
if (evsel == NULL) {
printf("Unknown tp ID %" PRIu64 ", skipping...\n", sample.id);
continue;
}
perf trace: Support interrupted syscalls Using the same strategies as in the tmp.perf/trace2, i.e. the 'trace' tool implemented by tglx, just updated to the current codebase. Example: [root@sandy linux]# perf trace usleep 1 | tail 2.003: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128396288 2.017: mmap(addr: 0, len: 4096, prot: 3, flags: 34, fd: 4294967295, off: 0 ) = -2128400384 2.029: arch_prctl(option: 4098, arg2: 140146949441280, arg3: 140146949435392, arg4: 34, arg5: 4294967295) = 0 2.084: mprotect(start: 208741634048, len: 16384, prot: 1 ) = 0 2.098: mprotect(start: 208735956992, len: 4096, prot: 1 ) = 0 2.122: munmap(addr: 140146949447680, len: 91882 ) = 0 2.359: brk(brk: 0 ) = 28987392 2.371: brk(brk: 29122560 ) = 29122560 2.490: nanosleep(rqtp: 140735694241504, rmtp: 0 ) = 0 2.507: exit_group(error_code: 0 [root@sandy linux]# For now the timestamp and duration are always on, will be selectable. Also if multiple threads are being monitored, its tid will appear. The ret output continues to be interpreted a la strace. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/n/tip-ly9ulroru4my5isn0xe9gr0m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-06 21:43:19 +00:00
if (sample.raw_data == NULL) {
printf("%s sample with no payload for tid: %d, cpu %d, raw_size=%d, skipping...\n",
perf_evsel__name(evsel), sample.tid,
sample.cpu, sample.raw_size);
continue;
}
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
if (sample.raw_data == NULL) {
printf("%s sample with no payload for tid: %d, cpu %d, raw_size=%d, skipping...\n",
perf_evsel__name(evsel), sample.tid,
sample.cpu, sample.raw_size);
continue;
}
handler = evsel->handler.func;
handler(trace, evsel, &sample);
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
}
}
if (trace->nr_events == before) {
if (done)
goto out_delete_evlist;
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
poll(evlist->pollfd, evlist->nr_fds, -1);
}
if (done)
perf_evlist__disable(evlist);
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
goto again;
out_delete_evlist:
perf_evlist__delete(evlist);
out:
return err;
}
perf trace: Use sched:sched_stat_runtime to provide a thread summary [root@sandy ~]# perf trace --sched --duration 0.100 --pid `pidof firefox` <SNIP> 17079.847 ( 0.009 ms): 17643 poll(ufds: 140037623086496, nfds: 11, timeout_msecs: 0) = 0 Timeout 17079.892 ( 0.010 ms): 17643 read(fd: 4, buf: 140038178943092, count: 4096 ) = -1 EAGAIN Resource temporarily unavailable 17079.921 ( 0.013 ms): 17643 poll(ufds: 140037623086496, nfds: 11, timeout_msecs: 0) = 0 Timeout 17079.949 ( 0.009 ms): 17643 read(fd: 4, buf: 140038178943092, count: 4096 ) = -1 EAGAIN Resource temporarily unavailable ^C _____________________________________________________________________ __) Summary of events (__ [ task - pid ] [ events ] [ ratio ] [ runtime ] _____________________________________________________________________ firefox - 17643 : 18013 [ 72.2% ] 359.110 ms firefox - 17663 : 41 [ 0.2% ] 21.439 ms firefox - 17664 : 6840 [ 27.4% ] 133.642 ms firefox - 17667 : 46 [ 0.2% ] 0.682 ms [root@sandy ~]# This is equivalent to the 'perf trace summary' subcomand in the tmp.perf/trace2 branch. Another example, setting a huge duration filter to get just a system wide summary: [root@sandy ~]# perf trace --duration 10000.0 --sched ^C _____________________________________________________________________ __) Summary of events (__ [ task - pid ] [ events ] [ ratio ] [ runtime ] _____________________________________________________________________ scsi_eh_1 - 258 : 15 [ 0.0% ] 0.133 ms kworker/0:1H - 322 : 13 [ 0.0% ] 0.032 ms jbd2/dm-0-8 - 384 : 4 [ 0.0% ] 0.115 ms flush-253:0 - 470 : 1 [ 0.0% ] 0.027 ms firefox - 950 : 4783 [ 0.1% ] 24.863 ms firefox - 992 : 1883 [ 0.1% ] 6.808 ms firefox - 995 : 35 [ 0.0% ] 0.111 ms ksoftirqd/6 - 4362 : 2 [ 0.0% ] 0.005 ms ksoftirqd/7 - 4365 : 1 [ 0.0% ] 0.007 ms Xorg - 4671 : 148 [ 0.0% ] 0.912 ms gnome-settings- - 4846 : 14 [ 0.0% ] 0.086 ms seahorse-daemon - 4847 : 14 [ 0.0% ] 0.092 ms gnome-panel - 4875 : 46 [ 0.0% ] 0.159 ms gnome-power-man - 4918 : 16 [ 0.0% ] 0.065 ms gvfs-afc-volume - 4992 : 77 [ 0.0% ] 0.136 ms gnome-screensav - 5114 : 24 [ 0.0% ] 0.128 ms xchat - 8082 : 466 [ 0.0% ] 2.019 ms synergyc - 8369 : 941 [ 0.0% ] 3.291 ms synergyc - 8371 : 85 [ 0.0% ] 1.817 ms jbd2/dm-4-8 - 9352 : 4 [ 0.0% ] 0.109 ms rpcbind - 9786 : 3 [ 0.0% ] 0.017 ms rtkit-daemon - 12802 : 10 [ 0.0% ] 0.038 ms rtkit-daemon - 12803 : 8 [ 0.0% ] 0.000 ms udisks-daemon - 13020 : 27 [ 0.0% ] 0.240 ms kworker/7:0 - 14651 : 669 [ 0.0% ] 2.616 ms kworker/5:1 - 16220 : 2 [ 0.0% ] 0.069 ms kworker/4:0 - 19776 : 13 [ 0.0% ] 0.176 ms openvpn - 20131 : 133 [ 0.0% ] 0.762 ms plugin-containe - 20508 : 60658 [ 1.7% ] 131.153 ms npviewer.bin - 20520 : 72208 [ 2.0% ] 138.945 ms npviewer.bin - 20542 : 35 [ 0.0% ] 0.074 ms npviewer.bin - 20543 : 30 [ 0.0% ] 0.074 ms npviewer.bin - 20547 : 35 [ 0.0% ] 0.092 ms npviewer.bin - 20552 : 35 [ 0.0% ] 0.093 ms sshd - 20645 : 32 [ 0.0% ] 0.071 ms npviewer.bin - 21053 : 35 [ 0.0% ] 0.074 ms npviewer.bin - 21054 : 35 [ 0.0% ] 0.097 ms kworker/0:2 - 21169 : 149 [ 0.0% ] 1.143 ms kworker/3:0 - 22171 : 113 [ 0.0% ] 96.892 ms flush-253:4 - 22410 : 1 [ 0.0% ] 0.028 ms kworker/6:0 - 24581 : 25 [ 0.0% ] 0.275 ms kworker/1:0 - 25572 : 4 [ 0.0% ] 0.103 ms kworker/2:1 - 26299 : 138 [ 0.0% ] 1.440 ms kworker/0:0 - 26325 : 1 [ 0.0% ] 0.003 ms perf - 26330 : 3506967 [ 96.1% ] 6648.310 ms [root@sandy ~]# Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-mzuli0srnxyi1o029py6537x@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-17 20:13:12 +00:00
static size_t trace__fprintf_threads_header(FILE *fp)
{
size_t printed;
printed = fprintf(fp, "\n _____________________________________________________________________\n");
printed += fprintf(fp," __) Summary of events (__\n\n");
printed += fprintf(fp," [ task - pid ] [ events ] [ ratio ] [ runtime ]\n");
printed += fprintf(fp," _____________________________________________________________________\n\n");
return printed;
}
static size_t trace__fprintf_thread_summary(struct trace *trace, FILE *fp)
{
size_t printed = trace__fprintf_threads_header(fp);
struct rb_node *nd;
for (nd = rb_first(&trace->host.threads); nd; nd = rb_next(nd)) {
struct thread *thread = rb_entry(nd, struct thread, rb_node);
struct thread_trace *ttrace = thread->priv;
const char *color;
double ratio;
if (ttrace == NULL)
continue;
ratio = (double)ttrace->nr_events / trace->nr_events * 100.0;
color = PERF_COLOR_NORMAL;
if (ratio > 50.0)
color = PERF_COLOR_RED;
else if (ratio > 25.0)
color = PERF_COLOR_GREEN;
else if (ratio > 5.0)
color = PERF_COLOR_YELLOW;
printed += color_fprintf(fp, color, "%20s", thread->comm);
printed += fprintf(fp, " - %-5d :%11lu [", thread->pid, ttrace->nr_events);
printed += color_fprintf(fp, color, "%5.1f%%", ratio);
printed += fprintf(fp, " ] %10.3f ms\n", ttrace->runtime_ms);
}
return printed;
}
static int trace__set_duration(const struct option *opt, const char *str,
int unset __maybe_unused)
{
struct trace *trace = opt->value;
trace->duration_filter = atof(str);
return 0;
}
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
int cmd_trace(int argc, const char **argv, const char *prefix __maybe_unused)
{
const char * const trace_usage[] = {
"perf trace [<options>] [<command>]",
"perf trace [<options>] -- <command> [<options>]",
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
NULL
};
struct trace trace = {
.audit_machine = audit_detect_machine(),
.syscalls = {
. max = -1,
},
.opts = {
.target = {
.uid = UINT_MAX,
.uses_mmap = true,
},
.user_freq = UINT_MAX,
.user_interval = ULLONG_MAX,
.no_delay = true,
.mmap_pages = 1024,
},
};
const struct option trace_options[] = {
OPT_STRING('p', "pid", &trace.opts.target.pid, "pid",
"trace events on existing process id"),
OPT_STRING(0, "tid", &trace.opts.target.tid, "tid",
"trace events on existing thread id"),
OPT_BOOLEAN(0, "all-cpus", &trace.opts.target.system_wide,
"system-wide collection from all CPUs"),
OPT_STRING(0, "cpu", &trace.opts.target.cpu_list, "cpu",
"list of cpus to monitor"),
OPT_BOOLEAN(0, "no-inherit", &trace.opts.no_inherit,
"child tasks do not inherit counters"),
OPT_UINTEGER(0, "mmap-pages", &trace.opts.mmap_pages,
"number of mmap data pages"),
OPT_STRING(0, "uid", &trace.opts.target.uid_str, "user",
"user to profile"),
OPT_CALLBACK(0, "duration", &trace, "float",
"show only events with duration > N.M ms",
trace__set_duration),
perf trace: Use sched:sched_stat_runtime to provide a thread summary [root@sandy ~]# perf trace --sched --duration 0.100 --pid `pidof firefox` <SNIP> 17079.847 ( 0.009 ms): 17643 poll(ufds: 140037623086496, nfds: 11, timeout_msecs: 0) = 0 Timeout 17079.892 ( 0.010 ms): 17643 read(fd: 4, buf: 140038178943092, count: 4096 ) = -1 EAGAIN Resource temporarily unavailable 17079.921 ( 0.013 ms): 17643 poll(ufds: 140037623086496, nfds: 11, timeout_msecs: 0) = 0 Timeout 17079.949 ( 0.009 ms): 17643 read(fd: 4, buf: 140038178943092, count: 4096 ) = -1 EAGAIN Resource temporarily unavailable ^C _____________________________________________________________________ __) Summary of events (__ [ task - pid ] [ events ] [ ratio ] [ runtime ] _____________________________________________________________________ firefox - 17643 : 18013 [ 72.2% ] 359.110 ms firefox - 17663 : 41 [ 0.2% ] 21.439 ms firefox - 17664 : 6840 [ 27.4% ] 133.642 ms firefox - 17667 : 46 [ 0.2% ] 0.682 ms [root@sandy ~]# This is equivalent to the 'perf trace summary' subcomand in the tmp.perf/trace2 branch. Another example, setting a huge duration filter to get just a system wide summary: [root@sandy ~]# perf trace --duration 10000.0 --sched ^C _____________________________________________________________________ __) Summary of events (__ [ task - pid ] [ events ] [ ratio ] [ runtime ] _____________________________________________________________________ scsi_eh_1 - 258 : 15 [ 0.0% ] 0.133 ms kworker/0:1H - 322 : 13 [ 0.0% ] 0.032 ms jbd2/dm-0-8 - 384 : 4 [ 0.0% ] 0.115 ms flush-253:0 - 470 : 1 [ 0.0% ] 0.027 ms firefox - 950 : 4783 [ 0.1% ] 24.863 ms firefox - 992 : 1883 [ 0.1% ] 6.808 ms firefox - 995 : 35 [ 0.0% ] 0.111 ms ksoftirqd/6 - 4362 : 2 [ 0.0% ] 0.005 ms ksoftirqd/7 - 4365 : 1 [ 0.0% ] 0.007 ms Xorg - 4671 : 148 [ 0.0% ] 0.912 ms gnome-settings- - 4846 : 14 [ 0.0% ] 0.086 ms seahorse-daemon - 4847 : 14 [ 0.0% ] 0.092 ms gnome-panel - 4875 : 46 [ 0.0% ] 0.159 ms gnome-power-man - 4918 : 16 [ 0.0% ] 0.065 ms gvfs-afc-volume - 4992 : 77 [ 0.0% ] 0.136 ms gnome-screensav - 5114 : 24 [ 0.0% ] 0.128 ms xchat - 8082 : 466 [ 0.0% ] 2.019 ms synergyc - 8369 : 941 [ 0.0% ] 3.291 ms synergyc - 8371 : 85 [ 0.0% ] 1.817 ms jbd2/dm-4-8 - 9352 : 4 [ 0.0% ] 0.109 ms rpcbind - 9786 : 3 [ 0.0% ] 0.017 ms rtkit-daemon - 12802 : 10 [ 0.0% ] 0.038 ms rtkit-daemon - 12803 : 8 [ 0.0% ] 0.000 ms udisks-daemon - 13020 : 27 [ 0.0% ] 0.240 ms kworker/7:0 - 14651 : 669 [ 0.0% ] 2.616 ms kworker/5:1 - 16220 : 2 [ 0.0% ] 0.069 ms kworker/4:0 - 19776 : 13 [ 0.0% ] 0.176 ms openvpn - 20131 : 133 [ 0.0% ] 0.762 ms plugin-containe - 20508 : 60658 [ 1.7% ] 131.153 ms npviewer.bin - 20520 : 72208 [ 2.0% ] 138.945 ms npviewer.bin - 20542 : 35 [ 0.0% ] 0.074 ms npviewer.bin - 20543 : 30 [ 0.0% ] 0.074 ms npviewer.bin - 20547 : 35 [ 0.0% ] 0.092 ms npviewer.bin - 20552 : 35 [ 0.0% ] 0.093 ms sshd - 20645 : 32 [ 0.0% ] 0.071 ms npviewer.bin - 21053 : 35 [ 0.0% ] 0.074 ms npviewer.bin - 21054 : 35 [ 0.0% ] 0.097 ms kworker/0:2 - 21169 : 149 [ 0.0% ] 1.143 ms kworker/3:0 - 22171 : 113 [ 0.0% ] 96.892 ms flush-253:4 - 22410 : 1 [ 0.0% ] 0.028 ms kworker/6:0 - 24581 : 25 [ 0.0% ] 0.275 ms kworker/1:0 - 25572 : 4 [ 0.0% ] 0.103 ms kworker/2:1 - 26299 : 138 [ 0.0% ] 1.440 ms kworker/0:0 - 26325 : 1 [ 0.0% ] 0.003 ms perf - 26330 : 3506967 [ 96.1% ] 6648.310 ms [root@sandy ~]# Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-mzuli0srnxyi1o029py6537x@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-17 20:13:12 +00:00
OPT_BOOLEAN(0, "sched", &trace.sched, "show blocking scheduler events"),
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
OPT_END()
};
int err;
char bf[BUFSIZ];
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
argc = parse_options(argc, argv, trace_options, trace_usage, 0);
err = perf_target__validate(&trace.opts.target);
if (err) {
perf_target__strerror(&trace.opts.target, err, bf, sizeof(bf));
printf("%s", bf);
return err;
}
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
err = perf_target__parse_uid(&trace.opts.target);
if (err) {
perf_target__strerror(&trace.opts.target, err, bf, sizeof(bf));
printf("%s", bf);
return err;
}
if (!argc && perf_target__none(&trace.opts.target))
trace.opts.target.system_wide = true;
perf trace: Use sched:sched_stat_runtime to provide a thread summary [root@sandy ~]# perf trace --sched --duration 0.100 --pid `pidof firefox` <SNIP> 17079.847 ( 0.009 ms): 17643 poll(ufds: 140037623086496, nfds: 11, timeout_msecs: 0) = 0 Timeout 17079.892 ( 0.010 ms): 17643 read(fd: 4, buf: 140038178943092, count: 4096 ) = -1 EAGAIN Resource temporarily unavailable 17079.921 ( 0.013 ms): 17643 poll(ufds: 140037623086496, nfds: 11, timeout_msecs: 0) = 0 Timeout 17079.949 ( 0.009 ms): 17643 read(fd: 4, buf: 140038178943092, count: 4096 ) = -1 EAGAIN Resource temporarily unavailable ^C _____________________________________________________________________ __) Summary of events (__ [ task - pid ] [ events ] [ ratio ] [ runtime ] _____________________________________________________________________ firefox - 17643 : 18013 [ 72.2% ] 359.110 ms firefox - 17663 : 41 [ 0.2% ] 21.439 ms firefox - 17664 : 6840 [ 27.4% ] 133.642 ms firefox - 17667 : 46 [ 0.2% ] 0.682 ms [root@sandy ~]# This is equivalent to the 'perf trace summary' subcomand in the tmp.perf/trace2 branch. Another example, setting a huge duration filter to get just a system wide summary: [root@sandy ~]# perf trace --duration 10000.0 --sched ^C _____________________________________________________________________ __) Summary of events (__ [ task - pid ] [ events ] [ ratio ] [ runtime ] _____________________________________________________________________ scsi_eh_1 - 258 : 15 [ 0.0% ] 0.133 ms kworker/0:1H - 322 : 13 [ 0.0% ] 0.032 ms jbd2/dm-0-8 - 384 : 4 [ 0.0% ] 0.115 ms flush-253:0 - 470 : 1 [ 0.0% ] 0.027 ms firefox - 950 : 4783 [ 0.1% ] 24.863 ms firefox - 992 : 1883 [ 0.1% ] 6.808 ms firefox - 995 : 35 [ 0.0% ] 0.111 ms ksoftirqd/6 - 4362 : 2 [ 0.0% ] 0.005 ms ksoftirqd/7 - 4365 : 1 [ 0.0% ] 0.007 ms Xorg - 4671 : 148 [ 0.0% ] 0.912 ms gnome-settings- - 4846 : 14 [ 0.0% ] 0.086 ms seahorse-daemon - 4847 : 14 [ 0.0% ] 0.092 ms gnome-panel - 4875 : 46 [ 0.0% ] 0.159 ms gnome-power-man - 4918 : 16 [ 0.0% ] 0.065 ms gvfs-afc-volume - 4992 : 77 [ 0.0% ] 0.136 ms gnome-screensav - 5114 : 24 [ 0.0% ] 0.128 ms xchat - 8082 : 466 [ 0.0% ] 2.019 ms synergyc - 8369 : 941 [ 0.0% ] 3.291 ms synergyc - 8371 : 85 [ 0.0% ] 1.817 ms jbd2/dm-4-8 - 9352 : 4 [ 0.0% ] 0.109 ms rpcbind - 9786 : 3 [ 0.0% ] 0.017 ms rtkit-daemon - 12802 : 10 [ 0.0% ] 0.038 ms rtkit-daemon - 12803 : 8 [ 0.0% ] 0.000 ms udisks-daemon - 13020 : 27 [ 0.0% ] 0.240 ms kworker/7:0 - 14651 : 669 [ 0.0% ] 2.616 ms kworker/5:1 - 16220 : 2 [ 0.0% ] 0.069 ms kworker/4:0 - 19776 : 13 [ 0.0% ] 0.176 ms openvpn - 20131 : 133 [ 0.0% ] 0.762 ms plugin-containe - 20508 : 60658 [ 1.7% ] 131.153 ms npviewer.bin - 20520 : 72208 [ 2.0% ] 138.945 ms npviewer.bin - 20542 : 35 [ 0.0% ] 0.074 ms npviewer.bin - 20543 : 30 [ 0.0% ] 0.074 ms npviewer.bin - 20547 : 35 [ 0.0% ] 0.092 ms npviewer.bin - 20552 : 35 [ 0.0% ] 0.093 ms sshd - 20645 : 32 [ 0.0% ] 0.071 ms npviewer.bin - 21053 : 35 [ 0.0% ] 0.074 ms npviewer.bin - 21054 : 35 [ 0.0% ] 0.097 ms kworker/0:2 - 21169 : 149 [ 0.0% ] 1.143 ms kworker/3:0 - 22171 : 113 [ 0.0% ] 96.892 ms flush-253:4 - 22410 : 1 [ 0.0% ] 0.028 ms kworker/6:0 - 24581 : 25 [ 0.0% ] 0.275 ms kworker/1:0 - 25572 : 4 [ 0.0% ] 0.103 ms kworker/2:1 - 26299 : 138 [ 0.0% ] 1.440 ms kworker/0:0 - 26325 : 1 [ 0.0% ] 0.003 ms perf - 26330 : 3506967 [ 96.1% ] 6648.310 ms [root@sandy ~]# Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-mzuli0srnxyi1o029py6537x@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-17 20:13:12 +00:00
err = trace__run(&trace, argc, argv);
if (trace.sched && !err)
trace__fprintf_thread_summary(&trace, stdout);
return err;
perf trace: New tool Initially should look loosely like the venerable 'strace' tool, but using the infrastructure in the perf tools to allow tracing extra targets: [acme@sandy linux]$ perf trace --hell Error: unknown option `hell' usage: perf trace <PID> -p, --pid <pid> trace events on existing process id --tid <tid> trace events on existing thread id --all-cpus system-wide collection from all CPUs --cpu <cpu> list of cpus to monitor --no-inherit child tasks do not inherit counters --mmap-pages <n> number of mmap data pages --uid <user> user to profile [acme@sandy linux]$ Those should have the same semantics as when using with 'perf record'. It gets stuck sometimes, but hey, it works sometimes too! In time it should support perf.data based workloads, i.e. it should have a: -o filename Command line option that will produce a perf.data file that can then be used with 'perf trace' or any of the other perf tools (script, report, etc). It will also eventually have the set of functionalities described in the previous 'trace' prototype by Thomas Gleixner: "Announcing a new utility: 'trace'" http://lwn.net/Articles/415728/ Also planned is to have some of the features suggested in the comments of that LWN article. Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Mike Galbraith <efault@gmx.de> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Steven Rostedt <rostedt@goodmis.org> Cc: Thomas Gleixner <tglx@linutronix.de> Link: http://lkml.kernel.org/n/tip-v9x3q9rv4caxtox7wtjpchq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-09-26 23:05:56 +00:00
}