Commit 75b757ca90469e990e6901f4a9497fe4161f7f5a

Authored by Arnaldo Carvalho de Melo
1 parent 3d903aa74a

perf trace: Show path associated with fd in live sessions

For live sessions we can just access /proc to map an fd to its path, on
a best effort way, i.e. sometimes the fd will have gone away when we try
to do the mapping, as it is done in a lazy way, only when a reference to
such fd is made then the path will be looked up in /proc.

This is disabled when processing perf.data files, where we will have to
have a way to get getname events, be it via an on-the-fly 'perf probe'
event or after a vfs_getname tracepoint is added to the kernel.

A first step will be to synthesize such event for the use cases where
the threads in the monitored workload exist already.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Mike Galbraith <efault@gmx.de>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/n/tip-1r1ti33ye1666jezu2d8q1c3@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>

Showing 1 changed file with 237 additions and 16 deletions Side-by-side Diff

tools/perf/builtin-trace.c
... ... @@ -36,6 +36,8 @@
36 36  
37 37 struct syscall_arg {
38 38 unsigned long val;
  39 + struct thread *thread;
  40 + struct trace *trace;
39 41 void *parm;
40 42 u8 idx;
41 43 u8 mask;
... ... @@ -65,6 +67,29 @@
65 67  
66 68 #define SCA_STRARRAY syscall_arg__scnprintf_strarray
67 69  
  70 +static size_t syscall_arg__scnprintf_fd(char *bf, size_t size,
  71 + struct syscall_arg *arg);
  72 +
  73 +#define SCA_FD syscall_arg__scnprintf_fd
  74 +
  75 +static size_t syscall_arg__scnprintf_fd_at(char *bf, size_t size,
  76 + struct syscall_arg *arg)
  77 +{
  78 + int fd = arg->val;
  79 +
  80 + if (fd == AT_FDCWD)
  81 + return scnprintf(bf, size, "CWD");
  82 +
  83 + return syscall_arg__scnprintf_fd(bf, size, arg);
  84 +}
  85 +
  86 +#define SCA_FDAT syscall_arg__scnprintf_fd_at
  87 +
  88 +static size_t syscall_arg__scnprintf_close_fd(char *bf, size_t size,
  89 + struct syscall_arg *arg);
  90 +
  91 +#define SCA_CLOSE_FD syscall_arg__scnprintf_close_fd
  92 +
68 93 static size_t syscall_arg__scnprintf_hex(char *bf, size_t size,
69 94 struct syscall_arg *arg)
70 95 {
71 96  
72 97  
73 98  
74 99  
75 100  
76 101  
77 102  
... ... @@ -613,28 +638,84 @@
613 638 { .name = "brk", .hexret = true,
614 639 .arg_scnprintf = { [0] = SCA_HEX, /* brk */ }, },
615 640 { .name = "clock_gettime", .errmsg = true, STRARRAY(0, clk_id, clockid), },
  641 + { .name = "close", .errmsg = true,
  642 + .arg_scnprintf = { [0] = SCA_CLOSE_FD, /* fd */ }, },
616 643 { .name = "connect", .errmsg = true, },
  644 + { .name = "dup", .errmsg = true,
  645 + .arg_scnprintf = { [0] = SCA_FD, /* fd */ }, },
  646 + { .name = "dup2", .errmsg = true,
  647 + .arg_scnprintf = { [0] = SCA_FD, /* fd */ }, },
  648 + { .name = "dup3", .errmsg = true,
  649 + .arg_scnprintf = { [0] = SCA_FD, /* fd */ }, },
617 650 { .name = "epoll_ctl", .errmsg = true, STRARRAY(1, op, epoll_ctl_ops), },
618 651 { .name = "eventfd2", .errmsg = true,
619 652 .arg_scnprintf = { [1] = SCA_EFD_FLAGS, /* flags */ }, },
620   - { .name = "fcntl", .errmsg = true, STRARRAY(1, cmd, fcntl_cmds), },
  653 + { .name = "faccessat", .errmsg = true,
  654 + .arg_scnprintf = { [0] = SCA_FDAT, /* dfd */ }, },
  655 + { .name = "fadvise64", .errmsg = true,
  656 + .arg_scnprintf = { [0] = SCA_FD, /* fd */ }, },
  657 + { .name = "fallocate", .errmsg = true,
  658 + .arg_scnprintf = { [0] = SCA_FD, /* fd */ }, },
  659 + { .name = "fchdir", .errmsg = true,
  660 + .arg_scnprintf = { [0] = SCA_FD, /* fd */ }, },
  661 + { .name = "fchmod", .errmsg = true,
  662 + .arg_scnprintf = { [0] = SCA_FD, /* fd */ }, },
  663 + { .name = "fchmodat", .errmsg = true,
  664 + .arg_scnprintf = { [0] = SCA_FDAT, /* fd */ }, },
  665 + { .name = "fchown", .errmsg = true,
  666 + .arg_scnprintf = { [0] = SCA_FD, /* fd */ }, },
  667 + { .name = "fchownat", .errmsg = true,
  668 + .arg_scnprintf = { [0] = SCA_FDAT, /* fd */ }, },
  669 + { .name = "fcntl", .errmsg = true,
  670 + .arg_scnprintf = { [0] = SCA_FD, /* fd */
  671 + [1] = SCA_STRARRAY, /* cmd */ },
  672 + .arg_parm = { [1] = &strarray__fcntl_cmds, /* cmd */ }, },
  673 + { .name = "fdatasync", .errmsg = true,
  674 + .arg_scnprintf = { [0] = SCA_FD, /* fd */ }, },
621 675 { .name = "flock", .errmsg = true,
622   - .arg_scnprintf = { [1] = SCA_FLOCK, /* cmd */ }, },
623   - { .name = "fstat", .errmsg = true, .alias = "newfstat", },
624   - { .name = "fstatat", .errmsg = true, .alias = "newfstatat", },
  676 + .arg_scnprintf = { [0] = SCA_FD, /* fd */
  677 + [1] = SCA_FLOCK, /* cmd */ }, },
  678 + { .name = "fsetxattr", .errmsg = true,
  679 + .arg_scnprintf = { [0] = SCA_FD, /* fd */ }, },
  680 + { .name = "fstat", .errmsg = true, .alias = "newfstat",
  681 + .arg_scnprintf = { [0] = SCA_FD, /* fd */ }, },
  682 + { .name = "fstatat", .errmsg = true, .alias = "newfstatat",
  683 + .arg_scnprintf = { [0] = SCA_FDAT, /* dfd */ }, },
  684 + { .name = "fstatfs", .errmsg = true,
  685 + .arg_scnprintf = { [0] = SCA_FD, /* fd */ }, },
  686 + { .name = "fsync", .errmsg = true,
  687 + .arg_scnprintf = { [0] = SCA_FD, /* fd */ }, },
  688 + { .name = "ftruncate", .errmsg = true,
  689 + .arg_scnprintf = { [0] = SCA_FD, /* fd */ }, },
625 690 { .name = "futex", .errmsg = true,
626 691 .arg_scnprintf = { [1] = SCA_FUTEX_OP, /* op */ }, },
  692 + { .name = "futimesat", .errmsg = true,
  693 + .arg_scnprintf = { [0] = SCA_FDAT, /* fd */ }, },
  694 + { .name = "getdents", .errmsg = true,
  695 + .arg_scnprintf = { [0] = SCA_FD, /* fd */ }, },
  696 + { .name = "getdents64", .errmsg = true,
  697 + .arg_scnprintf = { [0] = SCA_FD, /* fd */ }, },
627 698 { .name = "getitimer", .errmsg = true, STRARRAY(0, which, itimers), },
628 699 { .name = "getrlimit", .errmsg = true, STRARRAY(0, resource, rlimit_resources), },
629 700 { .name = "ioctl", .errmsg = true,
630   - .arg_scnprintf = { [2] = SCA_HEX, /* arg */ }, },
  701 + .arg_scnprintf = { [0] = SCA_FD, /* fd */
  702 + [2] = SCA_HEX, /* arg */ }, },
