[PATCH v2 1/3] perf script: Move evname print code to process_event()

[PATCH v2 1/3] perf script: Move evname print code to process_event()

[Namhyung Kim]

The print_sample_start() will be reused by other printing routine for
internal events like COMM, FORK and EXIT from next patch.  And because
they're not tied to a specific event, move the evname print code to
its caller.

Reviewed-by: David Ahern <dsahern@gmail.com>
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
 tools/perf/builtin-script.c | 11 +++++------
 1 file changed, 5 insertions(+), 6 deletions(-)

diff --git a/tools/perf/builtin-script.c b/tools/perf/builtin-script.c
index baf17989a216..b392770766dd 100644
--- a/tools/perf/builtin-script.c
+++ b/tools/perf/builtin-script.c
@@ -288,7 +288,6 @@ static void print_sample_start(struct perf_sample *sample,
 			       struct perf_evsel *evsel)
 {
 	struct perf_event_attr *attr = &evsel->attr;
-	const char *evname = NULL;
 	unsigned long secs;
 	unsigned long usecs;
 	unsigned long long nsecs;
@@ -323,11 +322,6 @@ static void print_sample_start(struct perf_sample *sample,
 		usecs = nsecs / NSECS_PER_USEC;
 		printf("%5lu.%06lu: ", secs, usecs);
 	}
-
-	if (PRINT_FIELD(EVNAME)) {
-		evname = perf_evsel__name(evsel);
-		printf("%s: ", evname ? evname : "[unknown]");
-	}
 }
 
 static bool is_bts_event(struct perf_event_attr *attr)
