Skip to contentSkip to conversation

perf trace: Infrastructure to show COMM strings for syscalls returning PIDs

tip:perf/core tip-bot for Arnaldo Carvalho de Melo 1 participant 1 message Apr 13, 2016 perf events

lore
Share & tools
lore

tip-bot for Arnaldo Carvalho de Melo

author merge bot
#0 lore raw
Commit-ID:  11c8e39f5133aed9e0f8ffc624c7d5f64c97bc79
Gitweb:     http://git.kernel.org/tip/11c8e39f5133aed9e0f8ffc624c7d5f64c97bc79
Author:     Arnaldo Carvalho de Melo <[email protected]>
AuthorDate: Wed, 6 Apr 2016 14:33:07 -0300
Committer:  Arnaldo Carvalho de Melo <[email protected]>
CommitDate: Wed, 6 Apr 2016 14:37:25 -0300

perf trace: Infrastructure to show COMM strings for syscalls returning PIDs

Starting with clone, waitid and wait4:

  # trace -e waitid,wait4
     1.385 ( 1.385 ms): bash/12122 wait4(upid: -1, stat_addr: 0x7ffe0cee1720, options: UNTRACED|CONTINUED) = 1210 (ls)
     1.426 ( 0.002 ms): bash/12122 wait4(upid: -1, stat_addr: 0x7ffe0cee1150, options: NOHANG|UNTRACED|CONTINUED) = 0
     3.293 ( 0.604 ms): bash/1211 wait4(upid: -1, stat_addr: 0x7ffe0cee0560                             ) = 1214 (sed)
     3.342 ( 0.002 ms): bash/1211 wait4(upid: -1, stat_addr: 0x7ffe0cee01d0, options: NOHANG            ) = -1 ECHILD No child processes
     3.576 ( 0.016 ms): bash/12122 wait4(upid: -1, stat_addr: 0x7ffe0cee0550, options: NOHANG|UNTRACED|CONTINUED) = 1211 (bash)
  ^C# trace -e clone
     0.027 ( 0.000 ms): systemd/1  ... [continued]: clone()) = 1227 (systemd)
     0.050 ( 0.000 ms): systemd/1227  ... [continued]: clone()) = 0
  ^C[root@jouet ~]#
Cc Adrian Hunter <[email protected]>
Cc David Ahern <[email protected]>
Cc Jiri Olsa <[email protected]>
Cc Namhyung Kim <[email protected]>
Cc Wang Nan <[email protected]>
Link http://lkml.kernel.org/n/[email protected] open here
Signed-off-by Arnaldo Carvalho de Melo <[email protected]>
---
 tools/perf/builtin-trace.c | 19 +++++++++++++++----
 1 file changed, 15 insertions(+), 4 deletions(-)
tools/perf/builtin-trace.c +15 -4
index 9a6c7b1..22a4901 100644
@@ -1082,6 +1082,7 @@ static struct syscall_fmt {
 	size_t	   (*arg_scnprintf[6])(char *bf, size_t size, struct syscall_arg *arg);
 	void	   *arg_parm[6];
 	bool	   errmsg;
+	bool	   errpid;
 	bool	   timeout;
 	bool	   hexret;
 } syscall_fmts[] = {

@@ -1099,6 +1100,7 @@ static struct syscall_fmt {
 	{ .name	    = "chroot",	    .errmsg = true,
 	  .arg_scnprintf = { [0] = SCA_FILENAME, /* filename */ }, },
 	{ .name     = "clock_gettime",  .errmsg = true, STRARRAY(0, clk_id, clockid), },
+	{ .name	    = "clone",	    .errpid = true, },
 	{ .name	    = "close",	    .errmsg = true,
 	  .arg_scnprintf = { [0] = SCA_CLOSE_FD, /* fd */ }, },
 	{ .name	    = "connect",    .errmsg = true, },

@@ -1365,9 +1367,9 @@ static struct syscall_fmt {
 	  .arg_scnprintf = { [0] = SCA_FILENAME, /* filename */ }, },
 	{ .name	    = "vmsplice",  .errmsg = true,
 	  .arg_scnprintf = { [0] = SCA_FD, /* fd */ }, },
-	{ .name	    = "wait4",	    .errmsg = true,
+	{ .name	    = "wait4",	    .errpid = true,
 	  .arg_scnprintf = { [2] = SCA_WAITID_OPTIONS, /* options */ }, },
-	{ .name	    = "waitid",	    .errmsg = true,
+	{ .name	    = "waitid",	    .errpid = true,
 	  .arg_scnprintf = { [3] = SCA_WAITID_OPTIONS, /* options */ }, },
 	{ .name	    = "write",	    .errmsg = true,
 	  .arg_scnprintf = { [0] = SCA_FD, /* fd */ }, },

@@ -2156,7 +2158,7 @@ static int trace__sys_exit(struct trace *trace, struct perf_evsel *evsel,
 	if (sc->fmt == NULL) {
 signed_print:
 		fprintf(trace->output, ") = %ld", ret);
-	} else if (ret < 0 && sc->fmt->errmsg) {
+	} else if (ret < 0 && (sc->fmt->errmsg || sc->fmt->errpid)) {
 		char bf[STRERR_BUFSIZE];
 		const char *emsg = strerror_r(-ret, bf, sizeof(bf)),
 			   *e = audit_errno_to_name(-ret);

@@ -2166,7 +2168,16 @@ signed_print:
 		fprintf(trace->output, ") = 0 Timeout");
 	else if (sc->fmt->hexret)
 		fprintf(trace->output, ") = %#lx", ret);
-	else
+	else if (sc->fmt->errpid) {
+		struct thread *child = machine__find_thread(trace->host, ret, ret);
+
+		if (child != NULL) {
+			fprintf(trace->output, ") = %ld", ret);
+			if (child->comm_set)
+				fprintf(trace->output, " (%s)", thread__comm_str(child));
+			thread__put(child);
+		}
+	} else
 		goto signed_print;
 
 	fputc('\n', trace->output);