631 703 { .name = "kill", .errmsg = true,
632 704 .arg_scnprintf = { [1] = SCA_SIGNUM, /* sig */ }, },
633   - { .name = "lseek", .errmsg = true, STRARRAY(2, whence, whences), },
  705 + { .name = "linkat", .errmsg = true,
  706 + .arg_scnprintf = { [0] = SCA_FDAT, /* fd */ }, },
  707 + { .name = "lseek", .errmsg = true,
  708 + .arg_scnprintf = { [0] = SCA_FD, /* fd */
  709 + [2] = SCA_STRARRAY, /* whence */ },
  710 + .arg_parm = { [2] = &strarray__whences, /* whence */ }, },
634 711 { .name = "lstat", .errmsg = true, .alias = "newlstat", },
635 712 { .name = "madvise", .errmsg = true,
636 713 .arg_scnprintf = { [0] = SCA_HEX, /* start */
637 714 [2] = SCA_MADV_BHV, /* behavior */ }, },
  715 + { .name = "mkdirat", .errmsg = true,
  716 + .arg_scnprintf = { [0] = SCA_FDAT, /* fd */ }, },
  717 + { .name = "mknodat", .errmsg = true,
  718 + .arg_scnprintf = { [0] = SCA_FDAT, /* fd */ }, },
