[tip:perf/core] perf tools: Sample after exit loses thread correlation
From: tip-bot for David Ahern
Date: Thu Aug 29 2013 - 06:09:12 EST
Commit-ID: 236a3bbd5cb51edbf9550f5a7df885665d18a271
Gitweb: http://git.kernel.org/tip/236a3bbd5cb51edbf9550f5a7df885665d18a271
Author: David Ahern <dsahern@xxxxxxxxx>
AuthorDate: Wed, 14 Aug 2013 08:49:27 -0600
Committer: Arnaldo Carvalho de Melo <acme@xxxxxxxxxx>
CommitDate: Mon, 26 Aug 2013 17:25:36 -0300
perf tools: Sample after exit loses thread correlation
Occassionally events (e.g., context-switch, sched tracepoints) are losing
the conversion of sample data associated with a thread. For example:
$ perf record -e sched:sched_switch -c 1 -a -- sleep 5
$ perf script
<selected events shown>
ls 30482 [000] 1379727.583037: sched:sched_switch: prev_comm=ls prev_pid=30482 ...
ls 30482 [000] 1379727.586339: sched:sched_switch: prev_comm=ls prev_pid=30482 ...
:30482 30482 [000] 1379727.589462: sched:sched_switch: prev_comm=ls prev_pid=30482 ...
The last line lost the conversion from tid to comm. If you look at the events
(perf script -D) you see why - a SAMPLE event is generated after the EXIT:
0 1379727589449774 0x1540b0 [0x38]: PERF_RECORD_EXIT(30482:30482):(30482:30482)
0 1379727589462497 0x1540e8 [0x80]: PERF_RECORD_SAMPLE(IP, 1): 30482/30482: 0xffffffff816416f1 period: 1 addr: 0
... thread: :30482:30482
When perf processes the EXIT event the thread is moved to the dead_threads
list. When the SAMPLE event is processed no thread exists for the pid so a new
one is created by machine__findnew_thread.
This patch address the problem by delaying the move to the dead_threads list
until the tid is re-used (per Adrian's suggestion).
With this patch we get the previous example shows:
ls 30482 [000] 1379727.583037: sched:sched_switch: prev_comm=ls prev_pid=30482 ...
ls 30482 [000] 1379727.586339: sched:sched_switch: prev_comm=ls prev_pid=30482 ...
ls 30482 [000] 1379727.589462: sched:sched_switch: prev_comm=ls prev_pid=30482 ...
and
0 1379727589449774 0x1540b0 [0x38]: PERF_RECORD_EXIT(30482:30482):(30482:30482)
0 1379727589462497 0x1540e8 [0x80]: PERF_RECORD_SAMPLE(IP, 1): 30482/30482: 0xffffffff816416f1 period: 1 addr: 0
... thread: ls:30482
v4: per Arnaldo's request add dead flag to thread struct and set when task exits
v3: re-do from a time based check to a delayed move to dead_threads list
v2: Rebased to latest perf/core branch. Changed time comparison to use
a macro which explicitly shows the time basis
Signed-off-by: David Ahern <dsahern@xxxxxxxxx>
Acked-by: Adrian Hunter <adrian.hunter@xxxxxxxxx>
Cc: Adrian Hunter <adrian.hunter@xxxxxxxxx>
Cc: Frederic Weisbecker <fweisbec@xxxxxxxxx>
Cc: Ingo Molnar <mingo@xxxxxxxxxx>
Cc: Jiri Olsa <jolsa@xxxxxxxxxx>
Cc: Mike Galbraith <efault@xxxxxx>
Cc: Namhyung Kim <namhyung@xxxxxxxxxx>
Cc: Peter Zijlstra <peterz@xxxxxxxxxxxxx>
Cc: Stephane Eranian <eranian@xxxxxxxxxx>
Link: http://lkml.kernel.org/r/1376491767-84171-1-git-send-email-dsahern@xxxxxxxxx
Signed-off-by: Arnaldo Carvalho de Melo <acme@xxxxxxxxxx>
---
tools/perf/util/machine.c | 34 ++++++++++++++++++++--------------
tools/perf/util/thread.h | 5 +++++
2 files changed, 25 insertions(+), 14 deletions(-)
diff --git a/tools/perf/util/machine.c b/tools/perf/util/machine.c
index 4514e7e..574feb7 100644
--- a/tools/perf/util/machine.c
+++ b/tools/perf/util/machine.c
@@ -1031,11 +1031,27 @@ out_problem:
return 0;
}
+static void machine__remove_thread(struct machine *machine, struct thread *th)
+{
+ machine->last_match = NULL;
+ rb_erase(&th->rb_node, &machine->threads);
+ /*
+ * We may have references to this thread, for instance in some hist_entry
+ * instances, so just move them to a separate list.
+ */
+ list_add_tail(&th->node, &machine->dead_threads);
+}
+
int machine__process_fork_event(struct machine *machine, union perf_event *event)
{
- struct thread *thread = machine__findnew_thread(machine, event->fork.tid);
+ struct thread *thread = machine__find_thread(machine, event->fork.tid);
struct thread *parent = machine__findnew_thread(machine, event->fork.ptid);
+ /* if a thread currently exists for the thread id remove it */
+ if (thread != NULL)
+ machine__remove_thread(machine, thread);
+
+ thread = machine__findnew_thread(machine, event->fork.tid);
if (dump_trace)
perf_event__fprintf_task(event, stdout);
@@ -1048,18 +1064,8 @@ int machine__process_fork_event(struct machine *machine, union perf_event *event
return 0;
}
-static void machine__remove_thread(struct machine *machine, struct thread *th)
-{
- machine->last_match = NULL;
- rb_erase(&th->rb_node, &machine->threads);
- /*
- * We may have references to this thread, for instance in some hist_entry
- * instances, so just move them to a separate list.
- */
- list_add_tail(&th->node, &machine->dead_threads);
-}
-
-int machine__process_exit_event(struct machine *machine, union perf_event *event)
+int machine__process_exit_event(struct machine *machine __maybe_unused,
+ union perf_event *event)
{
struct thread *thread = machine__find_thread(machine, event->fork.tid);
@@ -1067,7 +1073,7 @@ int machine__process_exit_event(struct machine *machine, union perf_event *event
perf_event__fprintf_task(event, stdout);
if (thread != NULL)
- machine__remove_thread(machine, thread);
+ thread__exited(thread);
return 0;
}
diff --git a/tools/perf/util/thread.h b/tools/perf/util/thread.h
index 13c62c9..32d0601 100644
--- a/tools/perf/util/thread.h
+++ b/tools/perf/util/thread.h
@@ -16,6 +16,7 @@ struct thread {
pid_t ppid;
char shortname[3];
bool comm_set;
+ bool dead; /* if set thread has exited */
char *comm;
int comm_len;
@@ -26,6 +27,10 @@ struct machine;
struct thread *thread__new(pid_t tid);
void thread__delete(struct thread *self);
+static inline void thread__exited(struct thread *thread)
+{
+ thread->dead = true;
+}
int thread__set_comm(struct thread *self, const char *comm);
int thread__comm_len(struct thread *self);
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/