* [PATCH 01/10] perf trace: Do not process PERF_RECORD_LOST twice
2016-04-01 21:56 [GIT PULL 00/10] perf/core improvements and fixes Arnaldo Carvalho de Melo
@ 2016-04-01 21:56 ` Arnaldo Carvalho de Melo
2016-04-01 21:56 ` [PATCH 02/10] perf trace: Pretty print seccomp() args Arnaldo Carvalho de Melo
` (9 subsequent siblings)
10 siblings, 0 replies; 12+ messages in thread
From: Arnaldo Carvalho de Melo @ 2016-04-01 21:56 UTC (permalink / raw)
To: Ingo Molnar
Cc: linux-kernel, Arnaldo Carvalho de Melo, Adrian Hunter,
David Ahern, Jiri Olsa, Namhyung Kim, Wang Nan
From: Arnaldo Carvalho de Melo <acme@redhat.com>
We catch this record to provide a visual indication that events are
getting lost, then call the default method to allow extra logging shared
with the other tools to take place.
This extra logging was done twice because we were continuing to the
"default" clause where machine__process_event() will end up calling
machine__process_lost_event() again, fix it.
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-wus2zlhw3qo24ye84ewu4aqw@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
tools/perf/builtin-trace.c | 1 +
1 file changed, 1 insertion(+)
diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c
index 93ac724fb635..6485576f3337 100644
--- a/tools/perf/builtin-trace.c
+++ b/tools/perf/builtin-trace.c
@@ -1618,6 +1618,7 @@ static int trace__process_event(struct trace *trace, struct machine *machine,
color_fprintf(trace->output, PERF_COLOR_RED,
"LOST %" PRIu64 " events!\n", event->lost.lost);
ret = machine__process_lost_event(machine, event, sample);
+ break;
default:
ret = machine__process_event(machine, event, sample);
break;
--
2.5.5
^ permalink raw reply related [flat|nested] 12+ messages in thread
* [PATCH 02/10] perf trace: Pretty print seccomp() args
2016-04-01 21:56 [GIT PULL 00/10] perf/core improvements and fixes Arnaldo Carvalho de Melo
2016-04-01 21:56 ` [PATCH 01/10] perf trace: Do not process PERF_RECORD_LOST twice Arnaldo Carvalho de Melo
@ 2016-04-01 21:56 ` Arnaldo Carvalho de Melo
2016-04-01 21:56 ` [PATCH 03/10] perf trace: Pretty print getrandom() args Arnaldo Carvalho de Melo
` (8 subsequent siblings)
10 siblings, 0 replies; 12+ messages in thread
From: Arnaldo Carvalho de Melo @ 2016-04-01 21:56 UTC (permalink / raw)
To: Ingo Molnar
Cc: linux-kernel, Arnaldo Carvalho de Melo, Adrian Hunter,
David Ahern, Jiri Olsa, Milian Wolff, Namhyung Kim, Wang Nan
From: Arnaldo Carvalho de Melo <acme@redhat.com>
E.g:
# trace -e seccomp
200.061 (0.009 ms): :2441/2441 seccomp(op: FILTER, flags: TSYNC ) = -1 EFAULT Bad address
200.910 (0.121 ms): :2441/2441 seccomp(op: FILTER, flags: TSYNC, uargs: 0x7fff57479fe0) = 0
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-t369uckshlwp4evkks4bcoo7@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
tools/perf/builtin-trace.c | 47 ++++++++++++++++++++++++++++++++++++++++++++++
1 file changed, 47 insertions(+)
diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c
index 6485576f3337..0c8bcb94934e 100644
--- a/tools/perf/builtin-trace.c
+++ b/tools/perf/builtin-trace.c
@@ -40,6 +40,10 @@
#include <sys/mman.h>
#include <linux/futex.h>
#include <linux/err.h>
+#include <linux/seccomp.h>
+#include <linux/filter.h>
+#include <linux/audit.h>
+#include <sys/ptrace.h>
/* For older distros: */
#ifndef MAP_STACK
@@ -1001,6 +1005,46 @@ static const char *tioctls[] = {
static DEFINE_STRARRAY_OFFSET(tioctls, 0x5401);
#endif /* defined(__i386__) || defined(__x86_64__) */
+static size_t syscall_arg__scnprintf_seccomp_op(char *bf, size_t size, struct syscall_arg *arg)
+{
+ int op = arg->val;
+ size_t printed = 0;
+
+ switch (op) {
+#define P_SECCOMP_SET_MODE_OP(n) case SECCOMP_SET_MODE_##n: printed = scnprintf(bf, size, #n); break
+ P_SECCOMP_SET_MODE_OP(STRICT);
+ P_SECCOMP_SET_MODE_OP(FILTER);
+#undef P_SECCOMP_SET_MODE_OP
+ default: printed = scnprintf(bf, size, "%#x", op); break;
+ }
+
+ return printed;
+}
+
+#define SCA_SECCOMP_OP syscall_arg__scnprintf_seccomp_op
+
+static size_t syscall_arg__scnprintf_seccomp_flags(char *bf, size_t size,
+ struct syscall_arg *arg)
+{
+ int printed = 0, flags = arg->val;
+
+#define P_FLAG(n) \
+ if (flags & SECCOMP_FILTER_FLAG_##n) { \
+ printed += scnprintf(bf + printed, size - printed, "%s%s", printed ? "|" : "", #n); \
+ flags &= ~SECCOMP_FILTER_FLAG_##n; \
+ }
+
+ P_FLAG(TSYNC);
+#undef P_FLAG
+
+ if (flags)
+ printed += scnprintf(bf + printed, size - printed, "%s%#x", printed ? "|" : "", flags);
+
+ return printed;
+}
+
+#define SCA_SECCOMP_FLAGS syscall_arg__scnprintf_seccomp_flags
+
#define STRARRAY(arg, name, array) \
.arg_scnprintf = { [arg] = SCA_STRARRAY, }, \
.arg_parm = { [arg] = &strarray__##array, }
@@ -1234,6 +1278,9 @@ static struct syscall_fmt {
.arg_scnprintf = { [1] = SCA_SIGNUM, /* sig */ }, },
{ .name = "rt_tgsigqueueinfo", .errmsg = true,
.arg_scnprintf = { [2] = SCA_SIGNUM, /* sig */ }, },
+ { .name = "seccomp", .errmsg = true,
+ .arg_scnprintf = { [0] = SCA_SECCOMP_OP, /* op */
+ [1] = SCA_SECCOMP_FLAGS, /* flags */ }, },
{ .name = "select", .errmsg = true, .timeout = true, },
{ .name = "sendmmsg", .errmsg = true,
.arg_scnprintf = { [0] = SCA_FD, /* fd */
--
2.5.5
^ permalink raw reply related [flat|nested] 12+ messages in thread
* [PATCH 03/10] perf trace: Pretty print getrandom() args
2016-04-01 21:56 [GIT PULL 00/10] perf/core improvements and fixes Arnaldo Carvalho de Melo
2016-04-01 21:56 ` [PATCH 01/10] perf trace: Do not process PERF_RECORD_LOST twice Arnaldo Carvalho de Melo
2016-04-01 21:56 ` [PATCH 02/10] perf trace: Pretty print seccomp() args Arnaldo Carvalho de Melo
@ 2016-04-01 21:56 ` Arnaldo Carvalho de Melo
2016-04-01 21:57 ` [PATCH 04/10] perf tools: Add time conversion event Arnaldo Carvalho de Melo
` (7 subsequent siblings)
10 siblings, 0 replies; 12+ messages in thread
From: Arnaldo Carvalho de Melo @ 2016-04-01 21:56 UTC (permalink / raw)
To: Ingo Molnar
Cc: linux-kernel, Arnaldo Carvalho de Melo, Adrian Hunter,
David Ahern, Jiri Olsa, Milian Wolff, Namhyung Kim, Wang Nan
From: Arnaldo Carvalho de Melo <acme@redhat.com>
# trace -e getrandom
35622.560 ( 0.023 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16
35622.585 ( 0.006 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16
35622.594 ( 0.004 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16
35627.395 ( 0.010 ms): libvirtd/1353 getrandom(buf: 0x7f7a1bfa35c0, count: 16, flags: NONBLOCK ) = 16
35630.940 ( 0.013 ms): fwupd/16120 getrandom(buf: 0x7f63243aa5c0, count: 16, flags: NONBLOCK ) = 16
35718.613 ( 0.015 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16
35718.629 ( 0.005 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16
35718.637 ( 0.004 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16
35719.355 ( 0.010 ms): libvirtd/1353 getrandom(buf: 0x7f7a1bfa35c0, count: 16, flags: NONBLOCK ) = 16
35721.042 ( 0.030 ms): fwupd/16120 getrandom(buf: 0x7f63243aa5c0, count: 16, flags: NONBLOCK ) = 16
41090.830 ( 0.012 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16
41090.845 ( 0.004 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16
41090.851 ( 0.004 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16
41091.750 ( 0.010 ms): libvirtd/1353 getrandom(buf: 0x7f7a1bfa35c0, count: 16, flags: NONBLOCK ) = 16
41091.823 ( 0.006 ms): fwupd/16120 getrandom(buf: 0x7f63243aa5c0, count: 16, flags: NONBLOCK ) = 16
41122.078 ( 0.053 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16
41122.129 ( 0.009 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16
41122.139 ( 0.004 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16
41124.492 ( 0.007 ms): libvirtd/1353 getrandom(buf: 0x7f7a1bfa35c0, count: 16, flags: NONBLOCK ) = 16
41124.470 ( 0.013 ms): fwupd/16120 getrandom(buf: 0x7f63243aa5c0, count: 16, flags: NONBLOCK ) = 16
41590.832 ( 0.014 ms): chrome/5957 getrandom(buf: 0x7fabac7b15b0, count: 16, flags: NONBLOCK ) = 16
41590.884 ( 0.004 ms): chrome/5957 getrandom(buf: 0x7fabac7b15c0, count: 16, flags: NONBLOCK ) = 16
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-gca0n1p3aca3depey703ph2q@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
tools/perf/builtin-trace.c | 26 ++++++++++++++++++++++++++
1 file changed, 26 insertions(+)
diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c
index 0c8bcb94934e..c45c1cfeb866 100644
--- a/tools/perf/builtin-trace.c
+++ b/tools/perf/builtin-trace.c
@@ -44,6 +44,7 @@
#include <linux/filter.h>
#include <linux/audit.h>
#include <sys/ptrace.h>
+#include <linux/random.h>
/* For older distros: */
#ifndef MAP_STACK
@@ -1045,6 +1046,29 @@ static size_t syscall_arg__scnprintf_seccomp_flags(char *bf, size_t size,
#define SCA_SECCOMP_FLAGS syscall_arg__scnprintf_seccomp_flags
+static size_t syscall_arg__scnprintf_getrandom_flags(char *bf, size_t size,
+ struct syscall_arg *arg)
+{
+ int printed = 0, flags = arg->val;
+
+#define P_FLAG(n) \
+ if (flags & GRND_##n) { \
+ printed += scnprintf(bf + printed, size - printed, "%s%s", printed ? "|" : "", #n); \
+ flags &= ~GRND_##n; \
+ }
+
+ P_FLAG(RANDOM);
+ P_FLAG(NONBLOCK);
+#undef P_FLAG
+
+ if (flags)
+ printed += scnprintf(bf + printed, size - printed, "%s%#x", printed ? "|" : "", flags);
+
+ return printed;
+}
+
+#define SCA_GETRANDOM_FLAGS syscall_arg__scnprintf_getrandom_flags
+
#define STRARRAY(arg, name, array) \
.arg_scnprintf = { [arg] = SCA_STRARRAY, }, \
.arg_parm = { [arg] = &strarray__##array, }
@@ -1137,6 +1161,8 @@ static struct syscall_fmt {
{ .name = "getdents64", .errmsg = true,
.arg_scnprintf = { [0] = SCA_FD, /* fd */ }, },
{ .name = "getitimer", .errmsg = true, STRARRAY(0, which, itimers), },
+ { .name = "getrandom", .errmsg = true,
+ .arg_scnprintf = { [2] = SCA_GETRANDOM_FLAGS, /* flags */ }, },
{ .name = "getrlimit", .errmsg = true, STRARRAY(0, resource, rlimit_resources), },
{ .name = "getxattr", .errmsg = true,
.arg_scnprintf = { [0] = SCA_FILENAME, /* pathname */ }, },
--
2.5.5
^ permalink raw reply related [flat|nested] 12+ messages in thread
* [PATCH 04/10] perf tools: Add time conversion event
2016-04-01 21:56 [GIT PULL 00/10] perf/core improvements and fixes Arnaldo Carvalho de Melo
` (2 preceding siblings ...)
2016-04-01 21:56 ` [PATCH 03/10] perf trace: Pretty print getrandom() args Arnaldo Carvalho de Melo
@ 2016-04-01 21:57 ` Arnaldo Carvalho de Melo
2016-04-01 21:57 ` [PATCH 05/10] perf jit: Add support for using TSC as a timestamp Arnaldo Carvalho de Melo
` (6 subsequent siblings)
10 siblings, 0 replies; 12+ messages in thread
From: Arnaldo Carvalho de Melo @ 2016-04-01 21:57 UTC (permalink / raw)
To: Ingo Molnar
Cc: linux-kernel, Adrian Hunter, Jiri Olsa, Stephane Eranian,
Arnaldo Carvalho de Melo
From: Adrian Hunter <adrian.hunter@intel.com>
Intel PT uses the time members from the perf_event_mmap_page to convert
between TSC and perf time.
Due to a lack of foresight when Intel PT was implemented, those time
members were recorded in the (implementation dependent) AUXTRACE_INFO
event, the structure of which is generally inaccessible outside of the
Intel PT decoder. However now the conversion between TSC and perf time
is needed when processing a jitdump file when Intel PT has been used for
tracing.
So add a user event to record the time members. 'perf record' will
synthesize the event if the information is available. And session
processing will put a copy of the event on the session so that tools
like 'perf inject' can easily access it.
Signed-off-by: Adrian Hunter <adrian.hunter@intel.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/r/1457426324-30158-1-git-send-email-adrian.hunter@intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
tools/perf/arch/x86/util/tsc.c | 31 +++++++++++++++++++++++++++++++
tools/perf/builtin-inject.c | 1 +
tools/perf/builtin-record.c | 15 +++++++++++++++
tools/perf/util/event.c | 1 +
tools/perf/util/event.h | 9 +++++++++
tools/perf/util/session.c | 6 ++++++
tools/perf/util/session.h | 1 +
tools/perf/util/tool.h | 1 +
tools/perf/util/tsc.h | 10 ++++++++++
9 files changed, 75 insertions(+)
diff --git a/tools/perf/arch/x86/util/tsc.c b/tools/perf/arch/x86/util/tsc.c
index fd2868490d00..70ff7c14bea6 100644
--- a/tools/perf/arch/x86/util/tsc.c
+++ b/tools/perf/arch/x86/util/tsc.c
@@ -46,3 +46,34 @@ u64 rdtsc(void)
return low | ((u64)high) << 32;
}
+
+int perf_event__synth_time_conv(const struct perf_event_mmap_page *pc,
+ struct perf_tool *tool,
+ perf_event__handler_t process,
+ struct machine *machine)
+{
+ union perf_event event = {
+ .time_conv = {
+ .header = {
+ .type = PERF_RECORD_TIME_CONV,
+ .size = sizeof(struct time_conv_event),
+ },
+ },
+ };
+ struct perf_tsc_conversion tc;
+ int err;
+
+ err = perf_read_tsc_conversion(pc, &tc);
+ if (err == -EOPNOTSUPP)
+ return 0;
+ if (err)
+ return err;
+
+ pr_debug2("Synthesizing TSC conversion information\n");
+
+ event.time_conv.time_mult = tc.time_mult;
+ event.time_conv.time_shift = tc.time_shift;
+ event.time_conv.time_zero = tc.time_zero;
+
+ return process(tool, &event, NULL, machine);
+}
diff --git a/tools/perf/builtin-inject.c b/tools/perf/builtin-inject.c
index d1a2d104f2bc..e5afa8fe1bf1 100644
--- a/tools/perf/builtin-inject.c
+++ b/tools/perf/builtin-inject.c
@@ -748,6 +748,7 @@ int cmd_inject(int argc, const char **argv, const char *prefix __maybe_unused)
.auxtrace_info = perf_event__repipe_op2_synth,
.auxtrace = perf_event__repipe_auxtrace,
.auxtrace_error = perf_event__repipe_op2_synth,
+ .time_conv = perf_event__repipe_op2_synth,
.finished_round = perf_event__repipe_oe_synth,
.build_id = perf_event__repipe_op2_synth,
.id_index = perf_event__repipe_op2_synth,
diff --git a/tools/perf/builtin-record.c b/tools/perf/builtin-record.c
index 515510ecc76a..410035c6e300 100644
--- a/tools/perf/builtin-record.c
+++ b/tools/perf/builtin-record.c
@@ -29,6 +29,7 @@
#include "util/data.h"
#include "util/perf_regs.h"
#include "util/auxtrace.h"
+#include "util/tsc.h"
#include "util/parse-branch-options.h"
#include "util/parse-regs-options.h"
#include "util/llvm-utils.h"
@@ -512,6 +513,15 @@ static void workload_exec_failed_signal(int signo __maybe_unused,
static void snapshot_sig_handler(int sig);
+int __weak
+perf_event__synth_time_conv(const struct perf_event_mmap_page *pc __maybe_unused,
+ struct perf_tool *tool __maybe_unused,
+ perf_event__handler_t process __maybe_unused,
+ struct machine *machine __maybe_unused)
+{
+ return 0;
+}
+
static int record__synthesize(struct record *rec)
{
struct perf_session *session = rec->session;
@@ -549,6 +559,11 @@ static int record__synthesize(struct record *rec)
}
}
+ err = perf_event__synth_time_conv(rec->evlist->mmap[0].base, tool,
+ process_synthesized_event, machine);
+ if (err)
+ goto out;
+
if (rec->opts.full_auxtrace) {
err = perf_event__synthesize_auxtrace_info(rec->itr, tool,
session, process_synthesized_event);
diff --git a/tools/perf/util/event.c b/tools/perf/util/event.c
index dad55d04ffdd..b68959037688 100644
--- a/tools/perf/util/event.c
+++ b/tools/perf/util/event.c
@@ -45,6 +45,7 @@ static const char *perf_event__names[] = {
[PERF_RECORD_STAT] = "STAT",
[PERF_RECORD_STAT_ROUND] = "STAT_ROUND",
[PERF_RECORD_EVENT_UPDATE] = "EVENT_UPDATE",
+ [PERF_RECORD_TIME_CONV] = "TIME_CONV",
};
const char *perf_event__name(unsigned int id)
diff --git a/tools/perf/util/event.h b/tools/perf/util/event.h
index 6bb1c928350d..8d363d5e65a2 100644
--- a/tools/perf/util/event.h
+++ b/tools/perf/util/event.h
@@ -233,6 +233,7 @@ enum perf_user_event_type { /* above any possible kernel type */
PERF_RECORD_STAT = 76,
PERF_RECORD_STAT_ROUND = 77,
PERF_RECORD_EVENT_UPDATE = 78,
+ PERF_RECORD_TIME_CONV = 79,
PERF_RECORD_HEADER_MAX
};
@@ -469,6 +470,13 @@ struct stat_round_event {
u64 time;
};
+struct time_conv_event {
+ struct perf_event_header header;
+ u64 time_shift;
+ u64 time_mult;
+ u64 time_zero;
+};
+
union perf_event {
struct perf_event_header header;
struct mmap_event mmap;
@@ -497,6 +505,7 @@ union perf_event {
struct stat_config_event stat_config;
struct stat_event stat;
struct stat_round_event stat_round;
+ struct time_conv_event time_conv;
};
void perf_event__print_totals(void);
diff --git a/tools/perf/util/session.c b/tools/perf/util/session.c
index 4abd85c6346d..ef370557fb9a 100644
--- a/tools/perf/util/session.c
+++ b/tools/perf/util/session.c
@@ -409,6 +409,8 @@ void perf_tool__fill_defaults(struct perf_tool *tool)
tool->stat = process_stat_stub;
if (tool->stat_round == NULL)
tool->stat_round = process_stat_round_stub;
+ if (tool->time_conv == NULL)
+ tool->time_conv = process_event_op2_stub;
}
static void swap_sample_id_all(union perf_event *event, void *data)
@@ -794,6 +796,7 @@ static perf_event__swap_op perf_event__swap_ops[] = {
[PERF_RECORD_STAT] = perf_event__stat_swap,
[PERF_RECORD_STAT_ROUND] = perf_event__stat_round_swap,
[PERF_RECORD_EVENT_UPDATE] = perf_event__event_update_swap,
+ [PERF_RECORD_TIME_CONV] = perf_event__all64_swap,
[PERF_RECORD_HEADER_MAX] = NULL,
};
@@ -1341,6 +1344,9 @@ static s64 perf_session__process_user_event(struct perf_session *session,
return tool->stat(tool, event, session);
case PERF_RECORD_STAT_ROUND:
return tool->stat_round(tool, event, session);
+ case PERF_RECORD_TIME_CONV:
+ session->time_conv = event->time_conv;
+ return tool->time_conv(tool, event, session);
default:
return -EINVAL;
}
diff --git a/tools/perf/util/session.h b/tools/perf/util/session.h
index 5f792e35d4c1..f96fc9e8c52e 100644
--- a/tools/perf/util/session.h
+++ b/tools/perf/util/session.h
@@ -26,6 +26,7 @@ struct perf_session {
struct itrace_synth_opts *itrace_synth_opts;
struct list_head auxtrace_index;
struct trace_event tevent;
+ struct time_conv_event time_conv;
bool repipe;
bool one_mmap;
void *one_mmap_addr;
diff --git a/tools/perf/util/tool.h b/tools/perf/util/tool.h
index 55de4cffcd4e..ac2590a3de2d 100644
--- a/tools/perf/util/tool.h
+++ b/tools/perf/util/tool.h
@@ -57,6 +57,7 @@ struct perf_tool {
id_index,
auxtrace_info,
auxtrace_error,
+ time_conv,
thread_map,
cpu_map,
stat_config,
diff --git a/tools/perf/util/tsc.h b/tools/perf/util/tsc.h
index a8b78f1b3243..280ddc067556 100644
--- a/tools/perf/util/tsc.h
+++ b/tools/perf/util/tsc.h
@@ -3,10 +3,20 @@
#include <linux/types.h>
+#include "event.h"
#include "../arch/x86/util/tsc.h"
u64 perf_time_to_tsc(u64 ns, struct perf_tsc_conversion *tc);
u64 tsc_to_perf_time(u64 cyc, struct perf_tsc_conversion *tc);
u64 rdtsc(void);
+struct perf_event_mmap_page;
+struct perf_tool;
+struct machine;
+
+int perf_event__synth_time_conv(const struct perf_event_mmap_page *pc,
+ struct perf_tool *tool,
+ perf_event__handler_t process,
+ struct machine *machine);
+
#endif
--
2.5.5
^ permalink raw reply related [flat|nested] 12+ messages in thread
* [PATCH 05/10] perf jit: Add support for using TSC as a timestamp
2016-04-01 21:56 [GIT PULL 00/10] perf/core improvements and fixes Arnaldo Carvalho de Melo
` (3 preceding siblings ...)
2016-04-01 21:57 ` [PATCH 04/10] perf tools: Add time conversion event Arnaldo Carvalho de Melo
@ 2016-04-01 21:57 ` Arnaldo Carvalho de Melo
2016-04-01 21:57 ` [PATCH 06/10] perf intel-pt/bts: Define JITDUMP_USE_ARCH_TIMESTAMP Arnaldo Carvalho de Melo
` (5 subsequent siblings)
10 siblings, 0 replies; 12+ messages in thread
From: Arnaldo Carvalho de Melo @ 2016-04-01 21:57 UTC (permalink / raw)
To: Ingo Molnar
Cc: linux-kernel, Adrian Hunter, Alexander Shishkin, He Kuang,
Jiri Olsa, Josh Poimboeuf, Peter Zijlstra, Stephane Eranian,
Sukadev Bhattiprolu, Wang Nan, Arnaldo Carvalho de Melo
From: Adrian Hunter <adrian.hunter@intel.com>
Intel PT uses TSC as a timestamp, so add support for using TSC instead
of the monotonic clock. Use of TSC is selected by an environment
variable "JITDUMP_USE_ARCH_TIMESTAMP" and flagged in the jitdump file
with flag JITDUMP_FLAGS_ARCH_TIMESTAMP.
Signed-off-by: Adrian Hunter <adrian.hunter@intel.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: He Kuang <hekuang@huawei.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Josh Poimboeuf <jpoimboe@redhat.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Cc: Sukadev Bhattiprolu <sukadev@linux.vnet.ibm.com>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/r/1457426330-30226-1-git-send-email-adrian.hunter@intel.com
[ Added the fixup from He Kuang to make it build on other arches, ]
[ such as aarch64, to avoid inserting this bisectiong breakage upstream ]
Link: http://lkml.kernel.org/r/1459482572-129494-1-git-send-email-hekuang@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
tools/perf/arch/x86/util/tsc.c | 1 -
tools/perf/arch/x86/util/tsc.h | 17 -----------------
tools/perf/jvmti/jvmti_agent.c | 43 ++++++++++++++++++++++++++++++++++++++++--
tools/perf/util/Build | 3 +--
tools/perf/util/jitdump.c | 37 +++++++++++++++++++++++++++++++-----
tools/perf/util/jitdump.h | 3 +++
tools/perf/util/tsc.h | 11 ++++++++++-
7 files changed, 87 insertions(+), 28 deletions(-)
delete mode 100644 tools/perf/arch/x86/util/tsc.h
diff --git a/tools/perf/arch/x86/util/tsc.c b/tools/perf/arch/x86/util/tsc.c
index 70ff7c14bea6..357f1b13b5ae 100644
--- a/tools/perf/arch/x86/util/tsc.c
+++ b/tools/perf/arch/x86/util/tsc.c
@@ -7,7 +7,6 @@
#include <linux/types.h>
#include "../../util/debug.h"
#include "../../util/tsc.h"
-#include "tsc.h"
int perf_read_tsc_conversion(const struct perf_event_mmap_page *pc,
struct perf_tsc_conversion *tc)
diff --git a/tools/perf/arch/x86/util/tsc.h b/tools/perf/arch/x86/util/tsc.h
deleted file mode 100644
index 2edc4d31065c..000000000000
--- a/tools/perf/arch/x86/util/tsc.h
+++ /dev/null
@@ -1,17 +0,0 @@
-#ifndef TOOLS_PERF_ARCH_X86_UTIL_TSC_H__
-#define TOOLS_PERF_ARCH_X86_UTIL_TSC_H__
-
-#include <linux/types.h>
-
-struct perf_tsc_conversion {
- u16 time_shift;
- u32 time_mult;
- u64 time_zero;
-};
-
-struct perf_event_mmap_page;
-
-int perf_read_tsc_conversion(const struct perf_event_mmap_page *pc,
- struct perf_tsc_conversion *tc);
-
-#endif /* TOOLS_PERF_ARCH_X86_UTIL_TSC_H__ */
diff --git a/tools/perf/jvmti/jvmti_agent.c b/tools/perf/jvmti/jvmti_agent.c
index 6461e02ab940..3573f315f955 100644
--- a/tools/perf/jvmti/jvmti_agent.c
+++ b/tools/perf/jvmti/jvmti_agent.c
@@ -92,6 +92,22 @@ error:
return ret;
}
+static int use_arch_timestamp;
+
+static inline uint64_t
+get_arch_timestamp(void)
+{
+#if defined(__i386__) || defined(__x86_64__)
+ unsigned int low, high;
+
+ asm volatile("rdtsc" : "=a" (low), "=d" (high));
+
+ return low | ((uint64_t)high) << 32;
+#else
+ return 0;
+#endif
+}
+
#define NSEC_PER_SEC 1000000000
static int perf_clk_id = CLOCK_MONOTONIC;
@@ -107,6 +123,9 @@ perf_get_timestamp(void)
struct timespec ts;
int ret;
+ if (use_arch_timestamp)
+ return get_arch_timestamp();
+
ret = clock_gettime(perf_clk_id, &ts);
if (ret)
return 0;
@@ -203,6 +222,17 @@ perf_close_marker_file(void)
munmap(marker_addr, pgsz);
}
+static void
+init_arch_timestamp(void)
+{
+ char *str = getenv("JITDUMP_USE_ARCH_TIMESTAMP");
+
+ if (!str || !*str || !strcmp(str, "0"))
+ return;
+
+ use_arch_timestamp = 1;
+}
+
void *jvmti_open(void)
{
int pad_cnt;
@@ -211,11 +241,17 @@ void *jvmti_open(void)
int fd;
FILE *fp;
+ init_arch_timestamp();
+
/*
* check if clockid is supported
*/
- if (!perf_get_timestamp())
- warnx("jvmti: kernel does not support %d clock id", perf_clk_id);
+ if (!perf_get_timestamp()) {
+ if (use_arch_timestamp)
+ warnx("jvmti: arch timestamp not supported");
+ else
+ warnx("jvmti: kernel does not support %d clock id", perf_clk_id);
+ }
memset(&header, 0, sizeof(header));
@@ -263,6 +299,9 @@ void *jvmti_open(void)
header.timestamp = perf_get_timestamp();
+ if (use_arch_timestamp)
+ header.flags |= JITDUMP_FLAGS_ARCH_TIMESTAMP;
+
if (!fwrite(&header, sizeof(header), 1, fp)) {
warn("jvmti: cannot write dumpfile header");
goto error;
diff --git a/tools/perf/util/Build b/tools/perf/util/Build
index da48fd843438..85ceff357769 100644
--- a/tools/perf/util/Build
+++ b/tools/perf/util/Build
@@ -69,8 +69,7 @@ libperf-y += stat-shadow.o
libperf-y += record.o
libperf-y += srcline.o
libperf-y += data.o
-libperf-$(CONFIG_X86) += tsc.o
-libperf-$(CONFIG_AUXTRACE) += tsc.o
+libperf-y += tsc.o
libperf-y += cloexec.o
libperf-y += thread-stack.o
libperf-$(CONFIG_AUXTRACE) += auxtrace.o
diff --git a/tools/perf/util/jitdump.c b/tools/perf/util/jitdump.c
index ad0c0bb1fbc7..52fcef3074fe 100644
--- a/tools/perf/util/jitdump.c
+++ b/tools/perf/util/jitdump.c
@@ -17,6 +17,7 @@
#include "strlist.h"
#include <elf.h>
+#include "tsc.h"
#include "session.h"
#include "jit.h"
#include "jitdump.h"
@@ -33,6 +34,7 @@ struct jit_buf_desc {
size_t bufsize;
FILE *in;
bool needs_bswap; /* handles cross-endianess */
+ bool use_arch_timestamp;
void *debug_data;
size_t nr_debug_entries;
uint32_t code_load_count;
@@ -158,13 +160,16 @@ jit_open(struct jit_buf_desc *jd, const char *name)
header.flags = bswap_64(header.flags);
}
+ jd->use_arch_timestamp = header.flags & JITDUMP_FLAGS_ARCH_TIMESTAMP;
+
if (verbose > 2)
- pr_debug("version=%u\nhdr.size=%u\nts=0x%llx\npid=%d\nelf_mach=%d\n",
+ pr_debug("version=%u\nhdr.size=%u\nts=0x%llx\npid=%d\nelf_mach=%d\nuse_arch_timestamp=%d\n",
header.version,
header.total_size,
(unsigned long long)header.timestamp,
header.pid,
- header.elf_mach);
+ header.elf_mach,
+ jd->use_arch_timestamp);
if (header.flags & JITDUMP_FLAGS_RESERVED) {
pr_err("jitdump file contains invalid or unsupported flags 0x%llx\n",
@@ -172,10 +177,15 @@ jit_open(struct jit_buf_desc *jd, const char *name)
goto error;
}
+ if (jd->use_arch_timestamp && !jd->session->time_conv.time_mult) {
+ pr_err("jitdump file uses arch timestamps but there is no timestamp conversion\n");
+ goto error;
+ }
+
/*
* validate event is using the correct clockid
*/
- if (jit_validate_events(jd->session)) {
+ if (!jd->use_arch_timestamp && jit_validate_events(jd->session)) {
pr_err("error, jitted code must be sampled with perf record -k 1\n");
goto error;
}
@@ -329,6 +339,23 @@ jit_inject_event(struct jit_buf_desc *jd, union perf_event *event)
return 0;
}
+static uint64_t convert_timestamp(struct jit_buf_desc *jd, uint64_t timestamp)
+{
+ struct perf_tsc_conversion tc;
+
+ if (!jd->use_arch_timestamp)
+ return timestamp;
+
+ tc.time_shift = jd->session->time_conv.time_shift;
+ tc.time_mult = jd->session->time_conv.time_mult;
+ tc.time_zero = jd->session->time_conv.time_zero;
+
+ if (!tc.time_mult)
+ return 0;
+
+ return tsc_to_perf_time(timestamp, &tc);
+}
+
static int jit_repipe_code_load(struct jit_buf_desc *jd, union jr_entry *jr)
{
struct perf_sample sample;
@@ -410,7 +437,7 @@ static int jit_repipe_code_load(struct jit_buf_desc *jd, union jr_entry *jr)
id->tid = tid;
}
if (jd->sample_type & PERF_SAMPLE_TIME)
- id->time = jr->load.p.timestamp;
+ id->time = convert_timestamp(jd, jr->load.p.timestamp);
/*
* create pseudo sample to induce dso hit increment
@@ -499,7 +526,7 @@ static int jit_repipe_code_move(struct jit_buf_desc *jd, union jr_entry *jr)
id->tid = tid;
}
if (jd->sample_type & PERF_SAMPLE_TIME)
- id->time = jr->load.p.timestamp;
+ id->time = convert_timestamp(jd, jr->load.p.timestamp);
/*
* create pseudo sample to induce dso hit increment
diff --git a/tools/perf/util/jitdump.h b/tools/perf/util/jitdump.h
index b66c1f503d9e..bcacd20d0c1c 100644
--- a/tools/perf/util/jitdump.h
+++ b/tools/perf/util/jitdump.h
@@ -23,9 +23,12 @@
#define JITHEADER_VERSION 1
enum jitdump_flags_bits {
+ JITDUMP_FLAGS_ARCH_TIMESTAMP_BIT,
JITDUMP_FLAGS_MAX_BIT,
};
+#define JITDUMP_FLAGS_ARCH_TIMESTAMP (1ULL << JITDUMP_FLAGS_ARCH_TIMESTAMP_BIT)
+
#define JITDUMP_FLAGS_RESERVED (JITDUMP_FLAGS_MAX_BIT < 64 ? \
(~((1ULL << JITDUMP_FLAGS_MAX_BIT) - 1)) : 0)
diff --git a/tools/perf/util/tsc.h b/tools/perf/util/tsc.h
index 280ddc067556..d5b11e2b85e0 100644
--- a/tools/perf/util/tsc.h
+++ b/tools/perf/util/tsc.h
@@ -4,7 +4,16 @@
#include <linux/types.h>
#include "event.h"
-#include "../arch/x86/util/tsc.h"
+
+struct perf_tsc_conversion {
+ u16 time_shift;
+ u32 time_mult;
+ u64 time_zero;
+};
+struct perf_event_mmap_page;
+
+int perf_read_tsc_conversion(const struct perf_event_mmap_page *pc,
+ struct perf_tsc_conversion *tc);
u64 perf_time_to_tsc(u64 ns, struct perf_tsc_conversion *tc);
u64 tsc_to_perf_time(u64 cyc, struct perf_tsc_conversion *tc);
--
2.5.5
^ permalink raw reply related [flat|nested] 12+ messages in thread
* [PATCH 06/10] perf intel-pt/bts: Define JITDUMP_USE_ARCH_TIMESTAMP
2016-04-01 21:56 [GIT PULL 00/10] perf/core improvements and fixes Arnaldo Carvalho de Melo
` (4 preceding siblings ...)
2016-04-01 21:57 ` [PATCH 05/10] perf jit: Add support for using TSC as a timestamp Arnaldo Carvalho de Melo
@ 2016-04-01 21:57 ` Arnaldo Carvalho de Melo
2016-04-01 21:57 ` [PATCH 07/10] perf tools: Fix PMU term format max value calculation Arnaldo Carvalho de Melo
` (4 subsequent siblings)
10 siblings, 0 replies; 12+ messages in thread
From: Arnaldo Carvalho de Melo @ 2016-04-01 21:57 UTC (permalink / raw)
To: Ingo Molnar
Cc: linux-kernel, Adrian Hunter, Jiri Olsa, Stephane Eranian,
Arnaldo Carvalho de Melo
From: Adrian Hunter <adrian.hunter@intel.com>
For Intel PT / BTS, define the environment variable that selects TSC
timestamps in the jitdump file.
Signed-off-by: Adrian Hunter <adrian.hunter@intel.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/r/1457426333-30260-1-git-send-email-adrian.hunter@intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
tools/perf/arch/x86/util/intel-bts.c | 5 +++++
tools/perf/arch/x86/util/intel-pt.c | 5 +++++
2 files changed, 10 insertions(+)
diff --git a/tools/perf/arch/x86/util/intel-bts.c b/tools/perf/arch/x86/util/intel-bts.c
index d66f9ad4df2e..7dc30637cf66 100644
--- a/tools/perf/arch/x86/util/intel-bts.c
+++ b/tools/perf/arch/x86/util/intel-bts.c
@@ -438,6 +438,11 @@ struct auxtrace_record *intel_bts_recording_init(int *err)
if (!intel_bts_pmu)
return NULL;
+ if (setenv("JITDUMP_USE_ARCH_TIMESTAMP", "1", 1)) {
+ *err = -errno;
+ return NULL;
+ }
+
btsr = zalloc(sizeof(struct intel_bts_recording));
if (!btsr) {
*err = -ENOMEM;
diff --git a/tools/perf/arch/x86/util/intel-pt.c b/tools/perf/arch/x86/util/intel-pt.c
index a3395179c9ee..a07b9605e93b 100644
--- a/tools/perf/arch/x86/util/intel-pt.c
+++ b/tools/perf/arch/x86/util/intel-pt.c
@@ -1027,6 +1027,11 @@ struct auxtrace_record *intel_pt_recording_init(int *err)
if (!intel_pt_pmu)
return NULL;
+ if (setenv("JITDUMP_USE_ARCH_TIMESTAMP", "1", 1)) {
+ *err = -errno;
+ return NULL;
+ }
+
ptr = zalloc(sizeof(struct intel_pt_recording));
if (!ptr) {
*err = -ENOMEM;
--
2.5.5
^ permalink raw reply related [flat|nested] 12+ messages in thread
* [PATCH 07/10] perf tools: Fix PMU term format max value calculation
2016-04-01 21:56 [GIT PULL 00/10] perf/core improvements and fixes Arnaldo Carvalho de Melo
` (5 preceding siblings ...)
2016-04-01 21:57 ` [PATCH 06/10] perf intel-pt/bts: Define JITDUMP_USE_ARCH_TIMESTAMP Arnaldo Carvalho de Melo
@ 2016-04-01 21:57 ` Arnaldo Carvalho de Melo
2016-04-01 21:57 ` [PATCH 08/10] perf trace: Introduce function to set the base timestamp Arnaldo Carvalho de Melo
` (3 subsequent siblings)
10 siblings, 0 replies; 12+ messages in thread
From: Arnaldo Carvalho de Melo @ 2016-04-01 21:57 UTC (permalink / raw)
To: Ingo Molnar
Cc: linux-kernel, Kan Liang, Alexander Shishkin, Andi Kleen,
Jiri Olsa, Arnaldo Carvalho de Melo
From: Kan Liang <kan.liang@intel.com>
Currently the max value of format is calculated by the bits number. It
relies on the continuity of the format.
However, uncore event format is not continuous. E.g. uncore qpi event
format can be 0-7,21.
If bit 21 is set, there is parsing issues as below.
$ perf stat -a -e uncore_qpi_0/event=0x200002,umask=0x8/
event syntax error: '..pi_0/event=0x200002,umask=0x8/'
\___ value too big for format, maximum is 511
This patch return the real max value by setting all possible bits to 1.
Signed-off-by: Kan Liang <kan.liang@intel.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Andi Kleen <ak@linux.intel.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Link: http://lkml.kernel.org/r/1459365375-14285-1-git-send-email-kan.liang@intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
tools/perf/util/pmu.c | 13 ++++++-------
1 file changed, 6 insertions(+), 7 deletions(-)
diff --git a/tools/perf/util/pmu.c b/tools/perf/util/pmu.c
index adef23b1352e..bf34468a99cb 100644
--- a/tools/perf/util/pmu.c
+++ b/tools/perf/util/pmu.c
@@ -602,14 +602,13 @@ static void pmu_format_value(unsigned long *format, __u64 value, __u64 *v,
static __u64 pmu_format_max_value(const unsigned long *format)
{
- int w;
+ __u64 w = 0;
+ int fbit;
- w = bitmap_weight(format, PERF_PMU_FORMAT_BITS);
- if (!w)
- return 0;
- if (w < 64)
- return (1ULL << w) - 1;
- return -1;
+ for_each_set_bit(fbit, format, PERF_PMU_FORMAT_BITS)
+ w |= (1ULL << fbit);
+
+ return w;
}
/*
--
2.5.5
^ permalink raw reply related [flat|nested] 12+ messages in thread
* [PATCH 08/10] perf trace: Introduce function to set the base timestamp
2016-04-01 21:56 [GIT PULL 00/10] perf/core improvements and fixes Arnaldo Carvalho de Melo
` (6 preceding siblings ...)
2016-04-01 21:57 ` [PATCH 07/10] perf tools: Fix PMU term format max value calculation Arnaldo Carvalho de Melo
@ 2016-04-01 21:57 ` Arnaldo Carvalho de Melo
2016-04-01 21:57 ` [PATCH 09/10] perf trace: Don't set the base timestamp using events without PERF_SAMPLE_TIME Arnaldo Carvalho de Melo
` (2 subsequent siblings)
10 siblings, 0 replies; 12+ messages in thread
From: Arnaldo Carvalho de Melo @ 2016-04-01 21:57 UTC (permalink / raw)
To: Ingo Molnar
Cc: linux-kernel, Arnaldo Carvalho de Melo, Adrian Hunter,
David Ahern, Jiri Olsa, Milian Wolff, Namhyung Kim, Wang Nan
From: Arnaldo Carvalho de Melo <acme@redhat.com>
That is used in both live runs, i.e.:
# trace ls
As when processing events recorded in a perf.data file:
# trace -i perf.data
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-901l6yebnzeqg7z8mbaf49xb@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
tools/perf/builtin-trace.c | 16 +++++++++++-----
1 file changed, 11 insertions(+), 5 deletions(-)
diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c
index c45c1cfeb866..99daeed55a9b 100644
--- a/tools/perf/builtin-trace.c
+++ b/tools/perf/builtin-trace.c
@@ -2400,6 +2400,14 @@ static bool skip_sample(struct trace *trace, struct perf_sample *sample)
return false;
}
+static void trace__set_base_time(struct trace *trace,
+ struct perf_evsel *evsel __maybe_unused,
+ struct perf_sample *sample)
+{
+ if (trace->base_time == 0 && !trace->full_time)
+ trace->base_time = sample->time;
+}
+
static int trace__process_sample(struct perf_tool *tool,
union perf_event *event,
struct perf_sample *sample,
@@ -2414,8 +2422,7 @@ static int trace__process_sample(struct perf_tool *tool,
if (skip_sample(trace, sample))
return 0;
- if (!trace->full_time && trace->base_time == 0)
- trace->base_time = sample->time;
+ trace__set_base_time(trace, evsel, sample);
if (handler) {
++trace->nr_events;
@@ -2553,9 +2560,6 @@ static void trace__handle_event(struct trace *trace, union perf_event *event, st
const u32 type = event->header.type;
struct perf_evsel *evsel;
- if (!trace->full_time && trace->base_time == 0)
- trace->base_time = sample->time;
-
if (type != PERF_RECORD_SAMPLE) {
trace__process_event(trace, trace->host, event, sample);
return;
@@ -2567,6 +2571,8 @@ static void trace__handle_event(struct trace *trace, union perf_event *event, st
return;
}
+ trace__set_base_time(trace, evsel, sample);
+
if (evsel->attr.type == PERF_TYPE_TRACEPOINT &&
sample->raw_data == NULL) {
fprintf(trace->output, "%s sample with no payload for tid: %d, cpu %d, raw_size=%d, skipping...\n",
--
2.5.5
^ permalink raw reply related [flat|nested] 12+ messages in thread
* [PATCH 09/10] perf trace: Don't set the base timestamp using events without PERF_SAMPLE_TIME
2016-04-01 21:56 [GIT PULL 00/10] perf/core improvements and fixes Arnaldo Carvalho de Melo
` (7 preceding siblings ...)
2016-04-01 21:57 ` [PATCH 08/10] perf trace: Introduce function to set the base timestamp Arnaldo Carvalho de Melo
@ 2016-04-01 21:57 ` Arnaldo Carvalho de Melo
2016-04-01 21:57 ` [PATCH 10/10] perf bpf: Add sample types for 'bpf-output' event Arnaldo Carvalho de Melo
2016-04-06 6:47 ` [GIT PULL 00/10] perf/core improvements and fixes Ingo Molnar
10 siblings, 0 replies; 12+ messages in thread
From: Arnaldo Carvalho de Melo @ 2016-04-01 21:57 UTC (permalink / raw)
To: Ingo Molnar
Cc: linux-kernel, Arnaldo Carvalho de Melo, Adrian Hunter,
David Ahern, Jiri Olsa, Milian Wolff, Namhyung Kim, Wang Nan
From: Arnaldo Carvalho de Melo <acme@redhat.com>
This was causing bogus values to be shown at the timestamp column:
Before:
# trace --ev bpf-output/no-inherit,name=evt/ --ev /home/acme/bpf/test_bpf_trace.c/map:channel.event=evt/ usleep 10
94631143.385 ( 0.001 ms): brk( ) = 0x555555757000
94631143.398 ( 0.003 ms): mmap(len: 4096, prot: READ|WRITE, flags: PRIVATE|ANONYMOUS, fd: -1) = 0x7ffff7ff6000
94631143.406 ( 0.004 ms): access(filename: 0xf7df9e10, mode: R ) = -1 ENOENT No such file or directory
94631143.412 ( 0.004 ms): open(filename: 0xf7df8761, flags: CLOEXEC) = 3
94631143.415 ( 0.002 ms): fstat(fd: 3, statbuf: 0x7fffffffd6b0 ) = 0
94631143.419 ( 0.003 ms): mmap(len: 106798, prot: READ, flags: PRIVATE, fd: 3) = 0x7ffff7fdb000
94631143.420 ( 0.001 ms): close(fd: 3 ) = 0
94631143.432 ( 0.004 ms): open(filename: 0xf7ff6640, flags: CLOEXEC) = 3
<SNIP>
After:
# trace --ev bpf-output/no-inherit,name=evt/ --ev /home/acme/bpf/test_bpf_trace.c/map:channel.event=evt/ usleep 10
0.022 ( 0.001 ms): brk( ) = 0x55d7668a6000
0.037 ( 0.003 ms): mmap(len: 4096, prot: READ|WRITE, flags: PRIVATE|ANONYMOUS, fd: -1) = 0x7f8fbeb97000
0.123 ( 0.083 ms): access(filename: 0xbe995e10, mode: R ) = -1 ENOENT No such file or directory
0.130 ( 0.004 ms): open(filename: 0xbe994761, flags: CLOEXEC) = 3
0.133 ( 0.002 ms): fstat(fd: 3, statbuf: 0x7fff6487a890 ) = 0
0.138 ( 0.003 ms): mmap(len: 106798, prot: READ, flags: PRIVATE, fd: 3) = 0x7f8fbeb7c000
0.140 ( 0.001 ms): close(fd: 3 ) = 0
0.151 ( 0.004 ms): open(filename: 0xbeb97640, flags: CLOEXEC) = 3
<SNIP>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-p7m8llv81iv55ekxexdp5n57@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
tools/perf/builtin-trace.c | 13 +++++++++++--
1 file changed, 11 insertions(+), 2 deletions(-)
diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c
index 99daeed55a9b..d309f4535a45 100644
--- a/tools/perf/builtin-trace.c
+++ b/tools/perf/builtin-trace.c
@@ -2401,10 +2401,19 @@ static bool skip_sample(struct trace *trace, struct perf_sample *sample)
}
static void trace__set_base_time(struct trace *trace,
- struct perf_evsel *evsel __maybe_unused,
+ struct perf_evsel *evsel,
struct perf_sample *sample)
{
- if (trace->base_time == 0 && !trace->full_time)
+ /*
+ * BPF events were not setting PERF_SAMPLE_TIME, so be more robust
+ * and don't use sample->time unconditionally, we may end up having
+ * some other event in the future without PERF_SAMPLE_TIME for good
+ * reason, i.e. we may not be interested in its timestamps, just in
+ * it taking place, picking some piece of information when it
+ * appears in our event stream (vfs_getname comes to mind).
+ */
+ if (trace->base_time == 0 && !trace->full_time &&
+ (evsel->attr.sample_type & PERF_SAMPLE_TIME))
trace->base_time = sample->time;
}
--
2.5.5
^ permalink raw reply related [flat|nested] 12+ messages in thread
* [PATCH 10/10] perf bpf: Add sample types for 'bpf-output' event
2016-04-01 21:56 [GIT PULL 00/10] perf/core improvements and fixes Arnaldo Carvalho de Melo
` (8 preceding siblings ...)
2016-04-01 21:57 ` [PATCH 09/10] perf trace: Don't set the base timestamp using events without PERF_SAMPLE_TIME Arnaldo Carvalho de Melo
@ 2016-04-01 21:57 ` Arnaldo Carvalho de Melo
2016-04-06 6:47 ` [GIT PULL 00/10] perf/core improvements and fixes Ingo Molnar
10 siblings, 0 replies; 12+ messages in thread
From: Arnaldo Carvalho de Melo @ 2016-04-01 21:57 UTC (permalink / raw)
To: Ingo Molnar
Cc: linux-kernel, Wang Nan, Adrian Hunter, David Ahern, Jiri Olsa,
Milian Wolff, Namhyung Kim, pi3orama, Arnaldo Carvalho de Melo
From: Wang Nan <wangnan0@huawei.com>
Before this patch we can see very large time in the events before the
'bpf-output' event. For example:
# perf trace -vv -T --ev sched:sched_switch \
--ev bpf-output/no-inherit,name=evt/ \
--ev ./test_bpf_trace.c/map:channel.event=evt/ \
usleep 10
...
18446744073709.551 (18446564645918.480 ms): usleep/4157 nanosleep(rqtp: 0x7ffd3f0dc4e0) ...
18446744073709.551 ( ): evt:Raise a BPF event!..)
179427791.076 ( ): perf_bpf_probe:func_begin:(ffffffff810eb9a0))
179427791.081 ( ): sched:sched_switch:usleep:4157 [120] S ==> swapper/2:0 [120])
...
We can also see the differences between bpf-output events and
breakpoint events:
For bpf output event:
sample_type IP|TID|RAW|IDENTIFIER
For tracepoint events:
sample_type IP|TID|TIME|CPU|PERIOD|RAW|IDENTIFIER
This patch fix this differences by adding more sample type for
bpf-output events.
After this patch:
# perf trace -vv -T --ev sched:sched_switch \
--ev bpf-output/no-inherit,name=evt/ \
--ev ./test_bpf_trace.c/map:channel.event=evt/ \
usleep 10
...
179877370.878 ( 0.003 ms): usleep/5336 nanosleep(rqtp: 0x7ffff866c450) ...
179877370.878 ( ): evt:Raise a BPF event!..)
179877370.878 ( ): perf_bpf_probe:func_begin:(ffffffff810eb9a0))
179877370.882 ( ): sched:sched_switch:usleep:5336 [120] S ==> swapper/4:0 [120])
179877370.945 ( ): evt:Raise a BPF event!..)
...
# ./perf trace -vv -T --ev sched:sched_switch \
--ev bpf-output/no-inherit,name=evt/ \
--ev ./test_bpf_trace.c/map:channel.event=evt/ \
usleep 10 2>&1 | grep sample_type
sample_type IP|TID|TIME|ID|CPU|PERIOD|RAW
sample_type IP|TID|TIME|ID|CPU|PERIOD|RAW
sample_type IP|TID|TIME|ID|CPU|PERIOD|RAW
sample_type IP|TID|TIME|ID|CPU|PERIOD|RAW
sample_type IP|TID|TIME|ID|CPU|PERIOD|RAW
sample_type IP|TID|TIME|ID|CPU|PERIOD|RAW
The 'IDENTIFIER' info is not required because all events have the same
sample_type.
Committer notes:
Further testing, on top of the changes making 'perf trace' avoid samples
from events without PERF_SAMPLE_TIME:
Before:
# trace --ev bpf-output/no-inherit,name=evt/ --ev /home/acme/bpf/test_bpf_trace.c/map:channel.event=evt/ usleep 10
<SNIP>
0.560 ( 0.001 ms): brk( ) = 0x55e5a1df8000
18446640227439.430 (18446640227438.859 ms): nanosleep(rqtp: 0x7ffc96643370) ...
18446640227439.430 ( ): evt:Raise a BPF event!..)
0.576 ( ): perf_bpf_probe:func_begin:(ffffffff81112460))
18446640227439.430 ( ): evt:Raise a BPF event!..)
0.645 ( ): perf_bpf_probe:func_end:(ffffffff81112460 <- ffffffff81003d92))
0.646 ( 0.076 ms): ... [continued]: nanosleep()) = 0
#
After:
# trace --ev bpf-output/no-inherit,name=evt/ --ev /home/acme/bpf/test_bpf_trace.c/map:channel.event=evt/ usleep 10
<SNIP>
0.292 ( 0.001 ms): brk( ) = 0x55c7cd6e1000
0.302 ( 0.004 ms): nanosleep(rqtp: 0x7ffedd8bc0f0) ...
0.302 ( ): evt:Raise a BPF event!..)
0.303 ( ): perf_bpf_probe:func_begin:(ffffffff81112460))
0.397 ( ): evt:Raise a BPF event!..)
0.397 ( ): perf_bpf_probe:func_end:(ffffffff81112460 <- ffffffff81003d92))
0.398 ( 0.100 ms): ... [continued]: nanosleep()) = 0
Signed-off-by: Wang Nan <wangnan0@huawei.com>
Reported-and-Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: pi3orama@163.com
Link: http://lkml.kernel.org/r/1459517202-42320-1-git-send-email-wangnan0@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
tools/perf/util/evsel.c | 3 ++-
1 file changed, 2 insertions(+), 1 deletion(-)
diff --git a/tools/perf/util/evsel.c b/tools/perf/util/evsel.c
index 738ce226002b..3fd7c2c72f4a 100644
--- a/tools/perf/util/evsel.c
+++ b/tools/perf/util/evsel.c
@@ -226,7 +226,8 @@ struct perf_evsel *perf_evsel__new_idx(struct perf_event_attr *attr, int idx)
perf_evsel__init(evsel, attr, idx);
if (perf_evsel__is_bpf_output(evsel)) {
- evsel->attr.sample_type |= PERF_SAMPLE_RAW;
+ evsel->attr.sample_type |= (PERF_SAMPLE_RAW | PERF_SAMPLE_TIME |
+ PERF_SAMPLE_CPU | PERF_SAMPLE_PERIOD),
evsel->attr.sample_period = 1;
}
--
2.5.5
^ permalink raw reply related [flat|nested] 12+ messages in thread
* Re: [GIT PULL 00/10] perf/core improvements and fixes
2016-04-01 21:56 [GIT PULL 00/10] perf/core improvements and fixes Arnaldo Carvalho de Melo
` (9 preceding siblings ...)
2016-04-01 21:57 ` [PATCH 10/10] perf bpf: Add sample types for 'bpf-output' event Arnaldo Carvalho de Melo
@ 2016-04-06 6:47 ` Ingo Molnar
10 siblings, 0 replies; 12+ messages in thread
From: Ingo Molnar @ 2016-04-06 6:47 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo
Cc: linux-kernel, Adrian Hunter, Alexander Shishkin, Andi Kleen,
David Ahern, He Kuang, Jiri Olsa, Josh Poimboeuf, Kan Liang,
Milian Wolff, Namhyung Kim, Peter Zijlstra, pi3orama,
Stephane Eranian, Sukadev Bhattiprolu, Wang Nan,
Arnaldo Carvalho de Melo
* Arnaldo Carvalho de Melo <acme@kernel.org> wrote:
> Hi Ingo,
>
> Please consider pulling,
>
> - Arnaldo
>
> The following changes since commit d1b26c70246bc72922ae61d9f972d5c2588409e7:
>
> perf/ring_buffer: Prepare writing into the ring-buffer from the end (2016-03-31 10:30:49 +0200)
>
> are available in the git repository at:
>
> git://git.kernel.org/pub/scm/linux/kernel/git/acme/linux.git tags/perf-core-for-mingo-20160401
>
> for you to fetch changes up to d37ba880598654fda10b312331377cdca3edd574:
>
> perf bpf: Add sample types for 'bpf-output' event (2016-04-01 18:46:25 -0300)
>
> ----------------------------------------------------------------
> perf/core improvements and fixes:
>
> User visible:
>
> - Do not use events that don't have timestamps when setting 'perf trace's
> base timestamp, fixing up the timestamp column for syscalls (Arnaldo Carvalho de Melo)
>
> - Make the 'bpf-output' sample_type be the same as tracepoint's, fixing up
> 'perf trace's timestamp column for bpf events (Wang Nan)
>
> - Fix PMU term format max value calculation (Kan Liang)
>
> - Pretty print 'seccomp', 'getrandom' syscalls in 'perf trace' (Arnaldo Carvalho de Melo)
>
> Infrastructure:
>
> - Add support for using TSC as an ARCH timestamp when synthesizing
> JIT records (Adrian Hunter)
>
> Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
>
> ----------------------------------------------------------------
> Adrian Hunter (3):
> perf tools: Add time conversion event
> perf jit: Add support for using TSC as a timestamp
> perf intel-pt/bts: Define JITDUMP_USE_ARCH_TIMESTAMP
>
> Arnaldo Carvalho de Melo (5):
> perf trace: Do not process PERF_RECORD_LOST twice
> perf trace: Pretty print seccomp() args
> perf trace: Pretty print getrandom() args
> perf trace: Introduce function to set the base timestamp
> perf trace: Don't set the base timestamp using events without PERF_SAMPLE_TIME
>
> Kan Liang (1):
> perf tools: Fix PMU term format max value calculation
>
> Wang Nan (1):
> perf bpf: Add sample types for 'bpf-output' event
>
> tools/perf/arch/x86/util/intel-bts.c | 5 ++
> tools/perf/arch/x86/util/intel-pt.c | 5 ++
> tools/perf/arch/x86/util/tsc.c | 32 +++++++++++-
> tools/perf/arch/x86/util/tsc.h | 17 -------
> tools/perf/builtin-inject.c | 1 +
> tools/perf/builtin-record.c | 15 ++++++
> tools/perf/builtin-trace.c | 99 ++++++++++++++++++++++++++++++++++--
> tools/perf/jvmti/jvmti_agent.c | 43 +++++++++++++++-
> tools/perf/util/Build | 3 +-
> tools/perf/util/event.c | 1 +
> tools/perf/util/event.h | 9 ++++
> tools/perf/util/evsel.c | 3 +-
> tools/perf/util/jitdump.c | 37 ++++++++++++--
> tools/perf/util/jitdump.h | 3 ++
> tools/perf/util/pmu.c | 13 +++--
> tools/perf/util/session.c | 6 +++
> tools/perf/util/session.h | 1 +
> tools/perf/util/tool.h | 1 +
> tools/perf/util/tsc.h | 21 +++++++-
> 19 files changed, 274 insertions(+), 41 deletions(-)
> delete mode 100644 tools/perf/arch/x86/util/tsc.h
Pulled, thanks a lot Arnaldo!
Ingo
^ permalink raw reply [flat|nested] 12+ messages in thread