638 719 { .name = "mlock", .errmsg = true,
639 720 .arg_scnprintf = { [0] = SCA_HEX, /* addr */ }, },
640 721 { .name = "mlockall", .errmsg = true,
641 722  
642 723  
643 724  
644 725  
645 726  
... ... @@ -653,26 +734,45 @@
653 734 .arg_scnprintf = { [0] = SCA_HEX, /* addr */ }, },
654 735 { .name = "munmap", .errmsg = true,
655 736 .arg_scnprintf = { [0] = SCA_HEX, /* addr */ }, },
  737 + { .name = "name_to_handle_at", .errmsg = true,
  738 + .arg_scnprintf = { [0] = SCA_FDAT, /* dfd */ }, },
  739 + { .name = "newfstatat", .errmsg = true,
  740 + .arg_scnprintf = { [0] = SCA_FDAT, /* dfd */ }, },
656 741 { .name = "open", .errmsg = true,
657 742 .arg_scnprintf = { [1] = SCA_OPEN_FLAGS, /* flags */ }, },
658 743 { .name = "open_by_handle_at", .errmsg = true,
659   - .arg_scnprintf = { [2] = SCA_OPEN_FLAGS, /* flags */ }, },
  744 + .arg_scnprintf = { [0] = SCA_FDAT, /* dfd */
  745 + [2] = SCA_OPEN_FLAGS, /* flags */ }, },
660 746 { .name = "openat", .errmsg = true,
661   - .arg_scnprintf = { [2] = SCA_OPEN_FLAGS, /* flags */ }, },
  747 + .arg_scnprintf = { [0] = SCA_FDAT, /* dfd */
  748 + [2] = SCA_OPEN_FLAGS, /* flags */ }, },
662 749 { .name = "pipe2", .errmsg = true,
663 750 .arg_scnprintf = { [1] = SCA_PIPE_FLAGS, /* flags */ }, },
664 751 { .name = "poll", .errmsg = true, .timeout = true, },
665 752 { .name = "ppoll", .errmsg = true, .timeout = true, },
666   - { .name = "pread", .errmsg = true, .alias = "pread64", },
  753 + { .name = "pread", .errmsg = true, .alias = "pread64",
  754 + .arg_scnprintf = { [0] = SCA_FD, /* fd */ }, },
  755 + { .name = "preadv", .errmsg = true, .alias = "pread",
  756 + .arg_scnprintf = { [0] = SCA_FD, /* fd */ }, },