@@ -434,6 +428,11 @@ static void process_event(union perf_event *event, struct perf_sample *sample,
 
 	print_sample_start(sample, thread, evsel);
 
+	if (PRINT_FIELD(EVNAME)) {
+		const char *evname = perf_evsel__name(evsel);
+		printf("%s: ", evname ? evname : "[unknown]");
+	}
+
 	if (is_bts_event(attr)) {
 		print_sample_bts(event, sample, evsel, machine, thread);
 		return;
-- 
1.7.11.7

[PATCH v2 2/3] perf script: Print comm, fork and exit events also

[Namhyung Kim]

If --show-task option is given, also print internal COMM, FORK and
EXIT events.  It would be helpful for debugging.

  $ perf script --show-task
  ...
         swapper     0 [009] 3350640.335261: sched:sched_switch: prev_comm=swapper/9
           sleep  9486 [009] 3350640.335509: comm: perf --> sleep (9486)
           sleep  9486 [009] 3350640.335806: sched:sched_stat_runtime: comm=sleep pid=9486
         firefox  2635 [003] 3350641.275896: fork: firefox (2635 --> 9487)
         firefox  2635 [003] 3350641.275896: sched:sched_process_fork: comm=firefox pid=2635
           sleep  9486 [009] 3350641.336009: exit: sleep (9486)

Suggested-by: Frederic Weisbecker <fweisbec@gmail.com>
Reviewed-by: David Ahern <dsahern@gmail.com>
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
 tools/perf/Documentation/perf-script.txt |   3 +
 tools/perf/builtin-script.c              | 115 +++++++++++++++++++++++++++++++
 2 files changed, 118 insertions(+)

diff --git a/tools/perf/Documentation/perf-script.txt b/tools/perf/Documentation/perf-script.txt
index e9cbfcddfa3f..9a9a7c3d592d 100644
--- a/tools/perf/Documentation/perf-script.txt
+++ b/tools/perf/Documentation/perf-script.txt
@@ -203,6 +203,9 @@ OPTIONS
 --show-kernel-path::
 	Try to resolve the path of [kernel.kallsyms]
 
+--show-task
+	Display task related events (e.g. FORK, COMM, EXIT).
+
 SEE ALSO
 --------
 linkperf:perf-record[1], linkperf:perf-script-perl[1],
diff --git a/tools/perf/builtin-script.c b/tools/perf/builtin-script.c
index b392770766dd..d05e6d835877 100644
--- a/tools/perf/builtin-script.c
+++ b/tools/perf/builtin-script.c
@@ -548,6 +548,7 @@ static int process_sample_event(struct perf_tool *tool __maybe_unused,
 struct perf_script {
 	struct perf_tool	tool;
 	struct perf_session	*session;
+	bool			show_task_events;
 };
 
 static int process_attr(struct perf_tool *tool, union perf_event *event,
@@ -578,6 +579,111 @@ static int process_attr(struct perf_tool *tool, union perf_event *event,
 	return perf_evsel__check_attr(evsel, scr->session);
 }
 
+static int process_comm_event(struct perf_tool *tool,
+			      union perf_event *event,
+			      struct perf_sample *sample,
+			      struct machine *machine)
+{
+	struct thread *thread;
+	struct perf_script *script = container_of(tool, struct perf_script, tool);
+	struct perf_session *session = script->session;
+	struct perf_evsel *evsel = perf_evlist__first(session->evlist);
+	char *oldname;
+	int ret = -1;
+
+	thread = machine__findnew_thread(machine, event->comm.pid, event->comm.tid);
+	if (thread == NULL) {
+		pr_debug("problem processing COMM event, skipping it.\n");
+		return -1;
+	}
+
+	oldname = strdup(thread__comm_str(thread));
+	if (oldname == NULL) {
+		pr_debug("problem processing COMM event, skipping it.\n");
+		return -1;
+	}
+
+	if (perf_event__process_comm(tool, event, sample, machine) < 0)
+		goto out;
+
+	if (!evsel->attr.sample_id_all) {
+		sample->cpu = 0;
+		sample->time = 0;
+		sample->tid = event->comm.tid;
+		sample->pid = event->comm.pid;
+	}
+	print_sample_start(sample, thread, evsel);
+	printf("comm: %s --> %s (%d)\n", oldname, event->comm.comm,
+	       event->comm.tid);
+	ret = 0;
+
+out:
+	free(oldname);
+	return ret;
+}
+
+static int process_fork_event(struct perf_tool *tool,
+			      union perf_event *event,
+			      struct perf_sample *sample,
+			      struct machine *machine)
+{
+	struct thread *thread;
+	struct perf_script *script = container_of(tool, struct perf_script, tool);
+	struct perf_session *session = script->session;
+	struct perf_evsel *evsel = perf_evlist__first(session->evlist);
+
+	if (perf_event__process_fork(tool, event, sample, machine) < 0)
+		return -1;
+
+	thread = machine__findnew_thread(machine, event->fork.pid, event->fork.tid);
+	if (thread == NULL) {
+		pr_debug("problem processing FORK event, skipping it.\n");
+		return -1;
+	}
+
+	if (!evsel->attr.sample_id_all) {
+		sample->cpu = 0;
+		sample->time = event->fork.time;
+		sample->tid = event->fork.tid;
+		sample->pid = event->fork.pid;
+	}
+	print_sample_start(sample, thread, evsel);
+	printf("fork: %s (%d --> %d)\n", thread__comm_str(thread),
+	       event->fork.ptid, event->fork.tid);
+
+	return 0;
+}
+static int process_exit_event(struct perf_tool *tool,
+			      union perf_event *event,
+			      struct perf_sample *sample,
+			      struct machine *machine)
+{
+	struct thread *thread;
+	struct perf_script *script = container_of(tool, struct perf_script, tool);
+	struct perf_session *session = script->session;
+	struct perf_evsel *evsel = perf_evlist__first(session->evlist);
+
+	thread = machine__findnew_thread(machine, event->fork.pid, event->fork.tid);
+	if (thread == NULL) {
+		pr_debug("problem processing EXIT event, skipping it.\n");
+		return -1;
+	}
+
+	if (!evsel->attr.sample_id_all) {
+		sample->cpu = 0;
+		sample->time = 0;
+		sample->tid = event->comm.tid;
+		sample->pid = event->comm.pid;
+	}
+	print_sample_start(sample, thread, evsel);
+	printf("exit: %s (%d)\n", thread__comm_str(thread), event->fork.tid);
+
+	if (perf_event__process_exit(tool, event, sample, machine) < 0)
+		return -1;
+
+	return 0;
+}
+
 static void sig_handler(int sig __maybe_unused)
 {
 	session_done = 1;
@@ -589,6 +695,13 @@ static int __cmd_script(struct perf_script *script)
 
 	signal(SIGINT, sig_handler);
 
+	/* override event processing functions */
+	if (script->show_task_events) {
+		script->tool.comm = process_comm_event;
+		script->tool.fork = process_fork_event;
+		script->tool.exit = process_exit_event;
+	}
+
 	ret = perf_session__process_events(script->session, &script->tool);
 
 	if (debug_mode)
@@ -1351,6 +1464,8 @@ int cmd_script(int argc, const char **argv, const char *prefix __maybe_unused)
 		    "display extended information from perf.data file"),
 	OPT_BOOLEAN('\0', "show-kernel-path", &symbol_conf.show_kernel_path,
 		    "Show the path of [kernel.kallsyms]"),
+	OPT_BOOLEAN('\0', "show-task", &script.show_task_events,
+		    "Show the fork/comm/exit events"),
 	OPT_END()
 	};
 	const char * const script_usage[] = {
-- 
1.7.11.7

[PATCH v2 3/3] perf script: Print mmap[2] events also

[Namhyung Kim]

If --show-mmap option is given, also print internal MMAP and MMAP2
events.  It would be helpful for debugging.

  $ perf script --show-mmap
  ...
           sleep  9486 [009] 3350640.335531: mmap: [(0x400000 - 0x406000) @ 0 ]: x /usr/bin/sleep
           sleep  9486 [009] 3350640.335542: mmap: [(0x3153a00000 - 0x3153c23000) @ 0 ]: x /usr/lib64/ld-2.17.so
           sleep  9486 [009] 3350640.335553: mmap: [(0x7fff8b5fe000 - 0x7fff8b600000) @ 0x7fff8b5fe000 ]: x [vdso]
           sleep  9486 [009] 3350640.335643: mmap: [(0x3153e00000 - 0x31541c0000) @ 0 ]: x /usr/lib64/libc-2.17.so

Suggested-by: Frederic Weisbecker <fweisbec@gmail.com>
Reviewed-by: David Ahern <dsahern@gmail.com>
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
 tools/perf/Documentation/perf-script.txt |  3 ++
 tools/perf/builtin-script.c              | 78 ++++++++++++++++++++++++++++++++
 2 files changed, 81 insertions(+)

diff --git a/tools/perf/Documentation/perf-script.txt b/tools/perf/Documentation/perf-script.txt
index 9a9a7c3d592d..ad67f3b0efda 100644
--- a/tools/perf/Documentation/perf-script.txt
+++ b/tools/perf/Documentation/perf-script.txt
@@ -206,6 +206,9 @@ OPTIONS
 --show-task
 	Display task related events (e.g. FORK, COMM, EXIT).
 
+--show-mmap
+	Display mmap related events (e.g. MMAP, MMAP2).
+
 SEE ALSO
 --------
 linkperf:perf-record[1], linkperf:perf-script-perl[1],
diff --git a/tools/perf/builtin-script.c b/tools/perf/builtin-script.c
index d05e6d835877..03bf978a47ce 100644
--- a/tools/perf/builtin-script.c
+++ b/tools/perf/builtin-script.c
@@ -549,6 +549,7 @@ struct perf_script {
 	struct perf_tool	tool;
 	struct perf_session	*session;
 	bool			show_task_events;
+	bool			show_mmap_events;
 };
 
 static int process_attr(struct perf_tool *tool, union perf_event *event,
@@ -684,6 +685,77 @@ static int process_exit_event(struct perf_tool *tool,
 	return 0;
 }
 
+static int process_mmap_event(struct perf_tool *tool,
+			      union perf_event *event,
+			      struct perf_sample *sample,
+			      struct machine *machine)
+{
+	struct thread *thread;
+	struct perf_script *script = container_of(tool, struct perf_script, tool);
+	struct perf_session *session = script->session;
+	struct perf_evsel *evsel = perf_evlist__first(session->evlist);
+
+	if (perf_event__process_mmap(tool, event, sample, machine) < 0)
+		return -1;
+
+	thread = machine__findnew_thread(machine, event->mmap.pid, event->mmap.tid);
+	if (thread == NULL) {
+		pr_debug("problem processing MMAP event, skipping it.\n");
+		return -1;
+	}
+
+	if (!evsel->attr.sample_id_all) {
+		sample->cpu = 0;
+		sample->time = 0;
+		sample->tid = event->comm.tid;
+		sample->pid = event->comm.pid;
+	}
+	print_sample_start(sample, thread, evsel);
+	printf("mmap: [(%#"PRIx64" - %#"PRIx64") @ %#"PRIx64" ]: %c %s\n",
+	       event->mmap.start, event->mmap.start + event->mmap.len,
+	       event->mmap.pgoff,
+	       (event->header.misc & PERF_RECORD_MISC_MMAP_DATA) ? 'r' : 'x',
+	       event->mmap.filename);
+
+	return 0;
+}
+
+static int process_mmap2_event(struct perf_tool *tool,
+			      union perf_event *event,
+			      struct perf_sample *sample,
+			      struct machine *machine)
+{
+	struct thread *thread;
+	struct perf_script *script = container_of(tool, struct perf_script, tool);
+	struct perf_session *session = script->session;
+	struct perf_evsel *evsel = perf_evlist__first(session->evlist);
+
+	if (perf_event__process_mmap2(tool, event, sample, machine) < 0)
+		return -1;
+
+	thread = machine__findnew_thread(machine, event->mmap2.pid, event->mmap2.tid);
+	if (thread == NULL) {
+		pr_debug("problem processing MMAP2 event, skipping it.\n");
+		return -1;
+	}
+
+	if (!evsel->attr.sample_id_all) {
+		sample->cpu = 0;
+		sample->time = 0;
+		sample->tid = event->mmap2.tid;
+		sample->pid = event->mmap2.pid;
+	}
+	print_sample_start(sample, thread, evsel);
+	printf("mmap: [(%#"PRIx64" - %#"PRIx64") @ %#"PRIx64" %02x:%02x %"PRIu64"]: %c %s\n",
+	       event->mmap2.start, event->mmap2.start + event->mmap2.len,
+	       event->mmap2.pgoff, event->mmap2.maj, event->mmap2.min,
+	       event->mmap2.ino,
+	       (event->header.misc & PERF_RECORD_MISC_MMAP_DATA) ? 'r' : 'x',
+	       event->mmap2.filename);
+
+	return 0;
+}
+
 static void sig_handler(int sig __maybe_unused)
 {
 	session_done = 1;
@@ -701,6 +773,10 @@ static int __cmd_script(struct perf_script *script)
 		script->tool.fork = process_fork_event;
 		script->tool.exit = process_exit_event;
 	}
+	if (script->show_mmap_events) {
+		script->tool.mmap = process_mmap_event;
+		script->tool.mmap2 = process_mmap2_event;
+	}
 
 	ret = perf_session__process_events(script->session, &script->tool);
 
@@ -1466,6 +1542,8 @@ int cmd_script(int argc, const char **argv, const char *prefix __maybe_unused)
 		    "Show the path of [kernel.kallsyms]"),
 	OPT_BOOLEAN('\0', "show-task", &script.show_task_events,
 		    "Show the fork/comm/exit events"),
+	OPT_BOOLEAN('\0', "show-mmap", &script.show_mmap_events,
+		    "Show the mmap events"),
 	OPT_END()
 	};
 	const char * const script_usage[] = {
-- 
1.7.11.7

Re: [PATCH v2 2/3] perf script: Print comm, fork and exit events also

[Arnaldo Carvalho de Melo]

Em Mon, Nov 18, 2013 at 02:34:53PM +0900, Namhyung Kim escreveu:
> If --show-task option is given, also print internal COMM, FORK and
> EXIT events.  It would be helpful for debugging.

Humm, --show-task-events is clearer albeit long :-\ With shell
completion shouldn't be an issue tho.

Also, can't we use: perf_event__fprintf_{mmap,comm,task}?
 
>   $ perf script --show-task
>   ...
>          swapper     0 [009] 3350640.335261: sched:sched_switch: prev_comm=swapper/9
>            sleep  9486 [009] 3350640.335509: comm: perf --> sleep (9486)
>            sleep  9486 [009] 3350640.335806: sched:sched_stat_runtime: comm=sleep pid=9486
>          firefox  2635 [003] 3350641.275896: fork: firefox (2635 --> 9487)
>          firefox  2635 [003] 3350641.275896: sched:sched_process_fork: comm=firefox pid=2635
>            sleep  9486 [009] 3350641.336009: exit: sleep (9486)
> 
> Suggested-by: Frederic Weisbecker <fweisbec@gmail.com>
> Reviewed-by: David Ahern <dsahern@gmail.com>
> Signed-off-by: Namhyung Kim <namhyung@kernel.org>
> ---
>  tools/perf/Documentation/perf-script.txt |   3 +
>  tools/perf/builtin-script.c              | 115 +++++++++++++++++++++++++++++++
>  2 files changed, 118 insertions(+)
> 
> diff --git a/tools/perf/Documentation/perf-script.txt b/tools/perf/Documentation/perf-script.txt
> index e9cbfcddfa3f..9a9a7c3d592d 100644
> --- a/tools/perf/Documentation/perf-script.txt
> +++ b/tools/perf/Documentation/perf-script.txt
> @@ -203,6 +203,9 @@ OPTIONS
>  --show-kernel-path::
>  	Try to resolve the path of [kernel.kallsyms]
>  
> +--show-task
> +	Display task related events (e.g. FORK, COMM, EXIT).
> +
>  SEE ALSO
>  --------
>  linkperf:perf-record[1], linkperf:perf-script-perl[1],
> diff --git a/tools/perf/builtin-script.c b/tools/perf/builtin-script.c
> index b392770766dd..d05e6d835877 100644
> --- a/tools/perf/builtin-script.c
> +++ b/tools/perf/builtin-script.c
> @@ -548,6 +548,7 @@ static int process_sample_event(struct perf_tool *tool __maybe_unused,
>  struct perf_script {
>  	struct perf_tool	tool;
>  	struct perf_session	*session;
> +	bool			show_task_events;
>  };
>  
>  static int process_attr(struct perf_tool *tool, union perf_event *event,
> @@ -578,6 +579,111 @@ static int process_attr(struct perf_tool *tool, union perf_event *event,
>  	return perf_evsel__check_attr(evsel, scr->session);
>  }
>  
> +static int process_comm_event(struct perf_tool *tool,
> +			      union perf_event *event,
> +			      struct perf_sample *sample,
> +			      struct machine *machine)
> +{
> +	struct thread *thread;
> +	struct perf_script *script = container_of(tool, struct perf_script, tool);
> +	struct perf_session *session = script->session;
> +	struct perf_evsel *evsel = perf_evlist__first(session->evlist);
> +	char *oldname;
> +	int ret = -1;
> +
> +	thread = machine__findnew_thread(machine, event->comm.pid, event->comm.tid);
> +	if (thread == NULL) {
> +		pr_debug("problem processing COMM event, skipping it.\n");
> +		return -1;
> +	}
> +
> +	oldname = strdup(thread__comm_str(thread));
> +	if (oldname == NULL) {
> +		pr_debug("problem processing COMM event, skipping it.\n");
> +		return -1;
> +	}
> +
> +	if (perf_event__process_comm(tool, event, sample, machine) < 0)
> +		goto out;
> +
> +	if (!evsel->attr.sample_id_all) {
> +		sample->cpu = 0;
> +		sample->time = 0;
> +		sample->tid = event->comm.tid;
> +		sample->pid = event->comm.pid;
> +	}
> +	print_sample_start(sample, thread, evsel);
> +	printf("comm: %s --> %s (%d)\n", oldname, event->comm.comm,
> +	       event->comm.tid);
> +	ret = 0;
> +
> +out:
> +	free(oldname);
> +	return ret;
> +}
> +
> +static int process_fork_event(struct perf_tool *tool,
> +			      union perf_event *event,
> +			      struct perf_sample *sample,
> +			      struct machine *machine)
> +{
> +	struct thread *thread;
> +	struct perf_script *script = container_of(tool, struct perf_script, tool);
> +	struct perf_session *session = script->session;
> +	struct perf_evsel *evsel = perf_evlist__first(session->evlist);
> +
> +	if (perf_event__process_fork(tool, event, sample, machine) < 0)
> +		return -1;
> +
> +	thread = machine__findnew_thread(machine, event->fork.pid, event->fork.tid);
> +	if (thread == NULL) {
> +		pr_debug("problem processing FORK event, skipping it.\n");
> +		return -1;
> +	}
> +
> +	if (!evsel->attr.sample_id_all) {
> +		sample->cpu = 0;
> +		sample->time = event->fork.time;
> +		sample->tid = event->fork.tid;
> +		sample->pid = event->fork.pid;
> +	}
> +	print_sample_start(sample, thread, evsel);
> +	printf("fork: %s (%d --> %d)\n", thread__comm_str(thread),
> +	       event->fork.ptid, event->fork.tid);
> +
> +	return 0;
> +}
> +static int process_exit_event(struct perf_tool *tool,
> +			      union perf_event *event,
> +			      struct perf_sample *sample,
> +			      struct machine *machine)
> +{
> +	struct thread *thread;
> +	struct perf_script *script = container_of(tool, struct perf_script, tool);
> +	struct perf_session *session = script->session;
> +	struct perf_evsel *evsel = perf_evlist__first(session->evlist);
> +
> +	thread = machine__findnew_thread(machine, event->fork.pid, event->fork.tid);
> +	if (thread == NULL) {
> +		pr_debug("problem processing EXIT event, skipping it.\n");
> +		return -1;
> +	}
> +
> +	if (!evsel->attr.sample_id_all) {
> +		sample->cpu = 0;
> +		sample->time = 0;
> +		sample->tid = event->comm.tid;
> +		sample->pid = event->comm.pid;
> +	}
> +	print_sample_start(sample, thread, evsel);
> +	printf("exit: %s (%d)\n", thread__comm_str(thread), event->fork.tid);
> +
> +	if (perf_event__process_exit(tool, event, sample, machine) < 0)
> +		return -1;
> +
> +	return 0;
> +}
> +
>  static void sig_handler(int sig __maybe_unused)
>  {
>  	session_done = 1;
> @@ -589,6 +695,13 @@ static int __cmd_script(struct perf_script *script)
>  
>  	signal(SIGINT, sig_handler);
>  
> +	/* override event processing functions */
> +	if (script->show_task_events) {
> +		script->tool.comm = process_comm_event;
> +		script->tool.fork = process_fork_event;
> +		script->tool.exit = process_exit_event;
> +	}
> +
>  	ret = perf_session__process_events(script->session, &script->tool);
>  
>  	if (debug_mode)
> @@ -1351,6 +1464,8 @@ int cmd_script(int argc, const char **argv, const char *prefix __maybe_unused)
>  		    "display extended information from perf.data file"),
>  	OPT_BOOLEAN('\0', "show-kernel-path", &symbol_conf.show_kernel_path,
>  		    "Show the path of [kernel.kallsyms]"),
> +	OPT_BOOLEAN('\0', "show-task", &script.show_task_events,
> +		    "Show the fork/comm/exit events"),
>  	OPT_END()
>  	};
>  	const char * const script_usage[] = {
> -- 
> 1.7.11.7

Re: [PATCH v2 2/3] perf script: Print comm, fork and exit events also

[David Ahern]

On 11/18/13, 6:57 AM, Arnaldo Carvalho de Melo wrote:
> Em Mon, Nov 18, 2013 at 02:34:53PM +0900, Namhyung Kim escreveu:
>> If --show-task option is given, also print internal COMM, FORK and
>> EXIT events.  It would be helpful for debugging.
>
> Humm, --show-task-events is clearer albeit long :-\ With shell
> completion shouldn't be an issue tho.
>
> Also, can't we use: perf_event__fprintf_{mmap,comm,task}?

Good point. Those can be used to dump data after perf-script's 
sample_start. From a quick review it looks like perf_event__fprintf can 
be used rather than the lower fprintf_mmap functions.

David

Re: [PATCH v2 2/3] perf script: Print comm, fork and exit events also

[Namhyung Kim]

Hi Arnaldo,

On Mon, 18 Nov 2013 10:57:00 -0300, Arnaldo Carvalho de Melo wrote:
> Em Mon, Nov 18, 2013 at 02:34:53PM +0900, Namhyung Kim escreveu:
>> If --show-task option is given, also print internal COMM, FORK and
>> EXIT events.  It would be helpful for debugging.
>
> Humm, --show-task-events is clearer albeit long :-\ With shell
> completion shouldn't be an issue tho.

Okay, will change.

>
> Also, can't we use: perf_event__fprintf_{mmap,comm,task}?

We can do it.  The output will look like below if we use
perf_event__fprintf():

          swapper     0 [009] 3350640.335261: sched:sched_switch: prev_comm=swapper/9
            sleep  9486 [009] 3350640.335509: PERF_RECORD_COMM: sleep:9486
            sleep  9486 [009] 3350640.335806: sched:sched_stat_runtime: comm=sleep pid=9486
          firefox  2635 [003] 3350641.275896: PERF_RECORD_FORK(2635:9487):(2635:2635)
          firefox  2635 [003] 3350641.275896: sched:sched_process_fork: comm=firefox pid=2635
            sleep  9486 [009] 3350641.336009: PERF_RECORD_EXIT(9486:9486):(9486:9486)


But I'd prefer original version below since it shows the changes more
intuitively, no?

Thanks,
Namhyung

>  
>>   $ perf script --show-task
>>   ...
>>          swapper     0 [009] 3350640.335261: sched:sched_switch: prev_comm=swapper/9
>>            sleep  9486 [009] 3350640.335509: comm: perf --> sleep (9486)
>>            sleep  9486 [009] 3350640.335806: sched:sched_stat_runtime: comm=sleep pid=9486
>>          firefox  2635 [003] 3350641.275896: fork: firefox (2635 --> 9487)
>>          firefox  2635 [003] 3350641.275896: sched:sched_process_fork: comm=firefox pid=2635
>>            sleep  9486 [009] 3350641.336009: exit: sleep (9486)

Re: [PATCH v2 2/3] perf script: Print comm, fork and exit events also

[Arnaldo Carvalho de Melo]

Em Tue, Nov 19, 2013 at 09:18:20AM +0900, Namhyung Kim escreveu:
> On Mon, 18 Nov 2013 10:57:00 -0300, Arnaldo Carvalho de Melo wrote:
> > Em Mon, Nov 18, 2013 at 02:34:53PM +0900, Namhyung Kim escreveu:
> >> If --show-task option is given, also print internal COMM, FORK and
> >> EXIT events.  It would be helpful for debugging.

> > Humm, --show-task-events is clearer albeit long :-\ With shell
> > completion shouldn't be an issue tho.
 
> Okay, will change.

Ok, waiting for a new patchset then.
 
> > Also, can't we use: perf_event__fprintf_{mmap,comm,task}?
 
> We can do it.  The output will look like below if we use
> perf_event__fprintf():
 
>           swapper     0 [009] 3350640.335261: sched:sched_switch: prev_comm=swapper/9
>             sleep  9486 [009] 3350640.335509: PERF_RECORD_COMM: sleep:9486
>             sleep  9486 [009] 3350640.335806: sched:sched_stat_runtime: comm=sleep pid=9486
>           firefox  2635 [003] 3350641.275896: PERF_RECORD_FORK(2635:9487):(2635:2635)
>           firefox  2635 [003] 3350641.275896: sched:sched_process_fork: comm=firefox pid=2635
>             sleep  9486 [009] 3350641.336009: PERF_RECORD_EXIT(9486:9486):(9486:9486)

> But I'd prefer original version below since it shows the changes more
> intuitively, no?

Well, by reusing perf_event__fprintf() we will make it clear the kind of
that event, i.e. its not a tracepoint, but a sideband record generated
by the perf infrastructure.

Or perhaps we can change perf_event__fprintf* to show:

           swapper     0 [009] 3350640.335261: sched:sched_switch: prev_comm=swapper/9
             sleep  9486 [009] 3350640.335509: perf:comm: sleep:9486
             sleep  9486 [009] 3350640.335806: sched:sched_stat_runtime: comm=sleep pid=9486
           firefox  2635 [003] 3350641.275896: perf:fork(2635:9487):(2635:2635)
           firefox  2635 [003] 3350641.275896: sched:sched_process_fork: comm=firefox pid=2635
             sleep  9486 [009] 3350641.336009: perf:exit(9486:9486):(9486:9486)

Would that look nicer here and in 'perf report -D'? Ingo?

- Arnaldo

[tip:perf/core] perf script: Move evname print code to process_event()

[tip-bot for Namhyung Kim]

Commit-ID:  e944d3d7d151eea149c62310eaff7b92c7732f58
Gitweb:     http://git.kernel.org/tip/e944d3d7d151eea149c62310eaff7b92c7732f58
Author:     Namhyung Kim <namhyung@kernel.org>
AuthorDate: Mon, 18 Nov 2013 14:34:52 +0900
Committer:  Arnaldo Carvalho de Melo <acme@redhat.com>
CommitDate: Wed, 27 Nov 2013 14:58:35 -0300

perf script: Move evname print code to process_event()

The print_sample_start() will be reused by other printing routine for
internal events like COMM, FORK and EXIT from next patch.  And because
they're not tied to a specific event, move the evname print code to its
caller.

Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Reviewed-by: David Ahern <dsahern@gmail.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Ingo Molnar <mingo@kernel.org>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Namhyung Kim <namhyung.kim@lge.com>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Link: http://lkml.kernel.org/r/1384752894-10974-1-git-send-email-namhyung@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
 tools/perf/builtin-script.c | 11 +++++------
 1 file changed, 5 insertions(+), 6 deletions(-)

diff --git a/tools/perf/builtin-script.c b/tools/perf/builtin-script.c
index baf1798..b392770 100644
--- a/tools/perf/builtin-script.c
+++ b/tools/perf/builtin-script.c
@@ -288,7 +288,6 @@ static void print_sample_start(struct perf_sample *sample,
 			       struct perf_evsel *evsel)
 {
 	struct perf_event_attr *attr = &evsel->attr;
-	const char *evname = NULL;
 	unsigned long secs;
 	unsigned long usecs;
 	unsigned long long nsecs;
@@ -323,11 +322,6 @@ static void print_sample_start(struct perf_sample *sample,
 		usecs = nsecs / NSECS_PER_USEC;
 		printf("%5lu.%06lu: ", secs, usecs);
 	}
-
-	if (PRINT_FIELD(EVNAME)) {
-		evname = perf_evsel__name(evsel);
-		printf("%s: ", evname ? evname : "[unknown]");
-	}
 }
 
 static bool is_bts_event(struct perf_event_attr *attr)
@@ -434,6 +428,11 @@ static void process_event(union perf_event *event, struct perf_sample *sample,
 
 	print_sample_start(sample, thread, evsel);
 
+	if (PRINT_FIELD(EVNAME)) {
+		const char *evname = perf_evsel__name(evsel);
+		printf("%s: ", evname ? evname : "[unknown]");
+	}
+
 	if (is_bts_event(attr)) {
 		print_sample_bts(event, sample, evsel, machine, thread);
 		return;