perf sched: Add timehist subcommand
cover perf sched: Add timehist subcommand
Ingo/Arnaldo:
I have a lot of patches queued up on top of this set. Before I go much farther and the queue grows longer I wanted to throw out this set for comments, review and inclusion where possible. Most of the patches are cleanups and re-workings leading up to the new command. The patches I have after this continue to add more features and options to the timehist command to match what I have been using for the past few years.
David Ahern (19):
perf: sample after exit loses thread correlation - v3
perf sched: simplify arguments to read_events
perf sched: remove thread lookup in sample handler
perf sched: remove sched_process_exit tracepoint
perf sched: remove sched_process_fork tracepoint
perf symbol: add optimization for idle kernel symbols
perf top: use new idle_sym check
perf symbol: save vmlinux or kallsyms path loaded
perf tool: Simplify options to perf_evsel__print_ip
perf tool: Add option to print stack trace on single line
perf tool: Add option to limit stack depth in callchain dumps perf tool: Add support for exclude symbol list to symbol_conf perf tool: Skip symbols in exclude list while printing callchain perf sched: pass event to evsel handlers using data element perf sched: Add timehist command
perf tool: Change perf_session__has_traces to actually check for tracepoints perf sched timehist: add support for context-switch event
perf sched timehist: print all events in verbose mode
perf sched timehist: add pid/tid option
tools/perf/builtin-sched.c | 959 ++++++++++++++++++++++++++++++++++++++++--- tools/perf/builtin-script.c | 29 +- tools/perf/builtin-top.c | 25 +- tools/perf/util/machine.c | 37 +- tools/perf/util/session.c | 39 +- tools/perf/util/session.h | 8 +- tools/perf/util/symbol.c | 71 +++- tools/perf/util/symbol.h | 8 +- 8 files changed, 1063 insertions(+), 113 deletions(-)
Signature · 1 line
1.7.10.1
PATCH 1/19 perf: sample after exit loses thread correlation - v3
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 - 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
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
--- tools/perf/util/machine.c | 37 +++++++++++++++++++------------------ 1 file changed, 19 insertions(+), 18 deletions(-)
tools/perf/util/machine.c +19 -18
@@ -1011,11 +1011,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);
@@ -1028,27 +1044,12 @@ int machine__process_fork_event(struct machine *machine, union perf_event *eventreturn 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); -if (dump_trace)perf_event__fprintf_task (event, stdout); -if (thread !=NULL ) -machine__remove_thread (machine, thread); -return 0 ; }
Signature · 1 line
1.7.10.1
Re: [PATCH 01/19] perf: sample after exit loses thread correlation - v3
Em Wed, Aug 07, 2013 at 10:50:43PM -0400, David Ahern escreveu:
Quoted 2 lines
Occassionally events (e.g., context-switch, sched tracepoints) are losing the conversion of sample data associated with a thread. For example:
Humm, if we have a tool that traverses the list of threads in a machine it will not know, after one of them exits, about it being dead, so I think this needs to add a thread->dead, no?
As of now, from what I can remember, the closest to such a tool would be:
perf top --sort pid
But that uses hist_entries that would eventually be decayed as samples would cease to be taken at most a few moments after the EXIT event.
But at least for debugging purposes, machine__fprintf() would list dead threads as being present, i.e. alive till its pid gets reused.
This is the only, minor, problem that I see with this solution, what do you think?
- Arnaldo
Quoted 117 lines
$ 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 - SAMPLE event is generated after the EXIT:
0 1379727589449774
0x1540b0[0x38]: PERF_RECORD_EXIT(30482:30482):(30482:30482)
0 13797275894624970x1540e8[0x80]:PERF_RECORD_SAMPLE(IP, 1): 30482/30482:0xffffffff816416f1period: 1 addr: 0 ... thread: :30482:30482When perf processes the EXIT event the thread is moved to the
dead_threadslist. When the SAMPLE event is processed no thread exists for the pid so a new one is created bymachine__findnew_thread.This patch address the problem by delaying the move to the
dead_threadslist 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 13797275894624970x1540e8[0x80]:PERF_RECORD_SAMPLE(IP, 1): 30482/30482:0xffffffff816416f1period: 1 addr: 0 ... thread: ls:30482v3: re-do from a time based check to a delayed move to
dead_threadslistv2: Rebased to latest perf/core branch. Changed time comparison to use
a macro which explicitly shows the time basisSigned-off-by David Ahern <[email protected]>Acked-by Adrian Hunter <[email protected]>Cc Frederic Weisbecker <[email protected]>Cc Ingo Molnar <[email protected]>Cc Jiri Olsa <[email protected]>Cc Mike Galbraith <[email protected]>Cc Namhyung Kim <[email protected]>Cc Peter Zijlstra <[email protected]>Cc Stephane Eranian <[email protected]>Cc Adrian Hunter <[email protected]>--- tools/perf/util/machine.c | 37 +++++++++++++++++++------------------ 1 file changed, 19 insertions(+), 18 deletions(-)tools/perf/util/machine.c +19
-18@@ -1011,11 +1011,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);@@ -1028,27 +1044,12 @@ int machine__process_fork_event(struct machine *machine, union perf_event *eventreturn 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); -if (dump_trace)perf_event__fprintf_task (event, stdout); -if (thread !=NULL ) -machine__remove_thread (machine, thread); -return 0 ; }Signature · 1 line
1.7.10.1
Re: [PATCH 01/19] perf: sample after exit loses thread correlation - v3
Quoted 13 lines · Arnaldo Carvalho de Melo
Em Wed, Aug 07, 2013 at 10:50:43PM -0400, David Ahern escreveu:
Quoted 2 lines
Occassionally events (e.g., context-switch, sched tracepoints) are losing the conversion of sample data associated with a thread. For example:
Humm, if we have a tool that traverses the list of threads in a machine it will not know, after one of them exits, about it being dead, so I think this needs to add a
thread->dead, no?As of now, from what I can remember, the closest to such a tool would be:
perf top --sort pid
Quoted 8 lines
But that uses
hist_entriesthat would eventually be decayed as samples would cease to be taken at most a few moments after the EXIT event.But at least for debugging purposes,
machine__fprintf()would list dead threads as being present, i.e. alive till its pid gets reused.This is the only, minor, problem that I see with this solution, what do you think?
I can add the exit timestamp to the thread struct. non-0 means it has died. Ok with that as an indicator?
David
Re: [PATCH 01/19] perf: sample after exit loses thread correlation - v3
Em Thu, Aug 08, 2013 at 04:42:33PM -0400, David Ahern escreveu:
Quoted 17 lines · Arnaldo Carvalho de Melo
Quoted 16 lines
Em Wed, Aug 07, 2013 at 10:50:43PM -0400, David Ahern escreveu:
Quoted 2 lines
Occassionally events (e.g., context-switch, sched tracepoints) are losing the conversion of sample data associated with a thread. For example:
Humm, if we have a tool that traverses the list of threads in a machine it will not know, after one of them exits, about it being dead, so I think this needs to add a
thread->dead, no?As of now, from what I can remember, the closest to such a tool would be:
perf top --sort pid
But that uses
hist_entriesthat would eventually be decayed as samples would cease to be taken at most a few moments after the EXIT event.
Quoted 8 lines
Quoted 5 lines
But at least for debugging purposes,
machine__fprintf()would list dead threads as being present, i.e. alive till its pid gets reused.This is the only, minor, problem that I see with this solution, what do you think?
I can add the exit timestamp to the thread struct. non-0 means it has died. Ok with that as an indicator?
I thought about that, at first looked like overengineering and wasting some bytes, as we don't have an user for that now, all we need is a single bit (or bool) just after ->comm_set :-)
If we ever have a use for knowing when the thread exited, no problem in adding it then.
- Arnaldo
PATCH 2/19 perf sched: Simplify arguments to read_events
In reply to David AhernDestroy argument is not necessary. If session is not returned to caller, then clean it up.
--- tools/perf/builtin-sched.c | 16 +++++++++------- 1 file changed, 9 insertions(+), 7 deletions(-)
tools/perf/builtin-sched.c +9 -7
@@ -1445,7 +1445,7 @@ static int perf_sched__process_tracepoint_sample(struct perf_tool *tool __maybe_return err; } -static int perf_sched__read_events (struct perf_sched *sched,bool destroy, +static int perf_sched__read_events (struct perf_sched *sched,struct perf_session **psession) {const struct perf_evsel_str_handler handlers[] = {
@@ -1480,11 +1480,10 @@ static int perf_sched__read_events(struct perf_sched *sched, bool destroy, sched->nr_lost_chunks = session->stats.nr_events[PERF_RECORD_LOST ]; } -if (destroy) -perf_session__delete (session); -if (psession) *psession = session; +else +perf_session__delete (session);return 0 ;
@@ -1529,8 +1528,11 @@ static int perf_sched__lat(struct perf_sched *sched)struct perf_session *session;setup_pager (); -if (perf_sched__read_events (sched, false, &session)) + +/* save session -- references to threads are held in work_list */ +if (perf_sched__read_events (sched, &session))return -1 ; +perf_sched__sort_lat (sched);printf ("\n ---------------------------------------------------------------------------------------------------------------\n" );
@@ -1565,7 +1567,7 @@ static int perf_sched__map(struct perf_sched *sched) sched->max_cpu =sysconf (_SC_NPROCESSORS_CONF);setup_pager (); -if (perf_sched__read_events (sched, true,NULL )) +if (perf_sched__read_events (sched,NULL ))return -1 ;print_bad_events (sched);return 0 ;
@@ -1580,7 +1582,7 @@ static int perf_sched__replay(struct perf_sched *sched)test_calibrations (sched); -if (perf_sched__read_events (sched, true,NULL )) +if (perf_sched__read_events (sched,NULL ))return -1 ;printf ("nr_run_events: %ld\n" , sched->nr_run_events);
Signature · 1 line
1.7.10.1
Arnaldo Carvalho de Melo
AppliedRe: [PATCH 02/19] perf sched: Simplify arguments to read_events
Em Wed, Aug 07, 2013 at 10:50:44PM -0400, David Ahern escreveu:
Quoted 2 lines
Destroy argument is not necessary. If session is not returned to caller, then clean it up.
Thanks, applied.
tip-bot for David Ahern
merge bot[tip:perf/core] perf sched: Simplify arguments to read_events
In reply to David Ahernperf sched: Simplify arguments to read_events
Commit-ID: ad9def7ca020ef5b54968c89194f52d18ef1ef49 Gitweb: http://git.kernel.org/tip/ad9def7ca020ef5b54968c89194f52d18ef1ef49 Author: David Ahern <[email protected]> AuthorDate: Wed, 7 Aug 2013 22:50:44 -0400 Committer: Arnaldo Carvalho de Melo <[email protected]> CommitDate: Mon, 12 Aug 2013 10:31:05 -0300
perf sched: Simplify arguments to read_events
Destroy argument is not necessary. If session is not returned to caller, then clean it up.
--- tools/perf/builtin-sched.c | 16 +++++++++------- 1 file changed, 9 insertions(+), 7 deletions(-)
tools/perf/builtin-sched.c +9 -7
@@ -1445,7 +1445,7 @@ static int perf_sched__process_tracepoint_sample(struct perf_tool *tool __maybe_return err; } -static int perf_sched__read_events (struct perf_sched *sched,bool destroy, +static int perf_sched__read_events (struct perf_sched *sched,struct perf_session **psession) {const struct perf_evsel_str_handler handlers[] = {
@@ -1480,11 +1480,10 @@ static int perf_sched__read_events(struct perf_sched *sched, bool destroy, sched->nr_lost_chunks = session->stats.nr_events[PERF_RECORD_LOST ]; } -if (destroy) -perf_session__delete (session); -if (psession) *psession = session; +else +perf_session__delete (session);return 0 ;
@@ -1529,8 +1528,11 @@ static int perf_sched__lat(struct perf_sched *sched)struct perf_session *session;setup_pager (); -if (perf_sched__read_events (sched, false, &session)) + +/* save session -- references to threads are held in work_list */ +if (perf_sched__read_events (sched, &session))return -1 ; +perf_sched__sort_lat (sched);printf ("\n ---------------------------------------------------------------------------------------------------------------\n" );
@@ -1565,7 +1567,7 @@ static int perf_sched__map(struct perf_sched *sched) sched->max_cpu =sysconf (_SC_NPROCESSORS_CONF);setup_pager (); -if (perf_sched__read_events (sched, true,NULL )) +if (perf_sched__read_events (sched,NULL ))return -1 ;print_bad_events (sched);return 0 ;
@@ -1580,7 +1582,7 @@ static int perf_sched__replay(struct perf_sched *sched)test_calibrations (sched); -if (perf_sched__read_events (sched, true,NULL )) +if (perf_sched__read_events (sched,NULL ))return -1 ;printf ("nr_run_events: %ld\n" , sched->nr_run_events);
PATCH 3/19 perf sched: Remove thread lookup in sample handler
In reply to David AhernNot used in the function, so no sense in doing the lookup here. Thread look up will be done in the timehist command, and no sense in doing it twice.
--- tools/perf/builtin-sched.c | 7 ------- 1 file changed, 7 deletions(-)
tools/perf/builtin-sched.c +0 -7
@@ -1425,15 +1425,8 @@ static int perf_sched__process_tracepoint_sample(struct perf_tool *tool __maybe_struct perf_evsel *evsel, struct machine *machine) { - struct thread *thread = machine__findnew_thread(machine, sample->tid); int err = 0; -if (thread ==NULL ) { -pr_debug ("problem processing %s event, skipping it.\n" , -perf_evsel__name (evsel)); -return -1 ; - } - evsel->hists.stats.total_period += sample->period;hists__inc_nr_events (&evsel->hists,PERF_RECORD_SAMPLE );
Signature · 1 line
1.7.10.1
Arnaldo Carvalho de Melo
AppliedRe: [PATCH 03/19] perf sched: Remove thread lookup in sample handler
Em Wed, Aug 07, 2013 at 10:50:45PM -0400, David Ahern escreveu:
Quoted 2 lines
Not used in the function, so no sense in doing the lookup here. Thread look up will be done in the timehist command, and no sense in doing it twice.
Thanks, applied.
tip-bot for David Ahern
merge bot[tip:perf/core] perf sched: Remove thread lookup in sample handler
In reply to David Ahernperf sched: Remove thread lookup in sample handler
Commit-ID: ffb273dd7e3bd72e7d964fc0a0f6d441aceb7dae Gitweb: http://git.kernel.org/tip/ffb273dd7e3bd72e7d964fc0a0f6d441aceb7dae Author: David Ahern <[email protected]> AuthorDate: Wed, 7 Aug 2013 22:50:45 -0400 Committer: Arnaldo Carvalho de Melo <[email protected]> CommitDate: Mon, 12 Aug 2013 10:31:06 -0300
perf sched: Remove thread lookup in sample handler
Not used in the function, so no sense in doing the lookup here. Thread look up will be done in the timehist command, and no sense in doing it twice.
--- tools/perf/builtin-sched.c | 7 ------- 1 file changed, 7 deletions(-)
tools/perf/builtin-sched.c +0 -7
@@ -1425,15 +1425,8 @@ static int perf_sched__process_tracepoint_sample(struct perf_tool *tool __maybe_struct perf_evsel *evsel, struct machine *machine) { - struct thread *thread = machine__findnew_thread(machine, sample->tid); int err = 0; -if (thread ==NULL ) { -pr_debug ("problem processing %s event, skipping it.\n" , -perf_evsel__name (evsel)); -return -1 ; - } - evsel->hists.stats.total_period += sample->period;hists__inc_nr_events (&evsel->hists,PERF_RECORD_SAMPLE );
PATCH 4/19 perf sched: Remove sched_process_exit tracepoint
In reply to David AhernEvent is not needed nor analyzed. Since perf-sched leverages perf-record to capture the sched data, we already capture task events like EXIT.
--- tools/perf/builtin-sched.c | 11 ----------- 1 file changed, 11 deletions(-)
tools/perf/builtin-sched.c +0 -11
@@ -1392,15 +1392,6 @@ static int process_sched_fork_event(struct perf_tool *tool,return 0 ; } -static int process_sched_exit_event (struct perf_tool *tool__maybe_unused , -struct perf_evsel *evsel, -struct perf_sample *sample__maybe_unused , -struct machine *machine__maybe_unused ) -{ -pr_debug ("sched_exit event %p\n" , evsel); -return 0 ; -} - static int process_sched_migrate_task_event(struct perf_tool *tool, struct perf_evsel *evsel, struct perf_sample *sample,
@@ -1447,7 +1438,6 @@ static int perf_sched__read_events(struct perf_sched *sched, { "sched:sched_wakeup", process_sched_wakeup_event, }, { "sched:sched_wakeup_new", process_sched_wakeup_event, }, { "sched:sched_process_fork", process_sched_fork_event, }, - { "sched:sched_process_exit", process_sched_exit_event, }, { "sched:sched_migrate_task", process_sched_migrate_task_event, }, };struct perf_session *session;
@@ -1634,7 +1624,6 @@ static int __cmd_record(int argc, const char **argv)"-e" ,"sched:sched_stat_sleep" ,"-e" ,"sched:sched_stat_iowait" ,"-e" ,"sched:sched_stat_runtime" , -"-e" ,"sched:sched_process_exit" ,"-e" ,"sched:sched_process_fork" ,"-e" ,"sched:sched_wakeup" , "-e", "sched:sched_migrate_task",
Signature · 1 line
1.7.10.1
Arnaldo Carvalho de Melo
AppliedRe: [PATCH 04/19] perf sched: Remove sched_process_exit tracepoint
Em Wed, Aug 07, 2013 at 10:50:46PM -0400, David Ahern escreveu:
Quoted 2 lines
Event is not needed nor analyzed. Since perf-sched leverages perf-record to capture the sched data, we already capture task events like EXIT.
Thanks, applied.
tip-bot for David Ahern
merge bot[tip:perf/core] perf sched: Remove sched_process_exit tracepoint
In reply to David Ahernperf sched: Remove sched_process_exit tracepoint
Commit-ID: 4a957e4df1a212c447fd162d18dc7ee6320c1621 Gitweb: http://git.kernel.org/tip/4a957e4df1a212c447fd162d18dc7ee6320c1621 Author: David Ahern <[email protected]> AuthorDate: Wed, 7 Aug 2013 22:50:46 -0400 Committer: Arnaldo Carvalho de Melo <[email protected]> CommitDate: Mon, 12 Aug 2013 10:31:06 -0300
perf sched: Remove sched_process_exit tracepoint
Event is not needed nor analyzed. Since perf-sched leverages perf-record to capture the sched data, we already capture task events like EXIT.
--- tools/perf/builtin-sched.c | 11 ----------- 1 file changed, 11 deletions(-)
tools/perf/builtin-sched.c +0 -11
@@ -1392,15 +1392,6 @@ static int process_sched_fork_event(struct perf_tool *tool,return 0 ; } -static int process_sched_exit_event (struct perf_tool *tool__maybe_unused , -struct perf_evsel *evsel, -struct perf_sample *sample__maybe_unused , -struct machine *machine__maybe_unused ) -{ -pr_debug ("sched_exit event %p\n" , evsel); -return 0 ; -} - static int process_sched_migrate_task_event(struct perf_tool *tool, struct perf_evsel *evsel, struct perf_sample *sample,
@@ -1447,7 +1438,6 @@ static int perf_sched__read_events(struct perf_sched *sched, { "sched:sched_wakeup", process_sched_wakeup_event, }, { "sched:sched_wakeup_new", process_sched_wakeup_event, }, { "sched:sched_process_fork", process_sched_fork_event, }, - { "sched:sched_process_exit", process_sched_exit_event, }, { "sched:sched_migrate_task", process_sched_migrate_task_event, }, };struct perf_session *session;
@@ -1634,7 +1624,6 @@ static int __cmd_record(int argc, const char **argv)"-e" ,"sched:sched_stat_sleep" ,"-e" ,"sched:sched_stat_iowait" ,"-e" ,"sched:sched_stat_runtime" , -"-e" ,"sched:sched_process_exit" ,"-e" ,"sched:sched_process_fork" ,"-e" ,"sched:sched_wakeup" , "-e", "sched:sched_migrate_task",
PATCH 5/19 perf sched: Remove sched_process_fork tracepoint
In reply to David AhernThe PERF_RECORD_FORK event is already collected as part of the use of cmd_record and those events are analyzed as part of the libperf machinery. Using the fork tracepoint as well just duplicates the event load.
--- tools/perf/builtin-sched.c | 60 +++++++++++++++++++++++--------------------- 1 file changed, 31 insertions(+), 29 deletions(-)
tools/perf/builtin-sched.c +31 -29
@@ -109,8 +109,9 @@ struct trace_sched_handler {int (*wakeup_event)(struct perf_sched *sched,struct perf_evsel *evsel,struct perf_sample *sample,struct machine *machine); -int (*fork_event)(struct perf_sched *sched,struct perf_evsel *evsel, -struct perf_sample *sample); +/* PERF_RECORD_FORK event, not sched_process_fork tracepoint */ +int (*fork_event)(struct perf_sched *sched,union perf_event *event, +struct machine *machine); int (*migrate_task_event)(struct perf_sched *sched, struct perf_evsel *evsel,
@@ -717,22 +718,29 @@ static int replay_switch_event(struct perf_sched *sched,return 0 ; } -static int replay_fork_event (struct perf_sched *sched,struct perf_evsel *evsel, -struct perf_sample *sample) +static int replay_fork_event (struct perf_sched *sched, +union perf_event *event, +struct machine *machine) { -const char *parent_comm =perf_evsel__strval (evsel, sample,"parent_comm" ), - *child_comm =perf_evsel__strval (evsel, sample,"child_comm" ); -const u32 parent_pid =perf_evsel__intval (evsel, sample,"parent_pid" ), - child_pid =perf_evsel__intval (evsel, sample,"child_pid" ); +struct thread *child, *parent; + + child =machine__findnew_thread (machine, event->fork.tid); + parent =machine__findnew_thread (machine, event->fork.ptid); + +if (child ==NULL || parent ==NULL ) { +pr_debug ("thread does not exist on fork event: child %p, parent %p\n" , + child, parent); +return 0 ; + }if (verbose) { -printf ("sched_fork event %p\n" , evsel); -printf ("... parent: %s/%d\n" , parent_comm, parent_pid); -printf ("... child: %s/%d\n" , child_comm, child_pid); +printf ("fork event\n" ); +printf ("... parent: %s/%d\n" , parent->comm, parent->tid); +printf ("... child: %s/%d\n" , child->comm, child->tid); } -register_pid (sched, parent_pid, parent_comm); -register_pid (sched, child_pid, child_comm); +register_pid (sched, parent->tid, parent->comm); +register_pid (sched, child->tid, child->comm);return 0 ; }
@@ -824,14 +832,6 @@ static int thread_atoms_insert(struct perf_sched *sched, struct thread *thread)return 0 ; } -static int latency_fork_event (struct perf_sched *sched__maybe_unused , -struct perf_evsel *evsel__maybe_unused , -struct perf_sample *sample__maybe_unused ) -{ -/* should insert the newcomer */ -return 0 ; -} -static char sched_out_state (u64 prev_state) {const char *str =TASK_STATE_TO_CHAR_STR ;
@@ -1379,15 +1379,19 @@ static int process_sched_runtime_event(struct perf_tool *tool,return 0 ; } -static int process_sched_fork_event (struct perf_tool *tool, -struct perf_evsel *evsel, -struct perf_sample *sample, -struct machine *machine__maybe_unused ) +static int perf_sched__process_fork_event (struct perf_tool *tool, +union perf_event *event, +struct perf_sample *sample, +struct machine *machine) { struct perf_sched *sched = container_of(tool, struct perf_sched, tool); +/* run the fork event through the perf machineruy */ +perf_event__process_fork (tool, event, sample, machine); + +/* and then run additional processing needed for this command */ if (sched->tp_handler->fork_event) -return sched->tp_handler->fork_event (sched, evsel, sample); +return sched->tp_handler->fork_event (sched, event, machine);return 0 ; }
@@ -1437,7 +1441,6 @@ static int perf_sched__read_events(struct perf_sched *sched, { "sched:sched_stat_runtime", process_sched_runtime_event, }, { "sched:sched_wakeup", process_sched_wakeup_event, }, { "sched:sched_wakeup_new", process_sched_wakeup_event, }, - { "sched:sched_process_fork", process_sched_fork_event, }, { "sched:sched_migrate_task", process_sched_migrate_task_event, }, };struct perf_session *session;
@@ -1652,7 +1655,7 @@ static struct perf_sched sched = { .sample = perf_sched__process_tracepoint_sample, .comm = perf_event__process_comm, .lost = perf_event__process_lost, - .fork = perf_event__process_fork, + .fork = perf_sched__process_fork_event, .ordered_samples = true, }, .cmp_pid = LIST_HEAD_INIT(sched.cmp_pid),
@@ -1714,7 +1717,6 @@ int cmd_sched(int argc, const char **argv, const char *prefix __maybe_unused) .wakeup_event = latency_wakeup_event, .switch_event = latency_switch_event, .runtime_event = latency_runtime_event, - .fork_event = latency_fork_event, .migrate_task_event = latency_migrate_task_event, };struct trace_sched_handler map_ops = {
Signature · 1 line
1.7.10.1
Arnaldo Carvalho de Melo
AppliedRe: [PATCH 05/19] perf sched: Remove sched_process_fork tracepoint
Em Wed, Aug 07, 2013 at 10:50:47PM -0400, David Ahern escreveu:
Quoted 3 lines
The
PERF_RECORD_FORKevent is already collected as part of the use ofcmd_recordand those events are analyzed as part of the libperf machinery. Using the fork tracepoint as well just duplicates the event load.
Thanks, applied.
tip-bot for David Ahern
merge bot[tip:perf/core] perf sched: Remove sched_process_fork tracepoint
In reply to David Ahernperf sched: Remove sched_process_fork tracepoint
Commit-ID: cb627505ae028a0cd88cc29ed72a4c168a08751d Gitweb: http://git.kernel.org/tip/cb627505ae028a0cd88cc29ed72a4c168a08751d Author: David Ahern <[email protected]> AuthorDate: Wed, 7 Aug 2013 22:50:47 -0400 Committer: Arnaldo Carvalho de Melo <[email protected]> CommitDate: Mon, 12 Aug 2013 10:31:07 -0300
perf sched: Remove sched_process_fork tracepoint
The PERF_RECORD_FORK event is already collected as part of the use of cmd_record and those events are analyzed as part of the libperf machinery. Using the fork tracepoint as well just duplicates the event load.
--- tools/perf/builtin-sched.c | 60 ++++++++++++++++++++++++---------------------- 1 file changed, 31 insertions(+), 29 deletions(-)
tools/perf/builtin-sched.c +31 -29
@@ -109,8 +109,9 @@ struct trace_sched_handler {int (*wakeup_event)(struct perf_sched *sched,struct perf_evsel *evsel,struct perf_sample *sample,struct machine *machine); -int (*fork_event)(struct perf_sched *sched,struct perf_evsel *evsel, -struct perf_sample *sample); +/* PERF_RECORD_FORK event, not sched_process_fork tracepoint */ +int (*fork_event)(struct perf_sched *sched,union perf_event *event, +struct machine *machine); int (*migrate_task_event)(struct perf_sched *sched, struct perf_evsel *evsel,
@@ -717,22 +718,29 @@ static int replay_switch_event(struct perf_sched *sched,return 0 ; } -static int replay_fork_event (struct perf_sched *sched,struct perf_evsel *evsel, -struct perf_sample *sample) +static int replay_fork_event (struct perf_sched *sched, +union perf_event *event, +struct machine *machine) { -const char *parent_comm =perf_evsel__strval (evsel, sample,"parent_comm" ), - *child_comm =perf_evsel__strval (evsel, sample,"child_comm" ); -const u32 parent_pid =perf_evsel__intval (evsel, sample,"parent_pid" ), - child_pid =perf_evsel__intval (evsel, sample,"child_pid" ); +struct thread *child, *parent; + + child =machine__findnew_thread (machine, event->fork.tid); + parent =machine__findnew_thread (machine, event->fork.ptid); + +if (child ==NULL || parent ==NULL ) { +pr_debug ("thread does not exist on fork event: child %p, parent %p\n" , + child, parent); +return 0 ; + }if (verbose) { -printf ("sched_fork event %p\n" , evsel); -printf ("... parent: %s/%d\n" , parent_comm, parent_pid); -printf ("... child: %s/%d\n" , child_comm, child_pid); +printf ("fork event\n" ); +printf ("... parent: %s/%d\n" , parent->comm, parent->tid); +printf ("... child: %s/%d\n" , child->comm, child->tid); } -register_pid (sched, parent_pid, parent_comm); -register_pid (sched, child_pid, child_comm); +register_pid (sched, parent->tid, parent->comm); +register_pid (sched, child->tid, child->comm);return 0 ; }
@@ -824,14 +832,6 @@ static int thread_atoms_insert(struct perf_sched *sched, struct thread *thread)return 0 ; } -static int latency_fork_event (struct perf_sched *sched__maybe_unused , -struct perf_evsel *evsel__maybe_unused , -struct perf_sample *sample__maybe_unused ) -{ -/* should insert the newcomer */ -return 0 ; -} -static char sched_out_state (u64 prev_state) {const char *str =TASK_STATE_TO_CHAR_STR ;
@@ -1379,15 +1379,19 @@ static int process_sched_runtime_event(struct perf_tool *tool,return 0 ; } -static int process_sched_fork_event (struct perf_tool *tool, -struct perf_evsel *evsel, -struct perf_sample *sample, -struct machine *machine__maybe_unused ) +static int perf_sched__process_fork_event (struct perf_tool *tool, +union perf_event *event, +struct perf_sample *sample, +struct machine *machine) { struct perf_sched *sched = container_of(tool, struct perf_sched, tool); +/* run the fork event through the perf machineruy */ +perf_event__process_fork (tool, event, sample, machine); + +/* and then run additional processing needed for this command */ if (sched->tp_handler->fork_event) -return sched->tp_handler->fork_event (sched, evsel, sample); +return sched->tp_handler->fork_event (sched, event, machine);return 0 ; }
@@ -1437,7 +1441,6 @@ static int perf_sched__read_events(struct perf_sched *sched, { "sched:sched_stat_runtime", process_sched_runtime_event, }, { "sched:sched_wakeup", process_sched_wakeup_event, }, { "sched:sched_wakeup_new", process_sched_wakeup_event, }, - { "sched:sched_process_fork", process_sched_fork_event, }, { "sched:sched_migrate_task", process_sched_migrate_task_event, }, };struct perf_session *session;
@@ -1652,7 +1655,7 @@ static struct perf_sched sched = { .sample = perf_sched__process_tracepoint_sample, .comm = perf_event__process_comm, .lost = perf_event__process_lost, - .fork = perf_event__process_fork, + .fork = perf_sched__process_fork_event, .ordered_samples = true, }, .cmp_pid = LIST_HEAD_INIT(sched.cmp_pid),
@@ -1714,7 +1717,6 @@ int cmd_sched(int argc, const char **argv, const char *prefix __maybe_unused) .wakeup_event = latency_wakeup_event, .switch_event = latency_switch_event, .runtime_event = latency_runtime_event, - .fork_event = latency_fork_event, .migrate_task_event = latency_migrate_task_event, };struct trace_sched_handler map_ops = {
PATCH 6/19 perf symbol: Add optimization for idle kernel symbols
In reply to David AhernAvoid walking the list of idle symbols more than once by setting a flag in the symbol struct.
--- tools/perf/util/symbol.c | 44 ++++++++++++++++++++++++++++++++++++++++++++ tools/perf/util/symbol.h | 5 ++++- 2 files changed, 48 insertions(+), 1 deletion(-)
tools/perf/util/symbol.c +44 -0
@@ -509,6 +509,46 @@ static u8 kallsyms2elf_type(char type)return isupper (type) ?STB_GLOBAL :STB_LOCAL ; } +static bool is_idle_sym (const char *name) +{ +static const char *const idle_symbols[] = { +"cpu_idle" , +"intel_idle" , +"default_idle" , +"native_safe_halt" , +"enter_idle" , +"exit_idle" , +"mwait_idle" , +"mwait_idle_with_hints" , +"poll_idle" , +"ppc64_runlatch_off" , +"pseries_dedicated_idle_sleep" , +NULL + }; + +int i; + +for (i =0 ; idle_symbols[i]; i++) { +if (!strcmp (idle_symbols[i], name)) +return true; + } + +return false; +} + +bool symbol__is_idle (struct symbol *sym) +{ +if (!sym) +return false; + +if (!sym->idle_checked) { + sym->is_idle =is_idle_sym (sym->name); + sym->idle_checked = true; + } + +return sym->is_idle; +} +static int map__process_kallsym_symbol (void *arg,const char *name,char type,u64 start) {
@@ -527,6 +567,10 @@ static int map__process_kallsym_symbol(void *arg, const char *name, sym =symbol__new (start,0 ,kallsyms2elf_type (type), name);if (sym ==NULL )return -ENOMEM ; + + sym->is_idle =is_idle_sym (name); + sym->idle_checked = true; +/* * We will pass the symbols to the filter later, in * map__split_kallsyms, when we have split the maps per module
tools/perf/util/symbol.h +4 -1
@@ -59,7 +59,7 @@ static inline char *bfd_demangle(void __maybe_unused *v,/** struct symbol - symtab entry * -* @ignore - resolvable but tools ignore it (e.g. idle routines) +* @ignore - resolvable but perf-top ignores it (e.g. idle routines) */ struct symbol {struct rb_node rb_node;
@@ -68,6 +68,8 @@ struct symbol {u16 namelen;u8 binding;bool ignore; +bool is_idle;/* pertains to kernel symbols only */ +bool idle_checked;char name[0 ]; };
@@ -236,6 +238,7 @@ size_t symbol__fprintf(struct symbol *sym, FILE *fp);bool symbol_type__is_a (char symbol_type,enum map_type map_type);bool symbol__restricted_filename (const char *filename,const char *restricted_filename); +bool symbol__is_idle (struct symbol *sym); int dso__load_sym(struct dso *dso, struct map *map, struct symsrc *syms_ss, struct symsrc *runtime_ss, symbol_filter_t filter,
Signature · 1 line
1.7.10.1
PATCH 7/19 perf top: Use new idle_sym check
In reply to David AhernAvoids strcmp processing each sample.
--- tools/perf/builtin-top.c | 25 ++----------------------- 1 file changed, 2 insertions(+), 23 deletions(-)
tools/perf/builtin-top.c +2 -23
@@ -634,26 +634,9 @@ repeat:return NULL ; } -/* Tag samples to be skipped. */ -static const char *skip_symbols[] = { -"intel_idle" , -"default_idle" , -"native_safe_halt" , -"cpu_idle" , -"enter_idle" , -"exit_idle" , -"mwait_idle" , -"mwait_idle_with_hints" , -"poll_idle" , -"ppc64_runlatch_off" , -"pseries_dedicated_idle_sleep" , -NULL -}; -static int symbol_filter (struct map *map__maybe_unused ,struct symbol *sym) {const char *name = sym->name; -int i;/* * ppc64 uses function descriptors and appends a '.' to the
@@ -671,12 +654,8 @@ static int symbol_filter(struct map *map __maybe_unused, struct symbol *sym) strstr(name, "_text_end"))return 1 ; -for (i =0 ; skip_symbols[i]; i++) { -if (!strcmp (skip_symbols[i], name)) { - sym->ignore = true; -break ; - } - } +if (symbol__is_idle (sym)) + sym->ignore = true;return 0 ; }
Signature · 1 line
1.7.10.1
Re: [PATCH 07/19] perf top: Use new idle_sym check
Em Wed, Aug 07, 2013 at 10:50:49PM -0400, David Ahern escreveu:
Quoted 1 line
Avoids strcmp processing each sample.
How so? This is done just when loading a DSO, when then each symbol is checked against this list.
Tangentially, Frédéric, wasn't there a patchset from you that marks the context of idle samples, in perf_event_header->misc, additiotally to PERF_RECORD_MISC_KERNEL, etc? I think there were some for IRQ context as well, right?
- Arnaldo
Quoted 59 lines
Signed-off-by David Ahern <[email protected]>Cc Ingo Molnar <[email protected]>Cc Jiri Olsa <[email protected]>Cc Namhyung Kim <[email protected]>Cc Frederic Weisbecker <[email protected]>Cc Peter Zijlstra <[email protected]>Cc Stephane Eranian <[email protected]>--- tools/perf/builtin-top.c | 25 ++----------------------- 1 file changed, 2 insertions(+), 23 deletions(-)tools/perf/builtin-top.c +2
-23@@ -634,26 +634,9 @@ repeat:return NULL ; } -/* Tag samples to be skipped. */ -static const char *skip_symbols[] = { -"intel_idle" , -"default_idle" , -"native_safe_halt" , -"cpu_idle" , -"enter_idle" , -"exit_idle" , -"mwait_idle" , -"mwait_idle_with_hints" , -"poll_idle" , -"ppc64_runlatch_off" , -"pseries_dedicated_idle_sleep" , -NULL -}; -static int symbol_filter (struct map *map__maybe_unused ,struct symbol *sym) {const char *name = sym->name; -int i;/* * ppc64 uses function descriptors and appends a '.' to the @@ -671,12 +654,8 @@ static int symbol_filter(struct map *map __maybe_unused, struct symbol *sym) strstr(name, "_text_end"))return 1 ; -for (i =0 ; skip_symbols[i]; i++) { -if (!strcmp (skip_symbols[i], name)) { - sym->ignore = true; -break ; - } - } +if (symbol__is_idle (sym)) + sym->ignore = true;return 0 ; }Signature · 1 line
1.7.10.1
Re: [PATCH 07/19] perf top: Use new idle_sym check
Quoted 5 lines · Arnaldo Carvalho de Melo
Em Wed, Aug 07, 2013 at 10:50:49PM -0400, David Ahern escreveu:
Quoted 1 line
Avoids strcmp processing each sample.
How so? This is done just when loading a DSO, when then each symbol is checked against this list.
hmmm.... see that now, yes. The timehist command wants to know idle times, not just filter them out like perf-top does.
David
Quoted 67 lines
Tangentially, Frédéric, wasn't there a patchset from you that marks the context of idle samples, in
perf_event_header->misc, additiotally toPERF_RECORD_MISC_KERNEL, etc? I think there were some for IRQ context as well, right?- Arnaldo
Quoted 59 lines
Signed-off-by David Ahern <[email protected]>Cc Ingo Molnar <[email protected]>Cc Jiri Olsa <[email protected]>Cc Namhyung Kim <[email protected]>Cc Frederic Weisbecker <[email protected]>Cc Peter Zijlstra <[email protected]>Cc Stephane Eranian <[email protected]>--- tools/perf/builtin-top.c | 25 ++----------------------- 1 file changed, 2 insertions(+), 23 deletions(-)tools/perf/builtin-top.c +2
-24@@ -634,26 +634,9 @@ repeat:return NULL ; } -/* Tag samples to be skipped. */ -static const char *skip_symbols[] = { -"intel_idle" , -"default_idle" , -"native_safe_halt" , -"cpu_idle" , -"enter_idle" , -"exit_idle" , -"mwait_idle" , -"mwait_idle_with_hints" , -"poll_idle" , -"ppc64_runlatch_off" , -"pseries_dedicated_idle_sleep" , -NULL -}; -static int symbol_filter (struct map *map__maybe_unused ,struct symbol *sym) {const char *name = sym->name; -int i;/* * ppc64 uses function descriptors and appends a '.' to the @@ -671,12 +654,8 @@ static int symbol_filter(struct map *map __maybe_unused, struct symbol *sym) strstr(name, "_text_end"))return 1 ; -for (i =0 ; skip_symbols[i]; i++) { -if (!strcmp (skip_symbols[i], name)) { - sym->ignore = true; -break ; - } - } +if (symbol__is_idle (sym)) + sym->ignore = true;return 0 ; } --1.7.10.1
Re: [PATCH 07/19] perf top: Use new idle_sym check
Em Thu, Aug 08, 2013 at 10:49:24PM -0400, David Ahern escreveu:
Quoted 9 lines · Arnaldo Carvalho de Melo
Quoted 5 lines
Em Wed, Aug 07, 2013 at 10:50:49PM -0400, David Ahern escreveu:
Quoted 1 line
Avoids strcmp processing each sample.
How so? This is done just when loading a DSO, when then each symbol is checked against this list.
hmmm.... see that now, yes. The timehist command wants to know idle times, not just filter them out like perf-top does.
'perf top' shouldn't just discard idle symbols, but group them in a special hist_entry, that should be displayed at the top, etc, but this is another issue, what matters here is that it doesn't "filters" in the sense of symbol_filter_t, it returns 0 if the symbol name matches one of the entries in that skip_list, which marks symbol->ignore, but it is still in the rb_tree. Being "discarded" only later, when processing the sample.
The only thing it really filters out are these symtab entries:
if (!strcmp(name, "_text") ||
!strcmp(name, "_etext") ||
!strcmp(name, "_sinittext") ||
!strncmp("init_module", name, 11) ||
!strncmp("cleanup_module", name, 14) ||
strstr(name, "_text_start") ||
strstr(name, "_text_end"))
return 1;Those I think could be pruned somehow in dso__load_{kallsyms|kernel}*(), like some other symbols are already (SyS_).
With this in mind, would using the same scheme Ok for you?
- Arnaldo
PATCH 8/19 perf symbol: Save vmlinux or kallsyms path loaded
In reply to David AhernSave vmlinux or kallsyms path loaded using embedded default lookup (ie., not a user specified path). Upcoming perf sched timehist command requires kernel symbols for properly computing idle times and prints a warning if the kernel symbols are not loaded.
--- tools/perf/util/symbol.c | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-)
tools/perf/util/symbol.c +6 -1
@@ -1192,6 +1192,8 @@ int dso__load_vmlinux(struct dso *dso, struct map *map, dso->data_type =DSO_BINARY_TYPE__VMLINUX ;dso__set_long_name (dso, (char *)vmlinux);dso__set_loaded (dso, map->type); +if (symbol_conf.vmlinux_name ==NULL ) + symbol_conf.vmlinux_name =strdup (symfs_vmlinux);pr_debug ("Using %s for symbols\n" , symfs_vmlinux); }
@@ -1325,8 +1327,11 @@ static int dso__load_kernel_sym(struct dso *dso, struct map *map, do_kallsyms: err =dso__load_kallsyms (dso, kallsyms_filename, map, filter); -if (err >0 ) +if (err >0 ) { +if (symbol_conf.kallsyms_name ==NULL ) + symbol_conf.kallsyms_name =strdup (kallsyms_filename);pr_debug ("Using %s for symbols\n" , kallsyms_filename); + }free (kallsyms_allocated_filename);if (err >0 && !dso__is_kcore (dso)) {
Signature · 1 line
1.7.10.1
Re: [PATCH 08/19] perf symbol: Save vmlinux or kallsyms path loaded
Em Wed, Aug 07, 2013 at 10:50:50PM -0400, David Ahern escreveu:
Quoted 4 lines
Save vmlinux or kallsyms path loaded using embedded default lookup (ie., not a user specified path). Upcoming perf sched timehist command requires kernel symbols for properly computing idle times and prints a warning if the kernel symbols are not loaded.
With this we will not know if the user passed something to set those variables or if internally we did it, doesn't this break any existing code assumption?
- Arnaldo
Quoted 39 lines
Signed-off-by David Ahern <[email protected]>Cc Ingo Molnar <[email protected]>Cc Jiri Olsa <[email protected]>Cc Namhyung Kim <[email protected]>Cc Frederic Weisbecker <[email protected]>Cc Peter Zijlstra <[email protected]>Cc Stephane Eranian <[email protected]>--- tools/perf/util/symbol.c | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-)tools/perf/util/symbol.c +6
-1@@ -1192,6 +1192,8 @@ int dso__load_vmlinux(struct dso *dso, struct map *map, dso->data_type =DSO_BINARY_TYPE__VMLINUX ;dso__set_long_name (dso, (char *)vmlinux);dso__set_loaded (dso, map->type); +if (symbol_conf.vmlinux_name ==NULL ) + symbol_conf.vmlinux_name =strdup (symfs_vmlinux);pr_debug ("Using %s for symbols\n" , symfs_vmlinux); }@@ -1325,8 +1327,11 @@ static int dso__load_kernel_sym(struct dso *dso, struct map *map, do_kallsyms: err =dso__load_kallsyms (dso, kallsyms_filename, map, filter); -if (err >0 ) +if (err >0 ) { +if (symbol_conf.kallsyms_name ==NULL ) + symbol_conf.kallsyms_name =strdup (kallsyms_filename);pr_debug ("Using %s for symbols\n" , kallsyms_filename); + }free (kallsyms_allocated_filename);if (err >0 && !dso__is_kcore (dso)) {Signature · 1 line
1.7.10.1
Re: [PATCH 08/19] perf symbol: Save vmlinux or kallsyms path loaded
Quoted 9 lines · Arnaldo Carvalho de Melo
Em Wed, Aug 07, 2013 at 10:50:50PM -0400, David Ahern escreveu:
Quoted 4 lines
Save vmlinux or kallsyms path loaded using embedded default lookup (ie., not a user specified path). Upcoming perf sched timehist command requires kernel symbols for properly computing idle times and prints a warning if the kernel symbols are not loaded.
With this we will not know if the user passed something to set those variables or if internally we did it, doesn't this break any existing code assumption?
I believe this only affects code paths that go to default locations.
I am not aware of any code that looks at the path once the syms are loaded. AFAIK the timehist command is the first.
David
PATCH 9/19 perf tool: Simplify options to perf_evsel__print_ip
In reply to David AhernMake print options based on flags. Simplifies addition of more print options which is the subject of upcoming patches.
--- tools/perf/builtin-script.c | 27 +++++++++++++++++++++++---- tools/perf/util/session.c | 14 +++++++++++--- tools/perf/util/session.h | 7 ++++++- 3 files changed, 40 insertions(+), 8 deletions(-)
tools/perf/builtin-script.c +23 -4
@@ -66,6 +66,7 @@ struct output_option {static struct {bool user_set;bool wildcard_set; +unsigned int print_ip_opts;u64 fields;u64 invalid_fields; } output[PERF_TYPE_MAX ] = {
@@ -235,6 +236,7 @@ static int perf_session__check_output_opt(struct perf_session *session) {int j;struct perf_evsel *evsel; +struct perf_event_attr *attr;for (j =0 ; j <PERF_TYPE_MAX ; ++j) { evsel =perf_session__find_first_evtype (session, j);
@@ -253,6 +255,24 @@ static int perf_session__check_output_opt(struct perf_session *session)if (evsel && output[j].fields &&perf_evsel__check_attr (evsel, session))return -1 ; + +if (evsel ==NULL ) +continue ; + + attr = &evsel->attr; + + output[j].print_ip_opts =0 ; +if (PRINT_FIELD (IP )) + output[j].print_ip_opts |=PRINT_IP_OPT_IP ; + +if (PRINT_FIELD (SYM )) + output[j].print_ip_opts |=PRINT_IP_OPT_SYM ; + +if (PRINT_FIELD (DSO )) + output[j].print_ip_opts |=PRINT_IP_OPT_DSO ; + +if (PRINT_FIELD (SYMOFFSET )) + output[j].print_ip_opts |=PRINT_IP_OPT_SYMOFFSET ; }return 0 ;
@@ -382,8 +402,7 @@ static void print_sample_bts(union perf_event *event,else printf ("\n" );perf_evsel__print_ip (evsel, event, sample, machine, -PRINT_FIELD (SYM ),PRINT_FIELD (DSO ), -PRINT_FIELD (SYMOFFSET )); + output[attr->type].print_ip_opts); }printf (" => " );
@@ -423,9 +442,9 @@ static void process_event(union perf_event *event, struct perf_sample *sample,printf (" " ); else printf("\n"); +perf_evsel__print_ip (evsel, event, sample, machine, -PRINT_FIELD (SYM ),PRINT_FIELD (DSO ), -PRINT_FIELD (SYMOFFSET )); + output[attr->type].print_ip_opts); }printf ("\n" );
tools/perf/util/session.c +11 -3
@@ -1489,10 +1489,14 @@ struct perf_evsel *perf_session__find_first_evtype(struct perf_session *session,void perf_evsel__print_ip (struct perf_evsel *evsel,union perf_event *event,struct perf_sample *sample,struct machine *machine, -int print_sym,int print_dso,int print_symoffset) +unsigned int print_opts) {struct addr_location al;struct callchain_cursor_node *node; +int print_ip = print_opts &PRINT_IP_OPT_IP ; +int print_sym = print_opts &PRINT_IP_OPT_SYM ; +int print_dso = print_opts &PRINT_IP_OPT_DSO ; +int print_symoffset = print_opts &PRINT_IP_OPT_SYMOFFSET ;if (perf_event__preprocess_sample (event, machine, &al, sample,NULL ) <0 ) {
@@ -1516,7 +1520,9 @@ void perf_evsel__print_ip(struct perf_evsel *evsel, union perf_event *event,if (!node)break ; -printf ("\t%16" PRIx64, node->ip); +if (print_ip) +printf ("%16" PRIx64, node->ip); +if (print_sym) {printf (" " );if (print_symoffset) {
@@ -1537,7 +1543,9 @@ void perf_evsel__print_ip(struct perf_evsel *evsel, union perf_event *event, } }else { -printf ("%16" PRIx64, sample->ip); +if (print_ip) +printf ("%16" PRIx64, sample->ip); +if (print_sym) {printf (" " );if (print_symoffset)
tools/perf/util/session.h +6 -1
@@ -41,6 +41,11 @@ struct perf_session {char filename[1 ]; }; +#define PRINT_IP_OPT_IP (1<<0) +#define PRINT_IP_OPT_SYM (1<<1) +#define PRINT_IP_OPT_DSO (1<<2) +#define PRINT_IP_OPT_SYMOFFSET (1<<3) +struct perf_tool ; struct perf_session *perf_session__new(const char *filename, int mode,
@@ -103,7 +108,7 @@ struct perf_evsel *perf_session__find_first_evtype(struct perf_session *session,void perf_evsel__print_ip (struct perf_evsel *evsel,union perf_event *event,struct perf_sample *sample,struct machine *machine, -int print_sym,int print_dso,int print_symoffset); +unsigned int print_opts);int perf_session__cpu_bitmap (struct perf_session *session,const char *cpu_list,unsigned long *cpu_bitmap);
Signature · 1 line
1.7.10.1
Arnaldo Carvalho de Melo
AppliedRe: [PATCH 09/19] perf tool: Simplify options to perf_evsel__print_ip
Em Wed, Aug 07, 2013 at 10:50:51PM -0400, David Ahern escreveu:
Quoted 2 lines
Make print options based on flags. Simplifies addition of more print options which is the subject of upcoming patches.
Thanks, applied.
tip-bot for David Ahern
merge bot[tip:perf/core] perf tool: Simplify options to perf_evsel__print_ip
In reply to David Ahernperf tool: Simplify options to perf_evsel__print_ip
Commit-ID: a6ffaf91302dc1689fc72da0068b87226747fbe0 Gitweb: http://git.kernel.org/tip/a6ffaf91302dc1689fc72da0068b87226747fbe0 Author: David Ahern <[email protected]> AuthorDate: Wed, 7 Aug 2013 22:50:51 -0400 Committer: Arnaldo Carvalho de Melo <[email protected]> CommitDate: Mon, 12 Aug 2013 10:31:07 -0300
perf tool: Simplify options to perf_evsel__print_ip
Make print options based on flags. Simplifies addition of more print options which is the subject of upcoming patches.
--- tools/perf/builtin-script.c | 27 +++++++++++++++++++++++---- tools/perf/util/session.c | 14 +++++++++++--- tools/perf/util/session.h | 7 ++++++- 3 files changed, 40 insertions(+), 8 deletions(-)
tools/perf/builtin-script.c +23 -4
@@ -66,6 +66,7 @@ struct output_option {static struct {bool user_set;bool wildcard_set; +unsigned int print_ip_opts;u64 fields;u64 invalid_fields; } output[PERF_TYPE_MAX ] = {
@@ -235,6 +236,7 @@ static int perf_session__check_output_opt(struct perf_session *session) {int j;struct perf_evsel *evsel; +struct perf_event_attr *attr;for (j =0 ; j <PERF_TYPE_MAX ; ++j) { evsel =perf_session__find_first_evtype (session, j);
@@ -253,6 +255,24 @@ static int perf_session__check_output_opt(struct perf_session *session)if (evsel && output[j].fields &&perf_evsel__check_attr (evsel, session))return -1 ; + +if (evsel ==NULL ) +continue ; + + attr = &evsel->attr; + + output[j].print_ip_opts =0 ; +if (PRINT_FIELD (IP )) + output[j].print_ip_opts |=PRINT_IP_OPT_IP ; + +if (PRINT_FIELD (SYM )) + output[j].print_ip_opts |=PRINT_IP_OPT_SYM ; + +if (PRINT_FIELD (DSO )) + output[j].print_ip_opts |=PRINT_IP_OPT_DSO ; + +if (PRINT_FIELD (SYMOFFSET )) + output[j].print_ip_opts |=PRINT_IP_OPT_SYMOFFSET ; }return 0 ;
@@ -382,8 +402,7 @@ static void print_sample_bts(union perf_event *event,else printf ("\n" );perf_evsel__print_ip (evsel, event, sample, machine, -PRINT_FIELD (SYM ),PRINT_FIELD (DSO ), -PRINT_FIELD (SYMOFFSET )); + output[attr->type].print_ip_opts); }printf (" => " );
@@ -423,9 +442,9 @@ static void process_event(union perf_event *event, struct perf_sample *sample,printf (" " ); else printf("\n"); +perf_evsel__print_ip (evsel, event, sample, machine, -PRINT_FIELD (SYM ),PRINT_FIELD (DSO ), -PRINT_FIELD (SYMOFFSET )); + output[attr->type].print_ip_opts); }printf ("\n" );
tools/perf/util/session.c +11 -3
@@ -1489,10 +1489,14 @@ struct perf_evsel *perf_session__find_first_evtype(struct perf_session *session,void perf_evsel__print_ip (struct perf_evsel *evsel,union perf_event *event,struct perf_sample *sample,struct machine *machine, -int print_sym,int print_dso,int print_symoffset) +unsigned int print_opts) {struct addr_location al;struct callchain_cursor_node *node; +int print_ip = print_opts &PRINT_IP_OPT_IP ; +int print_sym = print_opts &PRINT_IP_OPT_SYM ; +int print_dso = print_opts &PRINT_IP_OPT_DSO ; +int print_symoffset = print_opts &PRINT_IP_OPT_SYMOFFSET ;if (perf_event__preprocess_sample (event, machine, &al, sample,NULL ) <0 ) {
@@ -1516,7 +1520,9 @@ void perf_evsel__print_ip(struct perf_evsel *evsel, union perf_event *event,if (!node)break ; -printf ("\t%16" PRIx64, node->ip); +if (print_ip) +printf ("%16" PRIx64, node->ip); +if (print_sym) {printf (" " );if (print_symoffset) {
@@ -1537,7 +1543,9 @@ void perf_evsel__print_ip(struct perf_evsel *evsel, union perf_event *event, } }else { -printf ("%16" PRIx64, sample->ip); +if (print_ip) +printf ("%16" PRIx64, sample->ip); +if (print_sym) {printf (" " );if (print_symoffset)
tools/perf/util/session.h +6 -1
@@ -41,6 +41,11 @@ struct perf_session {char filename[1 ]; }; +#define PRINT_IP_OPT_IP (1<<0) +#define PRINT_IP_OPT_SYM (1<<1) +#define PRINT_IP_OPT_DSO (1<<2) +#define PRINT_IP_OPT_SYMOFFSET (1<<3) +struct perf_tool ; struct perf_session *perf_session__new(const char *filename, int mode,
@@ -103,7 +108,7 @@ struct perf_evsel *perf_session__find_first_evtype(struct perf_session *session,void perf_evsel__print_ip (struct perf_evsel *evsel,union perf_event *event,struct perf_sample *sample,struct machine *machine, -int print_sym,int print_dso,int print_symoffset); +unsigned int print_opts);int perf_session__cpu_bitmap (struct perf_session *session,const char *cpu_list,unsigned long *cpu_bitmap);
PATCH 10/19 perf tool: Add option to print stack trace on single line
In reply to David AhernOption is used by upcoming timehist command.
--- tools/perf/util/session.c | 8 ++++++-- tools/perf/util/session.h | 1 + 2 files changed, 7 insertions(+), 2 deletions(-)
tools/perf/util/session.c +6 -2
@@ -1497,6 +1497,8 @@ void perf_evsel__print_ip(struct perf_evsel *evsel, union perf_event *event,int print_sym = print_opts &PRINT_IP_OPT_SYM ;int print_dso = print_opts &PRINT_IP_OPT_DSO ;int print_symoffset = print_opts &PRINT_IP_OPT_SYMOFFSET ; +int print_oneline = print_opts &PRINT_IP_OPT_ONELINE ; +char s = print_oneline ?' ' :'\t' ;if (perf_event__preprocess_sample (event, machine, &al, sample,NULL ) <0 ) {
@@ -1521,7 +1523,7 @@ void perf_evsel__print_ip(struct perf_evsel *evsel, union perf_event *event,break ;if (print_ip) -printf ("%16" PRIx64, node->ip); +printf ("%c%16" PRIx64, s, node->ip);if (print_sym) {printf (" " );
@@ -1537,7 +1539,9 @@ void perf_evsel__print_ip(struct perf_evsel *evsel, union perf_event *event,map__fprintf_dsoname (node->map, stdout);printf (")" ); } -printf ("\n" ); + +if (!print_oneline) +printf ("\n" );callchain_cursor_advance (&callchain_cursor); }
tools/perf/util/session.h +1 -0
@@ -45,6 +45,7 @@ struct perf_session {#define PRINT_IP_OPT_SYM (1<<1)#define PRINT_IP_OPT_DSO (1<<2)#define PRINT_IP_OPT_SYMOFFSET (1<<3) +#define PRINT_IP_OPT_ONELINE (1<<4)struct perf_tool ;
Signature · 1 line
1.7.10.1
tip-bot for David Ahern
merge bot[tip:perf/core] perf evsel: Add option to print stack trace on single line
perf evsel: Add option to print stack trace on single line
Commit-ID: b0b35f0179161a5e256eebffa274b0b6f023f451 Gitweb: http://git.kernel.org/tip/b0b35f0179161a5e256eebffa274b0b6f023f451 Author: David Ahern <[email protected]> AuthorDate: Wed, 7 Aug 2013 22:50:52 -0400 Committer: Arnaldo Carvalho de Melo <[email protected]> CommitDate: Mon, 12 Aug 2013 10:31:08 -0300
perf evsel: Add option to print stack trace on single line
Option is used by upcoming timehist command.
--- tools/perf/util/session.c | 8 ++++++-- tools/perf/util/session.h | 1 + 2 files changed, 7 insertions(+), 2 deletions(-)
tools/perf/util/session.c +6 -2
@@ -1497,6 +1497,8 @@ void perf_evsel__print_ip(struct perf_evsel *evsel, union perf_event *event,int print_sym = print_opts &PRINT_IP_OPT_SYM ;int print_dso = print_opts &PRINT_IP_OPT_DSO ;int print_symoffset = print_opts &PRINT_IP_OPT_SYMOFFSET ; +int print_oneline = print_opts &PRINT_IP_OPT_ONELINE ; +char s = print_oneline ?' ' :'\t' ;if (perf_event__preprocess_sample (event, machine, &al, sample,NULL ) <0 ) {
@@ -1521,7 +1523,7 @@ void perf_evsel__print_ip(struct perf_evsel *evsel, union perf_event *event,break ;if (print_ip) -printf ("%16" PRIx64, node->ip); +printf ("%c%16" PRIx64, s, node->ip);if (print_sym) {printf (" " );
@@ -1537,7 +1539,9 @@ void perf_evsel__print_ip(struct perf_evsel *evsel, union perf_event *event,map__fprintf_dsoname (node->map, stdout);printf (")" ); } -printf ("\n" ); + +if (!print_oneline) +printf ("\n" );callchain_cursor_advance (&callchain_cursor); }
tools/perf/util/session.h +1 -0
@@ -45,6 +45,7 @@ struct perf_session {#define PRINT_IP_OPT_SYM (1<<1)#define PRINT_IP_OPT_DSO (1<<2)#define PRINT_IP_OPT_SYMOFFSET (1<<3) +#define PRINT_IP_OPT_ONELINE (1<<4)struct perf_tool ;
PATCH 11/19 perf tool: Add option to limit stack depth in callchain dumps
In reply to David AhernOption is used by upcoming timehist command.
--- tools/perf/builtin-script.c | 6 ++++-- tools/perf/util/session.c | 6 ++++-- tools/perf/util/session.h | 2 +- 3 files changed, 9 insertions(+), 5 deletions(-)
tools/perf/builtin-script.c +4 -2
@@ -402,7 +402,8 @@ static void print_sample_bts(union perf_event *event,else printf ("\n" );perf_evsel__print_ip (evsel, event, sample, machine, - output[attr->type].print_ip_opts); + output[attr->type].print_ip_opts, +PERF_MAX_STACK_DEPTH ); }printf (" => " );
@@ -444,7 +445,8 @@ static void process_event(union perf_event *event, struct perf_sample *sample,printf ("\n" );perf_evsel__print_ip (evsel, event, sample, machine, - output[attr->type].print_ip_opts); + output[attr->type].print_ip_opts, +PERF_MAX_STACK_DEPTH ); }printf ("\n" );
tools/perf/util/session.c +4 -2
@@ -1489,7 +1489,7 @@ struct perf_evsel *perf_session__find_first_evtype(struct perf_session *session,void perf_evsel__print_ip (struct perf_evsel *evsel,union perf_event *event,struct perf_sample *sample,struct machine *machine, -unsigned int print_opts) +unsigned int print_opts,unsigned int stack_depth) {struct addr_location al;struct callchain_cursor_node *node;
@@ -1517,7 +1517,7 @@ void perf_evsel__print_ip(struct perf_evsel *evsel, union perf_event *event, }callchain_cursor_commit (&callchain_cursor); -while (1 ) { +while (stack_depth) { node =callchain_cursor_current (&callchain_cursor);if (!node)break ;
@@ -1544,6 +1544,8 @@ void perf_evsel__print_ip(struct perf_evsel *evsel, union perf_event *event,printf ("\n" );callchain_cursor_advance (&callchain_cursor); + + stack_depth--; } }else {
tools/perf/util/session.h +1 -1
@@ -109,7 +109,7 @@ struct perf_evsel *perf_session__find_first_evtype(struct perf_session *session,void perf_evsel__print_ip (struct perf_evsel *evsel,union perf_event *event,struct perf_sample *sample,struct machine *machine, -unsigned int print_opts); +unsigned int print_opts,unsigned int stack_depth);int perf_session__cpu_bitmap (struct perf_session *session,const char *cpu_list,unsigned long *cpu_bitmap);
Signature · 1 line
1.7.10.1
tip-bot for David Ahern
merge bot[tip:perf/core] perf evsel: Add option to limit stack depth in callchain dumps
perf evsel: Add option to limit stack depth in callchain dumps
Commit-ID: 307cbb92aa2bdc9eed7c74409ff4d5fc9135b4e2 Gitweb: http://git.kernel.org/tip/307cbb92aa2bdc9eed7c74409ff4d5fc9135b4e2 Author: David Ahern <[email protected]> AuthorDate: Wed, 7 Aug 2013 22:50:53 -0400 Committer: Arnaldo Carvalho de Melo <[email protected]> CommitDate: Mon, 12 Aug 2013 10:31:08 -0300
perf evsel: Add option to limit stack depth in callchain dumps
Option is used by upcoming timehist command.
--- tools/perf/builtin-script.c | 6 ++++-- tools/perf/util/session.c | 6 ++++-- tools/perf/util/session.h | 2 +- 3 files changed, 9 insertions(+), 5 deletions(-)
tools/perf/builtin-script.c +4 -2
@@ -402,7 +402,8 @@ static void print_sample_bts(union perf_event *event,else printf ("\n" );perf_evsel__print_ip (evsel, event, sample, machine, - output[attr->type].print_ip_opts); + output[attr->type].print_ip_opts, +PERF_MAX_STACK_DEPTH ); }printf (" => " );
@@ -444,7 +445,8 @@ static void process_event(union perf_event *event, struct perf_sample *sample,printf ("\n" );perf_evsel__print_ip (evsel, event, sample, machine, - output[attr->type].print_ip_opts); + output[attr->type].print_ip_opts, +PERF_MAX_STACK_DEPTH ); }printf ("\n" );
tools/perf/util/session.c +4 -2
@@ -1489,7 +1489,7 @@ struct perf_evsel *perf_session__find_first_evtype(struct perf_session *session,void perf_evsel__print_ip (struct perf_evsel *evsel,union perf_event *event,struct perf_sample *sample,struct machine *machine, -unsigned int print_opts) +unsigned int print_opts,unsigned int stack_depth) {struct addr_location al;struct callchain_cursor_node *node;
@@ -1517,7 +1517,7 @@ void perf_evsel__print_ip(struct perf_evsel *evsel, union perf_event *event, }callchain_cursor_commit (&callchain_cursor); -while (1 ) { +while (stack_depth) { node =callchain_cursor_current (&callchain_cursor);if (!node)break ;
@@ -1544,6 +1544,8 @@ void perf_evsel__print_ip(struct perf_evsel *evsel, union perf_event *event,printf ("\n" );callchain_cursor_advance (&callchain_cursor); + + stack_depth--; } }else {
tools/perf/util/session.h +1 -1
@@ -109,7 +109,7 @@ struct perf_evsel *perf_session__find_first_evtype(struct perf_session *session,void perf_evsel__print_ip (struct perf_evsel *evsel,union perf_event *event,struct perf_sample *sample,struct machine *machine, -unsigned int print_opts); +unsigned int print_opts,unsigned int stack_depth);int perf_session__cpu_bitmap (struct perf_session *session,const char *cpu_list,unsigned long *cpu_bitmap);
PATCH 12/19 perf tool: Add support for exclude symbol list to symbol_conf
In reply to David AhernAllows user to specify a list of symbols not interested in. One use case is the upcoming timehist command.
--- tools/perf/util/symbol.c | 20 ++++++++++++++++++++ tools/perf/util/symbol.h | 3 +++ 2 files changed, 23 insertions(+)
tools/perf/util/symbol.c +20 -0
@@ -549,6 +549,18 @@ bool symbol__is_idle(struct symbol *sym)return sym->is_idle; } +bool symbol__is_excluded (struct symbol *sym) +{ +if (sym ==NULL ) +return false; + +if (symbol_conf.excl_sym_list && +strlist__has_entry (symbol_conf.excl_sym_list, sym->name)) +return true; + +return false; +} +static int map__process_kallsym_symbol (void *arg,const char *name,char type,u64 start) {
@@ -1518,6 +1530,10 @@ int symbol__init(void) symbol_conf.sym_list_str, "symbol") < 0) goto out_free_comm_list; +if (setup_list (&symbol_conf.excl_sym_list, + symbol_conf.excl_sym_list_str,"exclude symbol" ) <0 ) + goto out_free_sym_list; +/* * A path to symbols of "/" is identical to "" * reset here for simplicity.
@@ -1535,6 +1551,8 @@ int symbol__init(void) symbol_conf.initialized = true;return 0 ; +out_free_sym_list: +strlist__delete (symbol_conf.sym_list); out_free_comm_list:strlist__delete (symbol_conf.comm_list); out_free_dso_list:
@@ -1546,10 +1564,12 @@ void symbol__exit(void) {if (!symbol_conf.initialized)return ; +strlist__delete (symbol_conf.excl_sym_list);strlist__delete (symbol_conf.sym_list);strlist__delete (symbol_conf.dso_list);strlist__delete (symbol_conf.comm_list);vmlinux_path__exit (); + symbol_conf.excl_sym_list =NULL ; symbol_conf.sym_list = symbol_conf.dso_list = symbol_conf.comm_list =NULL ; symbol_conf.initialized = false; }
tools/perf/util/symbol.h +3 -0
@@ -112,10 +112,12 @@ struct symbol_conf {const char *dso_list_str, *comm_list_str, *sym_list_str, + *excl_sym_list_str, *col_width_list_str;struct strlist *dso_list, *comm_list, *sym_list, + *excl_sym_list, *dso_from_list, *dso_to_list, *sym_from_list,
@@ -239,6 +241,7 @@ bool symbol_type__is_a(char symbol_type, enum map_type map_type);bool symbol__restricted_filename (const char *filename,const char *restricted_filename);bool symbol__is_idle (struct symbol *sym); +bool symbol__is_excluded (struct symbol *sym); int dso__load_sym(struct dso *dso, struct map *map, struct symsrc *syms_ss, struct symsrc *runtime_ss, symbol_filter_t filter,
Signature · 1 line
1.7.10.1
PATCH 13/19 perf tool: Skip symbols in exclude list while printing callchain
In reply to David AhernLeverage new exclude symbol list to allow user to not see certain functions in a backtrace. For example repeating patterns like:
do_select core_sys_select sys_select
can be reduced to just sys_select when dumping callchains, consuming less real estate on the screen while still conveying the essential message - the process is in a select call.
--- tools/perf/util/session.c | 8 ++++++-- 1 file changed, 6 insertions(+), 2 deletions(-)
tools/perf/util/session.c +6 -2
@@ -1522,6 +1522,9 @@ void perf_evsel__print_ip(struct perf_evsel *evsel, union perf_event *event,if (!node)break ; +if (symbol__is_excluded (node->sym)) + goto next; +if (print_ip)printf ("%c%16" PRIx64, s, node->ip);
@@ -1543,9 +1546,10 @@ void perf_evsel__print_ip(struct perf_evsel *evsel, union perf_event *event,if (!print_oneline)printf ("\n" ); -callchain_cursor_advance (&callchain_cursor); - stack_depth--; + +next: +callchain_cursor_advance (&callchain_cursor); } }else {
Signature · 1 line
1.7.10.1
PATCH 14/19 perf sched: pass event to evsel handlers using data element
In reply to David AhernUpcoming timehist command needs access to the event. Use the existing handler.data element to do that.
--- tools/perf/builtin-sched.c | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-)
tools/perf/builtin-sched.c +2 -1
@@ -1415,7 +1415,7 @@ typedef int (*tracepoint_handler)(struct perf_tool *tool, struct machine *machine);static int perf_sched__process_tracepoint_sample (struct perf_tool *tool__maybe_unused , -union perf_event *event__maybe_unused , +union perf_event *event,struct perf_sample *sample,struct perf_evsel *evsel,struct machine *machine)
@@ -1427,6 +1427,7 @@ static int perf_sched__process_tracepoint_sample(struct perf_tool *tool __maybe_if (evsel->handler.func !=NULL ) {tracepoint_handler f = evsel->handler.func; + evsel->handler.data = event; err =f (tool, evsel, sample, machine); }
Signature · 1 line
1.7.10.1
PATCH 15/19 perf sched: Add timehist command
In reply to David AhernBy default 'perf sched timehist' dumps a run-time summary for each task. The summary includes the number of times the process was scheduled and the min, max and average run times when scheduled (ie., a measure of how CPU time the task wanted). Summary of idle times per cpu is also shown.
Example output (abbreviated):
Runtime summary (times are in seconds)
comm parent number run-time min-run max-run avg-run stddev(%)
...
make[12858] 12823 2 0.000826 0.000063 0.000763 0.000413 84.74
make[12859] 12823 4 0.002706 0.000026 0.001368 0.000676 40.83
make[12860] 12823 3 0.002703 0.000026 0.001941 0.000901 62.01
make[12861] 12823 2 0.000863 0.000061 0.000801 0.000431 85.64
qemu-kvm[14716] -1 207 0.009341 0.000021 0.000187 0.000045 3.19
qemu-kvm[14720/14716] -1 146 0.005790 0.000011 0.000105 0.000039 3.84
qemu-kvm[14721/14716] -1 102 0.002717 0.000014 0.000068 0.000026 2.44
qemu-kvm[29548/29541] -1 10 0.089883 0.000000 0.009992 0.008988 11.11...
Idle stats:
CPU 0 idle for 0.096720
CPU 2 idle for 0.096138
CPU 4 idle for 0.084509
CPU 6 idle for 0.092162
CPU 8 idle for 0.069825
CPU 10 idle for 0.057123
CPU 12 idle for 0.087755
CPU 14 idle for 0.075491 Total number of unique tasks: 66
Total number of context switches: 1631
Total run time (sec): 0.204370
Individual sched_switch events can be dumped using the --events option. Output includes N elements of the stack trace on one line with options to control stack depth as well as exclude elements of stack dump to get more relevant information onto each line:
447399.732590 [14] make[12858] 0.000000 0.000063 __cond_resched _cond_resched wait_for_completion stop_one_cpu sched_exec 447399.732608 [08] <idle> 0.002126 0.001472 schedule_preempt_disabled cpu_startup_entry start_secondary 447399.732610 [14] migration/14[79] 0.003583 0.000019 smpboot_thread_fn kthread ret_from_fork 447399.732611 [06] qemu-kvm[14716] 0.000592 0.000073 poll_schedule_timeout do_select core_sys_select SyS_select system_call 447399.732623 [02] <idle> 0.000059 0.000965 schedule_preempt_disabled cpu_startup_entry start_secondary 447399.732627 [00] <idle> 0.000048 0.000054 schedule_preempt_disabled cpu_startup_entry rest_init start_kernel x86_64_start_reservations 447399.732658 [00] qemu-kvm[14721/14716] 0.000975 0.000030 kvm_vcpu_block kvm_arch_vcpu_ioctl_run kvm_vcpu_ioctl do_vfs_ioctl sys_ioctl 447399.732671 [02] qemu-kvm[14720/14716] 0.000965 0.000047 kvm_vcpu_block kvm_arch_vcpu_ioctl_run kvm_vcpu_ioctl do_vfs_ioctl sys_ioctl 447399.732686 [04] <idle> 0.000133 0.000172 schedule_preempt_disabled cpu_startup_entry start_secondary 447399.732700 [04] perf[12823] 0.000172 0.000013 do_wait SyS_wait4 system_call __libc_wait
Options include the usual report controls for kernel symbols, symfs, limiting output to command names of interest.
--- tools/perf/builtin-sched.c | 722 +++++++++++++++++++++++++++++++++++++++++++- 1 file changed, 721 insertions(+), 1 deletion(-)
tools/perf/builtin-sched.c +721 -1
@@ -16,6 +16,8 @@#include "util/debug.h" +#include "util/strlist.h" +#include "asm/bug.h" #include <sys/prctl.h> #include <sys/resource.h>
@@ -169,8 +171,39 @@ struct perf_sched {u64 cpu_last_switched[MAX_CPUS ];struct rb_root atom_root, sorted_atom_root;struct list_head sort_list, cmp_pid; + +/* options for timehist command */ +bool show_events; +bool no_callchain; +unsigned int max_stack_depth; +bool show_cpu_visual; +}; + +/* per thread run time data */ +struct thread_runtime { +u64 dt_run; +u64 dt_between; +u64 last_time; + +u64 count; +u64 total_run_time; +u64 min_run_time; +u64 max_run_time; +double mean, M2; +char commstr[32 ]; +}; + +/* per event run time data */ +struct evsel_runtime { +u64 *last_time;/* time this event was last seen per cpu */ +u32 ncpu;/* highest cpu slot allocated */ }; +/* track idle times per cpu */ +static struct thread **idle_threads; +static int idle_max_cpu; +static char idle_comm[] ="<idle>" ; +static u64 get_nsecs (void ) {struct timespec ts;
@@ -1479,6 +1512,652 @@ out_delete:return -1 ; } +static inline void printf_nsecs (unsigned long long nsecs,int width_sec) +{ +unsigned long secs; +unsigned long usecs; + + secs = nsecs /NSECS_PER_SEC ; + nsecs -= secs *NSECS_PER_SEC ; + usecs = nsecs /NSECS_PER_USEC ; +printf ("%*lu.%06lu " , width_sec, secs, usecs); +} + +static struct evsel_runtime *perf_evsel__get_runtime (struct perf_evsel *evsel) +{ +struct evsel_runtime *r = evsel->priv; + +if (r ==NULL ) { + r =zalloc (sizeof (struct evsel_runtime )); + evsel->priv = r; + } + +return r; +} + +static void perf_evsel__save_time (struct perf_evsel *evsel, +u64 timestamp,u32 cpu) +{ +struct evsel_runtime *r =perf_evsel__get_runtime (evsel); + +if (r ==NULL ) +return ; + +if ((cpu > r->ncpu) || (r->last_time ==NULL )) { +unsigned int i; +void *p = r->last_time; + + r->last_time =realloc (r->last_time, (cpu+1 ) *sizeof (u64)); +if (!r->last_time) { +free (p); +return ; + } + + i = r->ncpu ? r->ncpu +1 :0 ; +for (; i <= cpu; ++i) + r->last_time[i] = (u64 )0 ; + + r->ncpu = cpu; + } + + r->last_time[cpu] = timestamp; +} + +static u64 perf_evsel__get_time (struct perf_evsel *evsel,u32 cpu) +{ +struct evsel_runtime *r =perf_evsel__get_runtime (evsel); + +if (r ==NULL ) +return 0 ; + +if (!r->last_time) +return 0 ; + +if ((cpu > r->ncpu) || (r->last_time ==NULL )) +return 0 ; + +return r->last_time[cpu]; +} + +static void timehist_header (struct perf_sched *sched) +{ +u32 max_cpus = sched->max_cpu; +u32 i, j; + +printf ("%-15s %-4s" ,"time" ,"cpu" ); + +if (sched->show_cpu_visual && max_cpus) { +printf (" " ); +for (i =0 , j =0 ; i < max_cpus; ++i) { +printf ("%x" , j++); +if (j >15 ) + j =0 ; + } +printf (" " ); + } + +printf (" %-20s %9s %9s" , +"task name[tid/pid]" ,"b/n time" ,"run time" ); + +printf ("\n" ); + +printf ("%15s %4s" ,"---------------" ,"----" ); + +if (sched->show_cpu_visual && max_cpus) { +printf (" " ); +for (i =0 ; i < max_cpus; ++i) +printf ("-" ); +printf (" " ); + } + +printf (" %20s %9s %9s" , +"--------------------" ,"---------" ,"---------" ); + +printf ("\n" ); +} + +static char *timehist_time_str (char *tstr,int len,u64 t) +{ +unsigned long secs, usecs; +unsigned long long nsecs; + + nsecs = t; + secs = nsecs /NSECS_PER_SEC ; + nsecs -= secs *NSECS_PER_SEC ; + usecs = nsecs /NSECS_PER_USEC ; +snprintf (tstr, len,"%5lu.%06lu" , secs, usecs); + +return tstr; +} + +static unsigned int comm_width =20 ; + +static void timehist_print_sample (struct perf_sched *sched, +struct perf_evsel *evsel, +struct perf_sample *sample, +struct thread *thread, +struct machine *machine) +{ +struct thread_runtime *tr =thread__priv (thread); +union perf_event *event = evsel->handler.data; +char tstr[64 ]; +u32 max_cpus = sched->max_cpu; + +printf ("%15s " ,timehist_time_str (tstr,sizeof (tstr), sample->time)); + +printf ("[%02d] " , sample->cpu); + +if (sched->show_cpu_visual && max_cpus) { +u32 i; +char c; +for (i =0 ; i < max_cpus; ++i) { + c = i == sample->cpu ?'s' :' ' ; +printf ("%c" , c); + } +printf (" " ); + } + +printf ("%-*s " , comm_width, tr->commstr); + +printf_nsecs (tr->dt_between,2 ); +printf_nsecs (tr->dt_run,2 ); + +perf_evsel__print_ip (evsel, event, sample, machine, +PRINT_IP_OPT_SYM |PRINT_IP_OPT_ONELINE , + sched->max_stack_depth); + +printf ("\n" ); +} + +static int timehist_check_attr (struct perf_sched *sched, +struct perf_evlist *evlist) +{ +struct perf_evsel *evsel; +struct evsel_runtime *er; + +list_for_each_entry (evsel, &evlist->entries, node) { + er =perf_evsel__get_runtime (evsel); +if (er ==NULL ) { +pr_err ("Failed to allocate memory for evsel runtime data\n" ); +return -1 ; + } + +if (!sched->no_callchain && + !(evsel->attr.sample_type &PERF_SAMPLE_CALLCHAIN )) { + sched->no_callchain =1 ; + symbol_conf.use_callchain =0 ; + } + } + +return 0 ; +} + +static bool is_idle_sample (struct perf_sample *sample, +struct perf_evsel *evsel, +struct machine *machine) +{ +struct thread *thread; +struct callchain_cursor *cursor = &callchain_cursor; +struct callchain_cursor_node *node; +struct addr_location al; +int iter =5 ; + +/* pid 0 == swapper == idle task */ +if (sample->pid ==0 ) +return true; + +/* want main thread for process - has maps */ + thread =machine__findnew_thread (machine, sample->pid); +if (thread ==NULL ) { +pr_debug ("Failed to get thread for pid %d.\n" , sample->pid); +return false; + } + +if (!symbol_conf.use_callchain || sample->callchain ==NULL ) +return false; + +if (machine__resolve_callchain (machine, evsel, thread, + sample,NULL , &al) !=0 ) { +if (verbose) +error ("Failed to resolve callchain. Skipping\n" ); + +return false; + } +callchain_cursor_commit (cursor); + +/* idle symbol should be early in the stack */ +while (iter) { + node =callchain_cursor_current (cursor); +if (!node) +break ; + +if (symbol__is_idle (node->sym)) +return true; + +callchain_cursor_advance (cursor); + + iter--; + } + +return false; +} + +static void timehist_update_thread_stats (struct thread_runtime *r, +u64 t,u64 dt_run) +{ +u64 dt_task =0 ; +double delta; + + r->count++; + +/* current run time and total run time */ + r->dt_run = dt_run; + r->total_run_time += dt_run; + +/* time b/n sched events for task */ +if (r->last_time) + dt_task = t - r->last_time; + +/* subtract run time for this event to get time between +* sched in events - i.e., how long between accesses to CPU +*/ +if (dt_task > dt_run) + r->dt_between = dt_task - dt_run; + +/* +* update average and stddev stats +*/ + delta = dt_run - r->mean; + r->mean += delta / r->count; + r->M2 += delta * (dt_run - r->mean); + +if (dt_run > r->max_run_time) + r->max_run_time = dt_run; + +if (dt_run < r->min_run_time) + r->min_run_time = dt_run; +} + +static struct thread *get_idle_thread (int cpu) +{ +/* expand/allocate array of pointers to local thread +* structs if needed +*/ +if ((cpu > idle_max_cpu) || (idle_threads ==NULL )) { +int i, j =15 ; +void *p; + +if (cpu > j) + j = cpu; + p =realloc (idle_threads, (j+1 ) *sizeof (struct thread *)); +if (!p) +return NULL ; + + idle_threads = (struct thread **) p; + i = idle_max_cpu ? idle_max_cpu +1 :0 ; +for (; i <= cpu; ++i) + idle_threads[i] =NULL ; + + idle_max_cpu = cpu; + } + +/* allocate the actual thread struct if needed */ +if (idle_threads[cpu] ==NULL ) { + idle_threads[cpu] =zalloc (sizeof (struct thread )); +if (idle_threads[cpu]) { + idle_threads[cpu]->tid =0 ; + idle_threads[cpu]->comm = idle_comm; + } + } + +return idle_threads[cpu]; +} + +static void timehist_set_commstr (struct thread_runtime *r, +const char *comm, +pid_t pid,pid_t tid) +{ +unsigned int i, n; + +if ((r ==NULL ) || (*r->commstr !='\0' )) +return ; + +if (pid ==0 ) { +snprintf (r->commstr,sizeof (r->commstr)-1 ,"%s" , comm); + + }else if (tid != pid) { +snprintf (r->commstr,sizeof (r->commstr)-1 ,"%s[%d/%d]" , + comm, tid, pid); + }else { +snprintf (r->commstr,sizeof (r->commstr)-1 ,"%s[%d]" , + comm, tid); + } + +for (i =0 ; i <strlen (r->commstr); ++i) { +if (r->commstr[i] ==' ' ) + r->commstr[i] ='-' ; + } + + n =strlen (r->commstr); +if (n > comm_width) + comm_width = n; +} + +static struct thread_runtime *thread__init_runtime (struct thread *thread,pid_t pid) +{ +struct thread_runtime *r; + + r =zalloc (sizeof (struct thread_runtime )); +if (!r) +return NULL ; + + r->min_run_time = (u64) -1 ; +thread__set_priv (thread, r); + +/* optimization - saving comm string used in stack dump */ +timehist_set_commstr (r, thread->comm, pid, thread->tid); + +return r; +} + +static struct thread *timehist_get_thread (struct perf_evsel *evsel, +struct perf_sample *sample, +struct machine *machine) +{ +struct thread *thread; + +if (is_idle_sample (sample, evsel, machine)) { + thread =get_idle_thread (sample->cpu); +if (thread ==NULL ) +pr_err ("failed to get idle thread for cpu %d.\n" , sample->cpu); + + }else { + thread =machine__findnew_thread (machine, sample->tid); +if (thread ==NULL ) { +pr_debug ("Failed to get thread for tid %d. skipping sample.\n" , + sample->tid); + } + } + +return thread; +} + +static int timehist_sched_change_event (struct perf_tool *tool, +struct perf_evsel *evsel, +struct perf_sample *sample, +struct machine *machine) +{ + struct perf_sched *sched = container_of(tool, struct perf_sched, tool); +struct thread *thread; +struct thread_runtime *tr =NULL ; +u64 dt_run =0 , tprev; +int rc =0 ; + + thread =timehist_get_thread (evsel, sample, machine); +if (thread ==NULL ) { + rc =-1 ; + goto out; + } + + tr =thread__priv (thread); +if (tr ==NULL ) { +/* pid argument is not needed once Adrian's patch is picked up */ + tr =thread__init_runtime (thread, sample->pid); +if (tr ==NULL ) { +pr_debug ("failed to malloc memory for runtime data.\n" ); + rc =-1 ; + goto out; + } + } + + tprev =perf_evsel__get_time (evsel, sample->cpu); +if (tprev) + dt_run = sample->time - tprev; + +timehist_update_thread_stats (tr, sample->time, dt_run); +if (sched->show_events) +timehist_print_sample (sched, evsel, sample, thread, machine); + +out: +if (tr) + tr->last_time = sample->time; +perf_evsel__save_time (evsel, sample->time, sample->cpu); + +return rc; +} + +static int timehist_sched_switch_event (struct perf_tool *tool, +struct perf_evsel *evsel, +struct perf_sample *sample, +struct machine *machine) +{ +return timehist_sched_change_event (tool, evsel, sample, machine); +} + +static int process_lost (struct perf_tool *tool__maybe_unused , +union perf_event *event, +struct perf_sample *sample, +struct machine *machine__maybe_unused ) +{ +char tstr[64 ]; + +printf ("%15s " ,timehist_time_str (tstr,sizeof (tstr), sample->time)); +printf ("lost %" PRIu64" events on cpu %d\n" , event->lost.lost, sample->cpu); + +return 0 ; +} + + +static void print_thread_runtime (struct thread *t,struct thread_runtime *r) +{ +double variance; +float stddev; + +printf (" %*s %5d %6" PRIu64" " , + comm_width, r->commstr, t->ppid, r->count); + +printf_nsecs (r->total_run_time,2 ); +if (r->count >1 ) { + variance = r->M2 / (r->count -1 ); + stddev =100.0 *sqrt (variance / r->count) / r->mean; + +printf (" " ); +printf_nsecs (r->min_run_time,2 ); +printf (" " ); +printf_nsecs (r->max_run_time,2 ); +printf (" " ); +printf_nsecs ((u64 ) r->mean,2 ); +printf (" " ); +printf ("%5.2f" , stddev); + } +printf ("\n" ); +} + +static void timehist_print_summary (struct perf_session *session) +{ +struct machine *m = &session->machines.host; +struct rb_node *nd; +struct thread *t; +struct thread_runtime *r; +u64 total_run_time =0 ; +u64 total_count =0 ; +int i, total_task =0 ; + +printf ("\nRuntime summary (times are in seconds)\n" ); +printf (" %*s parent number " , comm_width,"comm" ); +printf ("run-time min-run max-run avg-run stddev(%%)\n" ); + + nd =rb_first (&m->threads); +while (nd) { + t = rb_entry(nd, struct thread, rb_node); + + r =thread__priv (t); +if (r && r->count) { + total_count += r->count; + total_run_time += r->total_run_time; + total_task++; +print_thread_runtime (t, r); + } + + nd =rb_next (nd); + } + +printf ("\nTerminated tasks:\n" ); +list_for_each_entry (t, &m->dead_threads, node) { + r =thread__priv (t); +if (r && r->count) { + total_count += r->count; + total_run_time += r->total_run_time; + total_task++; + +print_thread_runtime (t, r); + } + } + +printf ("\nIdle stats:\n" ); +for (i =0 ; i <= idle_max_cpu; ++i) { + t = idle_threads[i]; +if (!t) +continue ; + + r =thread__priv (t); +if (r && r->count) { + total_count += r->count; +printf (" CPU %d idle for " , i); +printf_nsecs (r->total_run_time,2 ); +printf ("\n" ); + } + } + +WARN_ONCE (!symbol_conf.vmlinux_name && !symbol_conf.kallsyms_name, +"kernel symbols not given. If this is an offline analysis idle time computations will be wrong\n" ); + +printf ("\n" +" Total number of unique tasks: %d\n" +"Total number of context switches: %" PRIu64"\n" +" Total run time (sec): " , + total_task, total_count); +printf_nsecs (total_run_time,2 ); +printf ("\n" ); +} +static int perf_timehist__process_sample (struct perf_tool *tool, +union perf_event *event, +struct perf_sample *sample, +struct perf_evsel *evsel, +struct machine *machine) +{ +int err =0 ; + + evsel->hists.stats.total_period += sample->period; +hists__inc_nr_events (&evsel->hists,PERF_RECORD_SAMPLE ); + +if (evsel->handler.func !=NULL || verbose) { +tracepoint_handler f = evsel->handler.func; + evsel->handler.data = event; + +if (f) + err =f (tool, evsel, sample, machine); + } + +return err; +} + +/* list of symbols to exclude from stack dump */ +static int setup_excl_sym (void ) +{ +char buf[4096 ]; + +snprintf (buf,sizeof (buf), +"schedule,__schedule," +"schedule_timeout,schedule_timeout_interruptible," +"schedule_hrtimeout_range_clock,schedule_hrtimeout_range," +"syscall,system_call_done,ia32_syscall_done,%s" , + symbol_conf.excl_sym_list_str ? symbol_conf.excl_sym_list_str :"" ); + + symbol_conf.excl_sym_list_str =strdup (buf); + +return 0 ; +} + +static int perf_sched__timehist (struct perf_sched *sched) +{ +const struct perf_evsel_str_handler handlers[] = { + {"sched:sched_switch" , timehist_sched_switch_event, }, + }; + +struct perf_session *session; +int err =-1 ; + +/* +* event handlers for timehist option +*/ + sched->tool.sample = perf_timehist__process_sample; + sched->tool.mmap = perf_event__process_mmap; + sched->tool.comm = perf_event__process_comm; + sched->tool.exit = perf_event__process_exit; + sched->tool.fork = perf_event__process_fork; + sched->tool.lost = process_lost; + sched->tool.attr = perf_event__process_attr; + sched->tool.tracing_data = perf_event__process_tracing_data; + sched->tool.build_id = perf_event__process_build_id; + + sched->tool.ordered_samples = true; + sched->tool.ordering_requires_timestamps = true; + +/* if not given default to stack depth of 5 */ +if (sched->max_stack_depth ==0 ) + sched->max_stack_depth =5 ; + + symbol_conf.use_callchain = !sched->no_callchain; +setup_excl_sym (); +if (symbol__init () <0 ) +return -1 ; + + session =perf_session__new (input_name,O_RDONLY ,0 , false, &sched->tool); +if (session ==NULL ) +return -ENOMEM ; + +setup_pager (); + +if (timehist_check_attr (sched, session->evlist) !=0 ) +return -ENOMEM ; + +perf_session__fprintf_info (session, stdout, true); + +/* pre-allocate struct for per-CPU idle stats */ + sched->max_cpu = session->header.env.nr_cpus_online; +if (sched->max_cpu >0 ) { + idle_max_cpu = sched->max_cpu -1 ; + idle_threads =zalloc (sched->max_cpu *sizeof (struct thread *)); + } + +/* setup per-evsel handlers */ +if (perf_session__set_tracepoints_handlers (session, handlers)) + goto out; + +if (perf_session__has_traces (session,"record -R" )) { +if (sched->show_events) +timehist_header (sched); + + err =perf_session__process_events (session, &sched->tool); +if (err) { +pr_err ("Failed to process events, error %d" , err); + goto out; + } + + sched->nr_events = session->stats.nr_events[0 ]; + sched->nr_lost_events = session->stats.total_lost; + sched->nr_lost_chunks = session->stats.nr_events[PERF_RECORD_LOST ]; + } + +timehist_print_summary (session); + +out: +perf_session__delete (session); + +return err; +} +static void print_bad_events (struct perf_sched *sched) {if (sched->nr_unordered_timestamps && sched->nr_timestamps) {
@@ -1702,6 +2381,36 @@ int cmd_sched(int argc, const char **argv, const char *prefix __maybe_unused) "dump raw trace in ASCII"),OPT_END () }; +const struct option timehist_options[] = { +OPT_STRING ('i' ,"input" , &input_name,"file" , +"input file name" ), +OPT_INCR ('v' ,"verbose" , &verbose, +"be more verbose (show symbol address, etc)" ), +OPT_BOOLEAN ('D' ,"dump-raw-trace" , &dump_trace, +"dump raw trace in ASCII" ), +OPT_STRING ('k' ,"vmlinux" , &symbol_conf.vmlinux_name, +"file" ,"vmlinux pathname" ), +OPT_STRING (0 ,"kallsyms" , &symbol_conf.kallsyms_name, +"file" ,"kallsyms pathname" ), +OPT_STRING ('c' ,"comms" , &symbol_conf.comm_list_str,"comm[,comm...]" , +"only display events for these comms" ), +OPT_UINTEGER ('s' ,"stack-depth" , &sched.max_stack_depth, +"Maximum number of functions to display backtrace." ), +OPT_STRING ('x' ,"excl" , &symbol_conf.excl_sym_list_str,"sym[,sym...]" , +"symbols to skip in backtrace" ), +OPT_BOOLEAN ('G' ,"hide-call-graph" , &sched.no_callchain, +"When printing symbols do not display call chain" ), +OPT_STRING (0 ,"symfs" , &symbol_conf.symfs,"directory" , +"Look for files with symbols relative to this directory" ), +OPT_BOOLEAN (0 ,"cpu-visual" , &sched.show_cpu_visual,"Show CPU visual" ), +OPT_BOOLEAN (0 ,"events" , &sched.show_events,"show all events" ), +OPT_END () + }; +const char *const timehist_usage[] = { +"perf sched timehist [<options>]" , +NULL + }; +const char *const latency_usage[] = {"perf sched latency [<options>]" ,NULL
@@ -1740,7 +2449,6 @@ int cmd_sched(int argc, const char **argv, const char *prefix __maybe_unused)if (!strcmp (argv[0 ],"script" ))return cmd_script (argc, argv, prefix); -symbol__init ();if (!strncmp (argv[0 ],"rec" ,3 )) {return __cmd_record (argc, argv); }else if (!strncmp (argv[0 ],"lat" ,3 )) {
@@ -1751,10 +2459,12 @@ int cmd_sched(int argc, const char **argv, const char *prefix __maybe_unused)usage_with_options (latency_usage, latency_options); }setup_sorting (&sched, latency_options, latency_usage); +symbol__init ();return perf_sched__lat (&sched); }else if (!strcmp (argv[0 ],"map" )) { sched.tp_handler = &map_ops;setup_sorting (&sched, latency_options, latency_usage); +symbol__init ();return perf_sched__map (&sched); }else if (!strncmp (argv[0 ],"rep" ,3 )) { sched.tp_handler = &replay_ops;
@@ -1763,7 +2473,17 @@ int cmd_sched(int argc, const char **argv, const char *prefix __maybe_unused)if (argc)usage_with_options (replay_usage, replay_options); } +symbol__init ();return perf_sched__replay (&sched); + }else if (!strcmp (argv[0 ],"timehist" )) { +if (argc) { + argc =parse_options (argc, argv, timehist_options, + timehist_usage,0 ); +if (argc) +usage_with_options (timehist_usage, timehist_options); + } + +return perf_sched__timehist (&sched); }else {usage_with_options (sched_usage, sched_options); }
Signature · 1 line
1.7.10.1
PATCH 16/19 perf tool: Change perf_session__has_traces to actually check for tracepoints
In reply to David AhernAny event can have RAW data attribute set. The intent of the function is to determine if the session has tracepoints, so check for the type of each event explicitly.
--- tools/perf/util/session.c | 11 +++++++---- 1 file changed, 7 insertions(+), 4 deletions(-)
tools/perf/util/session.c +7 -4
@@ -1401,12 +1401,15 @@ int perf_session__process_events(struct perf_session *self,bool perf_session__has_traces (struct perf_session *session,const char *msg) { -if (!(perf_evlist__sample_type (session->evlist) &PERF_SAMPLE_RAW )) { -pr_err ("No trace sample to read. Did you call 'perf %s'?\n" , msg); -return false; +struct perf_evsel *evsel; + +list_for_each_entry (evsel, &session->evlist->entries, node) { +if (evsel->attr.type ==PERF_TYPE_TRACEPOINT ) +return true; } -return true; +pr_err ("No trace sample to read. Did you call 'perf %s'?\n" , msg); +return false; } int maps__set_kallsyms_ref_reloc_sym(struct map **maps,
Signature · 1 line
1.7.10.1
Arnaldo Carvalho de Melo
AppliedRe: [PATCH 16/19] perf tool: Change perf_session__has_traces to actually check for tracepoints
Em Wed, Aug 07, 2013 at 10:50:58PM -0400, David Ahern escreveu:
Quoted 3 lines
Any event can have RAW data attribute set. The intent of the function is to determine if the session has tracepoints, so check for the type of each event explicitly.
Thanks, applied.
tip-bot for David Ahern
merge bot[tip:perf/core] perf session: Change perf_session__has_traces to actually check for tracepoints
In reply to David Ahernperf session: Change perf_session__has_traces to actually check for tracepoints
Commit-ID: 93ea01c29d4ed5a9fcf6d9a95bc584e54a420834 Gitweb: http://git.kernel.org/tip/93ea01c29d4ed5a9fcf6d9a95bc584e54a420834 Author: David Ahern <[email protected]> AuthorDate: Wed, 7 Aug 2013 22:50:58 -0400 Committer: Arnaldo Carvalho de Melo <[email protected]> CommitDate: Mon, 12 Aug 2013 10:31:08 -0300
perf session: Change perf_session__has_traces to actually check for tracepoints
Any event can have RAW data attribute set. The intent of the function is to determine if the session has tracepoints, so check for the type of each event explicitly.
--- tools/perf/util/session.c | 11 +++++++---- 1 file changed, 7 insertions(+), 4 deletions(-)
tools/perf/util/session.c +7 -4
@@ -1401,12 +1401,15 @@ int perf_session__process_events(struct perf_session *self,bool perf_session__has_traces (struct perf_session *session,const char *msg) { -if (!(perf_evlist__sample_type (session->evlist) &PERF_SAMPLE_RAW )) { -pr_err ("No trace sample to read. Did you call 'perf %s'?\n" , msg); -return false; +struct perf_evsel *evsel; + +list_for_each_entry (evsel, &session->evlist->entries, node) { +if (evsel->attr.type ==PERF_TYPE_TRACEPOINT ) +return true; } -return true; +pr_err ("No trace sample to read. Did you call 'perf %s'?\n" , msg); +return false; } int maps__set_kallsyms_ref_reloc_sym(struct map **maps,
PATCH 17/19 perf sched timehist: Add support for context-switch event
In reply to David AhernContext switch events are 64 bytes; sched_switch events are 136 bytes. Both indicate scheduling changes, so allow user to leverage the smaller event. If both events exist in a data file, then context-switch event is ignored.
--- tools/perf/builtin-sched.c | 67 +++++++++++++++++++++++++++++++++++--------- 1 file changed, 54 insertions(+), 13 deletions(-)
tools/perf/builtin-sched.c +54 -13
@@ -177,6 +177,7 @@ struct perf_sched {bool no_callchain;unsigned int max_stack_depth;bool show_cpu_visual; +bool skip_cs; };/* per thread run time data */
@@ -1674,8 +1675,17 @@ static int timehist_check_attr(struct perf_sched *sched, {struct perf_evsel *evsel;struct evsel_runtime *er; +const char *evname; +bool have_cs_event = false, have_sched_event = false;list_for_each_entry (evsel, &evlist->entries, node) { + evname =perf_evsel__name (evsel); +if (strcmp (evname,"cs" ) ==0 || +strcmp (evname,"context-switch" ) ==0 ) + have_cs_event = true; +else if (strcmp (evname,"sched:sched_switch" ) ==0 ) + have_sched_event = true; + er =perf_evsel__get_runtime (evsel);if (er ==NULL ) {pr_err ("Failed to allocate memory for evsel runtime data\n" );
@@ -1689,6 +1699,11 @@ static int timehist_check_attr(struct perf_sched *sched, } } +if (have_cs_event && have_sched_event) { +pr_debug ("Both schedule change events exist. Ignoring context-switch event\n" ); + sched->skip_cs = true; + } +return 0 ; }
@@ -1926,6 +1941,30 @@ out:return rc; } +static int timehist_cs_event (struct perf_tool *tool__maybe_unused , +struct perf_evsel *evsel, +struct perf_sample *sample, +struct machine *machine__maybe_unused ) +{ +return timehist_sched_change_event (tool, evsel, sample, machine); +} + +static void timehist_set_cs_handler (struct perf_evlist *evlist) +{ +struct perf_evsel *evsel; +const char *evname; + +list_for_each_entry (evsel, &evlist->entries, node) { + evname =perf_evsel__name (evsel); +if (strcmp (evname,"cs" ) ==0 || +strcmp (evname,"context-switch" ) ==0 ) { + evsel->handler.func = timehist_cs_event; + } + } + +return ; +} + static int timehist_sched_switch_event(struct perf_tool *tool, struct perf_evsel *evsel, struct perf_sample *sample,
@@ -2132,24 +2171,26 @@ static int perf_sched__timehist(struct perf_sched *sched) }/* setup per-evsel handlers */ -if (perf_session__set_tracepoints_handlers (session, handlers)) - goto out; +if (!sched->skip_cs) +timehist_set_cs_handler (session->evlist); -if (perf_session__has_traces (session,"record -R" )) { -if (sched->show_events) -timehist_header (sched); +if (perf_session__has_traces (session,"sched record" ) && +perf_session__set_tracepoints_handlers (session, handlers)) + goto out; - err =perf_session__process_events (session, &sched->tool); -if (err) { -pr_err ("Failed to process events, error %d" , err); - goto out; - } +if (sched->show_events) +timehist_header (sched); - sched->nr_events = session->stats.nr_events[0 ]; - sched->nr_lost_events = session->stats.total_lost; - sched->nr_lost_chunks = session->stats.nr_events[PERF_RECORD_LOST ]; + err =perf_session__process_events (session, &sched->tool); +if (err) { +pr_err ("Failed to process events, error %d" , err); + goto out; } + sched->nr_events = session->stats.nr_events[0 ]; + sched->nr_lost_events = session->stats.total_lost; + sched->nr_lost_chunks = session->stats.nr_events[PERF_RECORD_LOST ]; +timehist_print_summary (session); out:
Signature · 1 line
1.7.10.1
PATCH 18/19 perf sched timehist: Print all events in verbose mode
In reply to David AhernUseful for debugging and correlating extra events in a file with the scheduling events collected.
--- tools/perf/builtin-sched.c | 57 ++++++++++++++++++++++++++++++++++++++++---- 1 file changed, 53 insertions(+), 4 deletions(-)
tools/perf/builtin-sched.c +53 -4
@@ -1897,6 +1897,50 @@ static struct thread *timehist_get_thread(struct perf_evsel *evsel,return thread; } +static void timehist_print_sched_event (struct perf_tool *tool, +struct perf_evsel *evsel, +struct perf_sample *sample, +struct machine *machine) +{ + struct perf_sched *sched = container_of(tool, struct perf_sched, tool); +struct thread *thread; +struct thread_runtime *tr; +const char *evname; +char tstr[64 ]; + + thread =machine__findnew_thread (machine, sample->tid); +if (thread ==NULL ) +return ; + + tr =thread__priv (thread); +if (tr ==NULL ) { + tr =thread__init_runtime (thread, sample->pid); +if (tr ==NULL ) +return ; + } + +printf ("%15s " ,timehist_time_str (tstr,sizeof (tstr), sample->time)); +printf ("[%02d] " , sample->cpu); +if (sched->show_cpu_visual && sched->max_cpu) +printf ("%*s " , sched->max_cpu,"" ); + +printf ("%-*s " , comm_width, tr->commstr); + +/* dt spacer */ +printf (" %9s %9s " ,"" ,"" ); + + evname =perf_evsel__name (evsel); +printf ("%s " , evname ? evname :"[unknown]" ); +if (evsel->attr.type ==PERF_TYPE_TRACEPOINT ) { +event_format__print (evsel->tp_format, sample->cpu, + sample->raw_data, sample->raw_size); + } + +printf ("\n" ); + +return ; +} + static int timehist_sched_change_event(struct perf_tool *tool, struct perf_evsel *evsel, struct perf_sample *sample,
@@ -2079,12 +2123,14 @@ static void timehist_print_summary(struct perf_session *session)printf_nsecs (total_run_time,2 );printf ("\n" ); } +static int perf_timehist__process_sample (struct perf_tool *tool, -union perf_event *event, -struct perf_sample *sample, -struct perf_evsel *evsel, -struct machine *machine) +union perf_event *event, +struct perf_sample *sample, +struct perf_evsel *evsel, +struct machine *machine) { + struct perf_sched *sched = container_of(tool, struct perf_sched, tool);int err =0 ; evsel->hists.stats.total_period += sample->period;
@@ -2094,6 +2140,9 @@ static int perf_timehist__process_sample(struct perf_tool *tool,tracepoint_handler f = evsel->handler.func; evsel->handler.data = event; +if (sched->show_events && verbose) +timehist_print_sched_event (tool, evsel, sample, machine); +if (f) err =f (tool, evsel, sample, machine); }
Signature · 1 line
1.7.10.1
PATCH 19/19 perf sched timehist: Add pid/tid option
In reply to David AhernAllows analysis of individual tasks within a file collected for the entire system.
--- tools/perf/builtin-sched.c | 50 ++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 50 insertions(+)
tools/perf/builtin-sched.c +50 -0
@@ -17,6 +17,7 @@#include "util/debug.h" #include "util/strlist.h" +#include "util/intlist.h" #include "asm/bug.h" #include <sys/prctl.h> #include <sys/resource.h>
@@ -178,6 +179,9 @@ struct perf_sched {unsigned int max_stack_depth;bool show_cpu_visual;bool skip_cs; +/* process and task id's of interest */ +struct perf_target target; +struct intlist *pid, *tid; };/* per thread run time data */
@@ -1897,6 +1901,18 @@ static struct thread *timehist_get_thread(struct perf_evsel *evsel,return thread; } +static bool timehist_skip_sample (struct perf_sched *sched, +struct perf_sample *sample) +{ +if (sched->pid &&intlist__find (sched->pid, sample->pid) ==NULL ) +return true; + +if (sched->tid &&intlist__find (sched->tid, sample->tid) ==NULL ) +return true; + +return false; +} + static void timehist_print_sched_event(struct perf_tool *tool, struct perf_evsel *evsel, struct perf_sample *sample,
@@ -1908,6 +1924,9 @@ static void timehist_print_sched_event(struct perf_tool *tool,const char *evname;char tstr[64 ]; +if (timehist_skip_sample (sched, sample)) +return ; + thread =machine__findnew_thread (machine, sample->tid);if (thread ==NULL )return ;
@@ -1969,6 +1988,9 @@ static int timehist_sched_change_event(struct perf_tool *tool, } } +if (timehist_skip_sample (sched, sample)) + goto out; + tprev =perf_evsel__get_time (evsel, sample->cpu);if (tprev) dt_run = sample->time - tprev;
@@ -2167,6 +2189,27 @@ static int setup_excl_sym(void)return 0 ; } +static int parse_target_str (struct perf_sched *sched) +{ +if (sched->target.pid) { + sched->pid =intlist__new (sched->target.pid); +if (sched->pid ==NULL ) { +pr_err ("Error parsing process id string\n" ); +return -EINVAL ; + } + } + +if (sched->target.tid) { + sched->tid =intlist__new (sched->target.tid); +if (sched->tid ==NULL ) { +pr_err ("Error parsing thread id string\n" ); +return -EINVAL ; + } + } + +return 0 ; +} +static int perf_sched__timehist (struct perf_sched *sched) {const struct perf_evsel_str_handler handlers[] = {
@@ -2205,6 +2248,9 @@ static int perf_sched__timehist(struct perf_sched *sched)if (session ==NULL )return -ENOMEM ; +if (parse_target_str (sched) !=0 ) + goto out; +setup_pager ();if (timehist_check_attr (sched, session->evlist) !=0 )
@@ -2484,6 +2530,10 @@ int cmd_sched(int argc, const char **argv, const char *prefix __maybe_unused) "file", "kallsyms pathname"),OPT_STRING ('c' ,"comms" , &symbol_conf.comm_list_str,"comm[,comm...]" ,"only display events for these comms" ), +OPT_STRING ('p' ,"pid" , &sched.target.pid,"pid" , +"analyze events only for given process id(s)" ), +OPT_STRING ('t' ,"tid" , &sched.target.tid,"tid" , +"analyze events only for given thread id(s)" ),OPT_UINTEGER ('s' ,"stack-depth" , &sched.max_stack_depth,"Maximum number of functions to display backtrace." ), OPT_STRING('x', "excl", &symbol_conf.excl_sym_list_str, "sym[,sym...]",
Signature · 1 line
1.7.10.1