667 757 { .name = "prlimit64", .errmsg = true, STRARRAY(1, resource, rlimit_resources), },
668   - { .name = "pwrite", .errmsg = true, .alias = "pwrite64", },
669   - { .name = "read", .errmsg = true, },
  758 + { .name = "pwrite", .errmsg = true, .alias = "pwrite64",
  759 + .arg_scnprintf = { [0] = SCA_FD, /* fd */ }, },
  760 + { .name = "pwritev", .errmsg = true,
  761 + .arg_scnprintf = { [0] = SCA_FD, /* fd */ }, },
  762 + { .name = "read", .errmsg = true,
  763 + .arg_scnprintf = { [0] = SCA_FD, /* fd */ }, },
  764 + { .name = "readlinkat", .errmsg = true,
  765 + .arg_scnprintf = { [0] = SCA_FDAT, /* dfd */ }, },
  766 + { .name = "readv", .errmsg = true,
  767 + .arg_scnprintf = { [0] = SCA_FD, /* fd */ }, },
670 768 { .name = "recvfrom", .errmsg = true,
671 769 .arg_scnprintf = { [3] = SCA_MSG_FLAGS, /* flags */ }, },
672 770 { .name = "recvmmsg", .errmsg = true,
673 771 .arg_scnprintf = { [3] = SCA_MSG_FLAGS, /* flags */ }, },
674 772 { .name = "recvmsg", .errmsg = true,
675 773 .arg_scnprintf = { [2] = SCA_MSG_FLAGS, /* flags */ }, },
  774 + { .name = "renameat", .errmsg = true,
  775 + .arg_scnprintf = { [0] = SCA_FDAT, /* dfd */ }, },
676 776 { .name = "rt_sigaction", .errmsg = true,
677 777 .arg_scnprintf = { [0] = SCA_SIGNUM, /* sig */ }, },
678 778 { .name = "rt_sigprocmask", .errmsg = true, STRARRAY(0, how, sighow), },
... ... @@ -689,6 +789,8 @@
689 789 .arg_scnprintf = { [3] = SCA_MSG_FLAGS, /* flags */ }, },
690 790 { .name = "setitimer", .errmsg = true, STRARRAY(0, which, itimers), },
691 791 { .name = "setrlimit", .errmsg = true, STRARRAY(0, resource, rlimit_resources), },
  792 + { .name = "shutdown", .errmsg = true,
  793 + .arg_scnprintf = { [0] = SCA_FD, /* fd */ }, },
692 794 { .name = "socket", .errmsg = true,
693 795 .arg_scnprintf = { [0] = SCA_STRARRAY, /* family */
694 796 [1] = SCA_SK_TYPE, /* type */ },
695 797  
... ... @@ -698,11 +800,21 @@
698 800 [1] = SCA_SK_TYPE, /* type */ },
699 801 .arg_parm = { [0] = &strarray__socket_families, /* family */ }, },
700 802 { .name = "stat", .errmsg = true, .alias = "newstat", },
  803 + { .name = "symlinkat", .errmsg = true,
  804 + .arg_scnprintf = { [0] = SCA_FDAT, /* dfd */ }, },
