diff options
author | Linus Torvalds <torvalds@linux-foundation.org> | 2017-05-01 20:23:17 -0700 |
---|---|---|
committer | Linus Torvalds <torvalds@linux-foundation.org> | 2017-05-01 20:23:17 -0700 |
commit | 7c8c03bfc7b9f5211d8a69eab7fee99c9fb4f449 (patch) | |
tree | a5cee67325e50e893bf0cc0a0d060983a0df6653 /tools/perf/builtin-trace.c | |
parent | 6dc2cce9321198172cd96f955a5fc798a4cc35a6 (diff) | |
parent | fd7647979a3948dae4fc6f25dbbdf9ba269bed78 (diff) | |
download | linux-7c8c03bfc7b9f5211d8a69eab7fee99c9fb4f449.tar.bz2 |
Merge branch 'perf-core-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
Pull perf updates from Ingo Molnar:
"The main changes in this cycle were:
Kernel side changes:
- Kprobes and uprobes changes:
- Make their trampolines read-only while they are used
- Make UPROBES_EVENTS default-y which is the distro practice
- Apply misc fixes and robustization to probe point insertion.
- add support for AMD IOMMU events
- extend hw events on Intel Goldmont CPUs
- ... plus misc fixes and updates.
Tooling side changes:
- support s390 jump instructions in perf annotate (Christian
Borntraeger)
- vendor hardware events updates (Andi Kleen)
- add argument support for SDT events in powerpc (Ravi Bangoria)
- beautify the statx syscall arguments in 'perf trace' (Arnaldo
Carvalho de Melo)
- handle inline functions in callchains (Jin Yao)
- enable sorting by srcline as key (Milian Wolff)
- add 'brstackinsn' field in 'perf script' to reuse the x86
instruction decoder used in the Intel PT code to study hot paths to
samples (Andi Kleen)
- add PERF_RECORD_NAMESPACES so that the kernel can record
information required to associate samples to namespaces, helping in
container problem characterization. (Hari Bathini)
- allow sorting by symbol_size in 'perf report' and 'perf top'
(Charles Baylis)
- in perf stat, make system wide (-a) the default option if no target
was specified and one of following conditions is met:
- no workload specified (current behaviour)
- a workload is specified but all requested events are system wide
ones, like uncore ones. (Jiri Olsa)
- ... plus lots of other updates, enhancements, cleanups and fixes"
* 'perf-core-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip: (235 commits)
perf tools: Fix the code to strip command name
tools arch x86: Sync cpufeatures.h
tools arch: Sync arch/x86/lib/memcpy_64.S with the kernel
tools: Update asm-generic/mman-common.h copy from the kernel
perf tools: Use just forward declarations for struct thread where possible
perf tools: Add the right header to obtain PERF_ALIGN()
perf tools: Remove poll.h and wait.h from util.h
perf tools: Remove string.h, unistd.h and sys/stat.h from util.h
perf tools: Remove stale prototypes from builtin.h
perf tools: Remove string.h from util.h
perf tools: Remove sys/ioctl.h from util.h
perf tools: Remove a few more needless includes from util.h
perf tools: Include sys/param.h where needed
perf callchain: Move callchain specific routines from util.[ch]
perf tools: Add compress.h for the *_decompress_to_file() headers
perf mem: Fix display of data source snoop indication
perf debug: Move dump_stack() and sighandler_dump_stack() to debug.h
perf kvm: Make function only used by 'perf kvm' static
perf tools: Move timestamp routines from util.h to time-utils.h
perf tools: Move units conversion/formatting routines to separate object
...
Diffstat (limited to 'tools/perf/builtin-trace.c')
-rw-r--r-- | tools/perf/builtin-trace.c | 95 |
1 files changed, 66 insertions, 29 deletions
diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c index 256f1fac6f7e..eaa66fb57347 100644 --- a/tools/perf/builtin-trace.c +++ b/tools/perf/builtin-trace.c @@ -24,6 +24,7 @@ #include "util/evlist.h" #include <subcmd/exec-cmd.h> #include "util/machine.h" +#include "util/path.h" #include "util/session.h" #include "util/thread.h" #include <subcmd/parse-options.h> @@ -31,23 +32,33 @@ #include "util/intlist.h" #include "util/thread_map.h" #include "util/stat.h" +#include "trace/beauty/beauty.h" #include "trace-event.h" #include "util/parse-events.h" #include "util/bpf-loader.h" #include "callchain.h" +#include "print_binary.h" +#include "string2.h" #include "syscalltbl.h" #include "rb_resort.h" +#include <errno.h> +#include <inttypes.h> #include <libaudit.h> /* FIXME: Still needed for audit_errno_to_name */ +#include <poll.h> +#include <signal.h> #include <stdlib.h> #include <string.h> #include <linux/err.h> #include <linux/filter.h> #include <linux/audit.h> +#include <linux/kernel.h> #include <linux/random.h> #include <linux/stringify.h> #include <linux/time64.h> +#include "sane_ctype.h" + #ifndef O_CLOEXEC # define O_CLOEXEC 02000000 #endif @@ -267,15 +278,6 @@ out_delete: ({ struct syscall_tp *fields = evsel->priv; \ fields->name.pointer(&fields->name, sample); }) -struct syscall_arg { - unsigned long val; - struct thread *thread; - struct trace *trace; - void *parm; - u8 idx; - u8 mask; -}; - struct strarray { int offset; int nr_entries; @@ -771,6 +773,10 @@ static struct syscall_fmt { .arg_parm = { [0] = &strarray__socket_families, /* family */ }, }, { .name = "stat", .errmsg = true, .alias = "newstat", }, { .name = "statfs", .errmsg = true, }, + { .name = "statx", .errmsg = true, + .arg_scnprintf = { [0] = SCA_FDAT, /* flags */ + [2] = SCA_STATX_FLAGS, /* flags */ + [3] = SCA_STATX_MASK, /* mask */ }, }, { .name = "swapoff", .errmsg = true, .arg_scnprintf = { [0] = SCA_FILENAME, /* specialfile */ }, }, { .name = "swapon", .errmsg = true, @@ -821,12 +827,21 @@ struct syscall { void **arg_parm; }; -static size_t fprintf_duration(unsigned long t, FILE *fp) +/* + * We need to have this 'calculated' boolean because in some cases we really + * don't know what is the duration of a syscall, for instance, when we start + * a session and some threads are waiting for a syscall to finish, say 'poll', + * in which case all we can do is to print "( ? ) for duration and for the + * start timestamp. + */ +static size_t fprintf_duration(unsigned long t, bool calculated, FILE *fp) { double duration = (double)t / NSEC_PER_MSEC; size_t printed = fprintf(fp, "("); - if (duration >= 1.0) + if (!calculated) + printed += fprintf(fp, " ? "); + else 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); @@ -1028,13 +1043,27 @@ static bool trace__filter_duration(struct trace *trace, double t) return t < (trace->duration_filter * NSEC_PER_MSEC); } -static size_t trace__fprintf_tstamp(struct trace *trace, u64 tstamp, FILE *fp) +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); } +/* + * We're handling tstamp=0 as an undefined tstamp, i.e. like when we are + * using ttrace->entry_time for a thread that receives a sys_exit without + * first having received a sys_enter ("poll" issued before tracing session + * starts, lost sys_enter exit due to ring buffer overflow). + */ +static size_t trace__fprintf_tstamp(struct trace *trace, u64 tstamp, FILE *fp) +{ + if (tstamp > 0) + return __trace__fprintf_tstamp(trace, tstamp, fp); + + return fprintf(fp, " ? "); +} + static bool done = false; static bool interrupted = false; @@ -1045,10 +1074,10 @@ static void sig_handler(int sig) } static size_t trace__fprintf_entry_head(struct trace *trace, struct thread *thread, - u64 duration, u64 tstamp, FILE *fp) + u64 duration, bool duration_calculated, u64 tstamp, FILE *fp) { size_t printed = trace__fprintf_tstamp(trace, tstamp, fp); - printed += fprintf_duration(duration, fp); + printed += fprintf_duration(duration, duration_calculated, fp); if (trace->multiple_threads) { if (trace->show_comm) @@ -1450,7 +1479,7 @@ static int trace__printf_interrupted_entry(struct trace *trace, struct perf_samp duration = sample->time - ttrace->entry_time; - printed = trace__fprintf_entry_head(trace, trace->current, duration, ttrace->entry_time, trace->output); + printed = trace__fprintf_entry_head(trace, trace->current, duration, true, ttrace->entry_time, trace->output); printed += fprintf(trace->output, "%-70s) ...\n", ttrace->entry_str); ttrace->entry_pending = false; @@ -1497,7 +1526,7 @@ static int trace__sys_enter(struct trace *trace, struct perf_evsel *evsel, if (sc->is_exit) { if (!(trace->duration_filter || trace->summary_only || trace->min_stack)) { - trace__fprintf_entry_head(trace, thread, 1, ttrace->entry_time, trace->output); + trace__fprintf_entry_head(trace, thread, 0, false, ttrace->entry_time, trace->output); fprintf(trace->output, "%-70s)\n", ttrace->entry_str); } } else { @@ -1545,6 +1574,7 @@ static int trace__sys_exit(struct trace *trace, struct perf_evsel *evsel, { long ret; u64 duration = 0; + bool duration_calculated = false; struct thread *thread; int id = perf_evsel__sc_tp_uint(evsel, id, sample), err = -1, callchain_ret = 0; struct syscall *sc = trace__syscall_info(trace, evsel, id); @@ -1573,6 +1603,7 @@ static int trace__sys_exit(struct trace *trace, struct perf_evsel *evsel, duration = sample->time - ttrace->entry_time; if (trace__filter_duration(trace, duration)) goto out; + duration_calculated = true; } else if (trace->duration_filter) goto out; @@ -1588,7 +1619,7 @@ static int trace__sys_exit(struct trace *trace, struct perf_evsel *evsel, if (trace->summary_only) goto out; - trace__fprintf_entry_head(trace, thread, duration, ttrace->entry_time, trace->output); + trace__fprintf_entry_head(trace, thread, duration, duration_calculated, ttrace->entry_time, trace->output); if (ttrace->entry_pending) { fprintf(trace->output, "%-70s", ttrace->entry_str); @@ -1653,15 +1684,17 @@ static int trace__vfs_getname(struct trace *trace, struct perf_evsel *evsel, ttrace = thread__priv(thread); if (!ttrace) - goto out; + goto out_put; filename_len = strlen(filename); + if (filename_len == 0) + goto out_put; if (ttrace->filename.namelen < filename_len) { char *f = realloc(ttrace->filename.name, filename_len + 1); if (f == NULL) - goto out; + goto out_put; ttrace->filename.namelen = filename_len; ttrace->filename.name = f; @@ -1671,12 +1704,12 @@ static int trace__vfs_getname(struct trace *trace, struct perf_evsel *evsel, ttrace->filename.pending_open = true; if (!ttrace->filename.ptr) - goto out; + goto out_put; entry_str_len = strlen(ttrace->entry_str); remaining_space = trace__entry_str_size - entry_str_len - 1; /* \0 */ if (remaining_space <= 0) - goto out; + goto out_put; if (filename_len > (size_t)remaining_space) { filename += filename_len - remaining_space; @@ -1690,6 +1723,8 @@ static int trace__vfs_getname(struct trace *trace, struct perf_evsel *evsel, ttrace->filename.ptr = 0; ttrace->filename.entry_str_pos = 0; +out_put: + thread__put(thread); out: return 0; } @@ -1710,6 +1745,7 @@ static int trace__sched_stat_runtime(struct trace *trace, struct perf_evsel *evs ttrace->runtime_ms += runtime_ms; trace->runtime_ms += runtime_ms; +out_put: thread__put(thread); return 0; @@ -1720,8 +1756,7 @@ out_dump: (pid_t)perf_evsel__intval(evsel, sample, "pid"), runtime, perf_evsel__intval(evsel, sample, "vruntime")); - thread__put(thread); - return 0; + goto out_put; } static void bpf_output__printer(enum binary_printer_ops op, @@ -1851,7 +1886,7 @@ static int trace__pgfault(struct trace *trace, thread__find_addr_location(thread, sample->cpumode, MAP__FUNCTION, sample->ip, &al); - trace__fprintf_entry_head(trace, thread, 0, sample->time, trace->output); + trace__fprintf_entry_head(trace, thread, 0, true, sample->time, trace->output); fprintf(trace->output, "%sfault [", evsel->attr.config == PERF_COUNT_SW_PAGE_FAULTS_MAJ ? @@ -1920,7 +1955,7 @@ static int trace__process_sample(struct perf_tool *tool, thread = machine__findnew_thread(trace->host, sample->pid, sample->tid); if (thread && thread__is_filtered(thread)) - return 0; + goto out; trace__set_base_time(trace, evsel, sample); @@ -1928,7 +1963,8 @@ static int trace__process_sample(struct perf_tool *tool, ++trace->nr_events; handler(trace, evsel, event, sample); } - +out: + thread__put(thread); return err; } @@ -1988,7 +2024,7 @@ static int trace__record(struct trace *trace, int argc, const char **argv) for (i = 0; i < (unsigned int)argc; i++) rec_argv[j++] = argv[i]; - return cmd_record(j, rec_argv, NULL); + return cmd_record(j, rec_argv); } static size_t trace__fprintf_thread_summary(struct trace *trace, FILE *fp); @@ -2415,8 +2451,9 @@ static int trace__replay(struct trace *trace) trace->tool.exit = perf_event__process_exit; trace->tool.fork = perf_event__process_fork; trace->tool.attr = perf_event__process_attr; - trace->tool.tracing_data = perf_event__process_tracing_data; + trace->tool.tracing_data = perf_event__process_tracing_data; trace->tool.build_id = perf_event__process_build_id; + trace->tool.namespaces = perf_event__process_namespaces; trace->tool.ordered_events = true; trace->tool.ordering_requires_timestamps = true; @@ -2785,7 +2822,7 @@ out: return err; } -int cmd_trace(int argc, const char **argv, const char *prefix __maybe_unused) +int cmd_trace(int argc, const char **argv) { const char *trace_usage[] = { "perf trace [<options>] [<command>]", |