701 805 { .name = "tgkill", .errmsg = true,
702 806 .arg_scnprintf = { [2] = SCA_SIGNUM, /* sig */ }, },
703 807 { .name = "tkill", .errmsg = true,
704 808 .arg_scnprintf = { [1] = SCA_SIGNUM, /* sig */ }, },
705 809 { .name = "uname", .errmsg = true, .alias = "newuname", },
  810 + { .name = "unlinkat", .errmsg = true,
  811 + .arg_scnprintf = { [0] = SCA_FDAT, /* dfd */ }, },
  812 + { .name = "utimensat", .errmsg = true,
  813 + .arg_scnprintf = { [0] = SCA_FDAT, /* dirfd */ }, },
  814 + { .name = "write", .errmsg = true,
  815 + .arg_scnprintf = { [0] = SCA_FD, /* fd */ }, },
  816 + { .name = "writev", .errmsg = true,
  817 + .arg_scnprintf = { [0] = SCA_FD, /* fd */ }, },
706 818 };
707 819  
708 820 static int syscall_fmt__cmp(const void *name, const void *fmtp)
709 821  
... ... @@ -747,11 +859,20 @@
747 859 unsigned long nr_events;
748 860 char *entry_str;
749 861 double runtime_ms;
  862 + struct {
  863 + int max;
  864 + char **table;
  865 + } paths;
750 866 };
751 867  
752 868 static struct thread_trace *thread_trace__new(void)
753 869 {
754   - return zalloc(sizeof(struct thread_trace));
  870 + struct thread_trace *ttrace = zalloc(sizeof(struct thread_trace));
  871 +
  872 + if (ttrace)
  873 + ttrace->paths.max = -1;
  874 +
  875 + return ttrace;
755 876 }
756 877  
757 878 static struct thread_trace *thread__trace(struct thread *thread, FILE *fp)
... ... @@ -792,6 +913,7 @@
792 913 unsigned long nr_events;
793 914 struct strlist *ev_qualifier;
794 915 bool not_ev_qualifier;
  916 + bool live;
795 917 struct intlist *tid_list;
796 918 struct intlist *pid_list;
797 919 bool sched;
... ... @@ -801,6 +923,98 @@
801 923 double runtime_ms;
802 924 };
803 925  
  926 +static int thread__read_fd_path(struct thread *thread, int fd)
  927 +{
  928 + struct thread_trace *ttrace = thread->priv;
  929 + char linkname[PATH_MAX], pathname[PATH_MAX];
  930 + struct stat st;
  931 + int ret;
  932 +
  933 + if (thread->pid_ == thread->tid) {
  934 + scnprintf(linkname, sizeof(linkname),
  935 + "/proc/%d/fd/%d", thread->pid_, fd);
  936 + } else {
  937 + scnprintf(linkname, sizeof(linkname),
  938 + "/proc/%d/task/%d/fd/%d", thread->pid_, thread->tid, fd);
  939 + }
  940 +
  941 + if (lstat(linkname, &st) < 0 || st.st_size + 1 > (off_t)sizeof(pathname))
  942 + return -1;
  943 +
  944 + ret = readlink(linkname, pathname, sizeof(pathname));
  945 +
  946 + if (ret < 0 || ret > st.st_size)
  947 + return -1;
  948 +
  949 + pathname[ret] = '\0';
  950 +
  951 + if (fd > ttrace->paths.max) {
  952 + char **npath = realloc(ttrace->paths.table, (fd + 1) * sizeof(char *));
  953 +
  954 + if (npath == NULL)
  955 + return -1;
  956 +
  957 + if (ttrace->paths.max != -1) {
  958 + memset(npath + ttrace->paths.max + 1, 0,
  959 + (fd - ttrace->paths.max) * sizeof(char *));
  960 + } else {
  961 + memset(npath, 0, (fd + 1) * sizeof(char *));
  962 + }
  963 +
  964 + ttrace->paths.table = npath;
  965 + ttrace->paths.max = fd;
  966 + }
  967 +
  968 + ttrace->paths.table[fd] = strdup(pathname);
  969 +
  970 + return ttrace->paths.table[fd] != NULL ? 0 : -1;
  971 +}
  972 +
  973 +static const char *thread__fd_path(struct thread *thread, int fd, bool live)
  974 +{
  975 + struct thread_trace *ttrace = thread->priv;
  976 +
  977 + if (ttrace == NULL)
  978 + return NULL;
  979 +
  980 + if (fd < 0)
  981 + return NULL;
  982 +
  983 + if ((fd > ttrace->paths.max || ttrace->paths.table[fd] == NULL) &&
  984 + (!live || thread__read_fd_path(thread, fd)))
  985 + return NULL;
  986 +
  987 + return ttrace->paths.table[fd];
  988 +}
  989 +
  990 +static size_t syscall_arg__scnprintf_fd(char *bf, size_t size,
  991 + struct syscall_arg *arg)
  992 +{
  993 + int fd = arg->val;
  994 + size_t printed = scnprintf(bf, size, "%d", fd);
  995 + const char *path = thread__fd_path(arg->thread, fd, arg->trace->live);
  996 +
  997 + if (path)
  998 + printed += scnprintf(bf + printed, size - printed, "<%s>", path);
  999 +
  1000 + return printed;
  1001 +}
  1002 +
  1003 +static size_t syscall_arg__scnprintf_close_fd(char *bf, size_t size,
  1004 + struct syscall_arg *arg)
  1005 +{
  1006 + int fd = arg->val;
  1007 + size_t printed = syscall_arg__scnprintf_fd(bf, size, arg);
  1008 + struct thread_trace *ttrace = arg->thread->priv;
  1009 +
  1010 + if (ttrace && fd >= 0 && fd <= ttrace->paths.max) {
  1011 + free(ttrace->paths.table[fd]);
  1012 + ttrace->paths.table[fd] = NULL;
  1013 + }
  1014 +
  1015 + return printed;
  1016 +}
  1017 +
804 1018 static bool trace__filter_duration(struct trace *trace, double t)
805 1019 {
806 1020 return t < (trace->duration_filter * NSEC_PER_MSEC);
... ... @@ -969,7 +1183,8 @@
969 1183 }
970 1184  
971 1185 static size_t syscall__scnprintf_args(struct syscall *sc, char *bf, size_t size,
972   - unsigned long *args)
  1186 + unsigned long *args, struct trace *trace,
  1187 + struct thread *thread)
973 1188 {
974 1189 size_t printed = 0;
975 1190  
... ... @@ -977,8 +1192,10 @@
977 1192 struct format_field *field;
978 1193 u8 bit = 1;
979 1194 struct syscall_arg arg = {
980   - .idx = 0,
981   - .mask = 0,
  1195 + .idx = 0,
  1196 + .mask = 0,
  1197 + .trace = trace,
  1198 + .thread = thread,
982 1199 };
983 1200  
984 1201 for (field = sc->tp_format->format.fields->next; field;
... ... @@ -1111,7 +1328,8 @@
1111 1328 msg = ttrace->entry_str;
1112 1329 printed += scnprintf(msg + printed, 1024 - printed, "%s(", sc->name);
1113 1330  
1114   - printed += syscall__scnprintf_args(sc, msg + printed, 1024 - printed, args);
  1331 + printed += syscall__scnprintf_args(sc, msg + printed, 1024 - printed,
  1332 + args, trace, thread);
1115 1333  
1116 1334 if (!strcmp(sc->name, "exit_group") || !strcmp(sc->name, "exit")) {
1117 1335 if (!trace->duration_filter) {
... ... @@ -1292,6 +1510,8 @@
1292 1510 unsigned long before;
1293 1511 const bool forks = argc > 0;
1294 1512  
  1513 + trace->live = true;
  1514 +
1295 1515 if (evlist == NULL) {
1296 1516 fprintf(trace->output, "Not enough memory to run!\n");
1297 1517 goto out;
... ... @@ -1423,6 +1643,7 @@
1423 1643 out_delete_evlist:
1424 1644 perf_evlist__delete(evlist);
1425 1645 out:
  1646 + trace->live = false;
1426 1647 return err;
1427 1648 }
1428 1649