aboutsummaryrefslogtreecommitdiffstats
path: root/tools/perf/builtin-trace.c (follow)
AgeCommit message (Collapse)AuthorFilesLines
2017-09-01perf trace: Support syscall name globbingArnaldo Carvalho de Melo1-4/+35
So now we can use: # perf trace -e pkey_* 532.784 ( 0.006 ms): pkey/16018 pkey_alloc(init_val: DISABLE_WRITE) = -1 EINVAL Invalid argument 532.795 ( 0.004 ms): pkey/16018 pkey_mprotect(start: 0x7f380d0a6000, len: 4096, prot: READ|WRITE, pkey: -1) = 0 532.801 ( 0.002 ms): pkey/16018 pkey_free(pkey: -1 ) = -1 EINVAL Invalid argument ^C[root@jouet ~]# Or '-e epoll*', '-e *msg*', etc. Combining syscall names with perf events, tracepoints, etc, continues to be valid, i.e. this is possible: # perf probe -L sys_nanosleep <SyS_nanosleep@/home/acme/git/linux/kernel/time/hrtimer.c:0> 0 SYSCALL_DEFINE2(nanosleep, struct timespec __user *, rqtp, struct timespec __user *, rmtp) { struct timespec64 tu; 5 if (get_timespec64(&tu, rqtp)) 6 return -EFAULT; if (!timespec64_valid(&tu)) 9 return -EINVAL; 11 current->restart_block.nanosleep.type = rmtp ? TT_NATIVE : TT_NONE; 12 current->restart_block.nanosleep.rmtp = rmtp; 13 return hrtimer_nanosleep(&tu, HRTIMER_MODE_REL, CLOCK_MONOTONIC); } # perf probe my_probe="sys_nanosleep:12 rmtp" Added new event: probe:my_probe (on sys_nanosleep:12 with rmtp) You can now use it in all perf tools, such as: perf record -e probe:my_probe -aR sleep 1 # # perf trace -e probe:my_probe/max-stack=5/,*sleep sleep 1 0.427 ( 0.003 ms): sleep/16690 nanosleep(rqtp: 0x7ffefc245090) ... 0.430 ( ): probe:my_probe:(ffffffffbd112923) rmtp=0) sys_nanosleep ([kernel.kallsyms]) do_syscall_64 ([kernel.kallsyms]) return_from_SYSCALL_64 ([kernel.kallsyms]) __nanosleep_nocancel (/usr/lib64/libc-2.25.so) 0.427 (1000.208 ms): sleep/16690 ... [continued]: nanosleep()) = 0 # Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-elycoi8wy6y0w9dkj7ox1mzz@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-08-28perf trace beauty: Beautify pkey_{alloc,free,mprotect} argumentsArnaldo Carvalho de Melo1-0/+8
Reuse 'mprotect' beautifiers for 'pkey_mprotect'. System wide tracing pkey_alloc, pkey_free and pkey_mprotect calls, with backtraces: # perf trace -e pkey_alloc,pkey_mprotect,pkey_free --max-stack=5 0.000 ( 0.011 ms): pkey/7818 pkey_alloc(init_val: DISABLE_ACCESS|DISABLE_WRITE) = -1 EINVAL Invalid argument syscall (/usr/lib64/libc-2.25.so) pkey_alloc (/home/acme/c/pkey) 0.022 ( 0.003 ms): pkey/7818 pkey_mprotect(start: 0x7f28c3890000, len: 4096, prot: READ|WRITE, pkey: -1) = 0 syscall (/usr/lib64/libc-2.25.so) pkey_mprotect (/home/acme/c/pkey) 0.030 ( 0.002 ms): pkey/7818 pkey_free(pkey: -1 ) = -1 EINVAL Invalid argument syscall (/usr/lib64/libc-2.25.so) pkey_free (/home/acme/c/pkey) The tools/include/uapi/asm-generic/mman-common.h file is used to find the access rights defines for the pkey_alloc syscall second argument. Since we have the detector of changes for the tools/include header files versus its kernel origin (include/uapi/asm-generic/mman-common.h), we'll get whatever new flag appears for that argument automatically. This method should be used in other cases where it is easy to generate those flags tables because the header has properly namespaced defines like PKEY_DISABLE_ACCESS and PKEY_DISABLE_WRITE. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Arnd Bergmann <arnd@arndb.de> Cc: Dave Hansen <dave.hansen@linux.intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-3xq5312qlks7wtfzv2sk3nct@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-08-17perf trace: Fix off by one string allocation problemArnaldo Carvalho de Melo1-1/+1
We need to consider the null terminator, oops, fix it. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Fixes: 017037ff3d0b ("perf trace: Allow specifying list of syscalls and events in -e/--expr/--event") Link: http://lkml.kernel.org/n/tip-j79jpqqe91gvxqmsgxgfn2ni@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-08-01perf trace beauty ioctl: Improve 'cmd' beautifierArnaldo Carvalho de Melo1-43/+1
By using the _IOC_(DIR,NR,TYPE,SIZE) macros to lookup a 'type' keyed table that then gets indexed by 'nr', falling back to a notation similar to the one used by 'strace', only more compact, i.e.: 474.356 ( 0.007 ms): gnome-shell/22401 ioctl(fd: 8</dev/dri/card0>, cmd: (READ|WRITE, 0x64, 0xae, 0x1c), arg: 0x7ffc934f7880) = 0 474.369 ( 0.053 ms): gnome-shell/22401 ioctl(fd: 8</dev/dri/card0>, cmd: (READ|WRITE, 0x64, 0xb0, 0x18), arg: 0x7ffc934f77d0) = 0 505.055 ( 0.014 ms): gnome-shell/22401 ioctl(fd: 8</dev/dri/card0>, cmd: (READ|WRITE, 0x64, 0xaf, 0x4), arg: 0x7ffc934f741c) = 0 This also moves it out of builtin-trace.c and into trace/beauty/ioctl.c to better compartimentalize all these formatters. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-s3enursdxsvnhdomh6qlte4g@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-07-20perf trace: Filter out 'sshd' in the tracer ancestry in syswide tracingArnaldo Carvalho de Melo1-1/+15
Avoiding a loop, so now its quite convenient to ssh to a machine and then simply do: # perf trace To trace all syscalls without causing a loop. This was possible using --filter-pids, i.e. once you noticed the loop, get the sshd pid and add it to --filter-pids, restarting the 'perf trace'. Now to figure out how to do that in a X terminal, the other common scenario, which is way more involved, as there are multiple processes communicating to process terminal activity... Using --filter-pids + '-e \!syscall,names,you,dont,need' may be a good approximation when having to do syswide tracing on your workstation. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-68rjeao9wnpylla41htk7xps@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-07-20perf trace: Introduce filter_loop_pids()Arnaldo Carvalho de Melo1-1/+11
No change in functionality, just to make clearer that what we want when filtering the tracer pid in a system wide tracing session is to avoid a feedback loop. This also paves the way for a more interesting loop avoidance algorithm, one that tries to figure out if we are in a ssh session, xterm, etc. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-5fcttc5kdjkcyp9404ezkuy9@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-07-20perf trace beauty clone: Beautify syscall argumentsArnaldo Carvalho de Melo1-1/+6
Now, syswide tracing, selected entries: # trace -e clone 24417.203 ( 0.158 ms): bash/11323 clone(flags: CHILD_CLEARTID|CHILD_SETTID|0x11, child_stack: 0, parent_tidptr: 0, child_tidptr: 0x7f0778e5c9d0, tls: 0x7f0778e5c700) = 11325 (bash) ? ( ? ): bash/11325 ... [continued]: clone()) = 0 24419.355 ( 0.093 ms): bash/10586 clone(flags: CHILD_CLEARTID|CHILD_SETTID|0x11, child_stack: 0, parent_tidptr: 0, child_tidptr: 0x7f0778e5c9d0, tls: 0x7f0778e5c700) = 11326 (bash) ? ( ? ): bash/11326 ... [continued]: clone()) = 0 24419.744 ( 0.102 ms): bash/11326 clone(flags: CHILD_CLEARTID|CHILD_SETTID|0x11, child_stack: 0, parent_tidptr: 0, child_tidptr: 0x7f0778e5c9d0, tls: 0x7f0778e5c700) = 11327 (bash) ? ( ? ): bash/11327 ... [continued]: clone()) = 0 24420.138 ( 0.105 ms): bash/11327 clone(flags: CHILD_CLEARTID|CHILD_SETTID|0x11, child_stack: 0, parent_tidptr: 0, child_tidptr: 0x7f0778e5c9d0, tls: 0x7f0778e5c700) = 11328 (bash) ? ( ? ): bash/11328 ... [continued]: clone()) = 0 35747.722 ( 0.044 ms): gpg-agent/18087 clone(flags: VM|FS|FILES|SIGHAND|THREAD|SYSVSEM|SETTLS|PARENT_SETTID|CHILD_CLEARTID, child_stack: 0x7ff0755f6ff0, parent_tidptr: 0x7ff0755f79d0, child_tidptr: 0x7ff0755f79d0, tls: 0x7ff0755f7700) = 11329 (gpg-agent) ? ( ? ): gpg-agent/11329 ... [continued]: clone()) = 0 35748.359 ( 0.022 ms): gpg-agent/18087 clone(flags: VM|FS|FILES|SIGHAND|THREAD|SYSVSEM|SETTLS|PARENT_SETTID|CHILD_CLEARTID, child_stack: 0x7ff075df7ff0, parent_tidptr: 0x7ff075df89d0, child_tidptr: 0x7ff075df89d0, tls: 0x7ff075df8700) = 11330 (gpg-agent) ? ( ? ): gpg-agent/11330 ... [continued]: clone()) = 0 35781.422 ( 0.452 ms): NetworkManager/1112 clone(flags: VM|FS|FILES|SIGHAND|THREAD|SYSVSEM|SETTLS|PARENT_SETTID|CHILD_CLEARTID, child_stack: 0x7f2f1fffedb0, parent_tidptr: 0x7f2f1ffff9d0, child_tidptr: 0x7f2f1ffff9d0, tls: 0x7f2f1ffff700) = 11331 (NetworkManager) ? ( ? ): NetworkManager/11331 ... [continued]: clone()) = 0 Need to improve the formatting of the second return, to the child, this cset only focused on the argument formatting. If we trace just one pid: # trace -e clone -p 19863 0.349 ( 0.025 ms): Chrome_IOThrea/19863 clone(flags: VM|FS|FILES|SIGHAND|THREAD|SYSVSEM|SETTLS|PARENT_SETTID|CHILD_CLEARTID, child_stack: 0x7ffb84eaac70, parent_tidptr: 0x7ffb84eab9d0, child_tidptr: 0x7ffb84eab9d0, tls: 0x7ffb84eab700) = 11637 (Chrome_IOThread) 0.392 ( 0.013 ms): Chrome_IOThrea/19863 clone(flags: VM|FS|FILES|SIGHAND|THREAD|SYSVSEM|SETTLS|PARENT_SETTID|CHILD_CLEARTID, child_stack: 0x7ffb664b8c70, parent_tidptr: 0x7ffb664b99d0, child_tidptr: 0x7ffb664b99d0, tls: 0x7ffb664b9700) = 11638 (Chrome_IOThread) 0.573 ( 0.015 ms): Chrome_IOThrea/19863 clone(flags: VM|FS|FILES|SIGHAND|THREAD|SYSVSEM|SETTLS|PARENT_SETTID|CHILD_CLEARTID, child_stack: 0x7ffb6046cc70, parent_tidptr: 0x7ffb6046d9d0, child_tidptr: 0x7ffb6046d9d0, tls: 0x7ffb6046d700) = 11639 (Chrome_IOThread) 0.617 ( 0.014 ms): Chrome_IOThrea/19863 clone(flags: VM|FS|FILES|SIGHAND|THREAD|SYSVSEM|SETTLS|PARENT_SETTID|CHILD_CLEARTID, child_stack: 0x7ffb730dcc70, parent_tidptr: 0x7ffb730dd9d0, child_tidptr: 0x7ffb730dd9d0, tls: 0x7ffb730dd700) = 11640 (Chrome_IOThread) 4.350 ( 0.065 ms): Chrome_IOThrea/19863 clone(flags: VM|FS|FILES|SIGHAND|THREAD|SYSVSEM|SETTLS|PARENT_SETTID|CHILD_CLEARTID, child_stack: 0x7ffb720d9c70, parent_tidptr: 0x7ffb720da9d0, child_tidptr: 0x7ffb720da9d0, tls: 0x7ffb720da700) = 11642 (Chrome_IOThread) 5.642 ( 0.079 ms): Chrome_IOThrea/19863 clone(flags: VM|FS|FILES|SIGHAND|THREAD|SYSVSEM|SETTLS|PARENT_SETTID|CHILD_CLEARTID, child_stack: 0x7ffb718d8c70, parent_tidptr: 0x7ffb718d99d0, child_tidptr: 0x7ffb718d99d0, tls: 0x7ffb718d9700) = 11643 (Chrome_IOThread) ^C# We'll also have to fix the argument ordering in different arches, probably having multiple syscall_fmt entries with each possible order and then use perf_evsel__env_arch() (if dealing with a perf.data file) or the current system info, for live sessions. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-am068uyubgj83snepolwhbfe@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-07-20perf trace: Allow specifying names to syscall arguments formattersArnaldo Carvalho de Melo1-2/+13
For tracepointless syscalls, like clone, otherwise get them from the tracepoint's /format file. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-ml5qvv1w5k96ghwhxpzzsmm3@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-07-20perf trace: Allow specifying number of syscall args for tracepointless syscallsArnaldo Carvalho de Melo1-1/+5
When we don't have syscalls:sys_{enter,exit}_NAME, we had to resort to dumping all the 6 syscall arguments, fix it by providing that info for such syscalls, like 'clone'. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-dfq1jtrxj8dqvqoeqqpr3slu@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-07-20perf trace: Ditch __syscall__arg_val() variant, not needed anymoreArnaldo Carvalho de Melo1-7/+2
All callers now can use syscall__arg_val(arg, idx), be it to iterate thru the syscall arguments while taking into account alignment, or to get values for other arguments that affect how the current argument should be formatted (think of fcntl's 'cmd' and 'arg' arguments). Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-wm5b156d8kro1r4y3b33eyta@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-07-20perf trace: Use the syscall_fmt formatters without a tracepointArnaldo Carvalho de Melo1-24/+30
Previously we only used the syscall_fmt when we had sc->tp_format set, i.e. when we found the (enter, exit) pair in tracefs/events/syscalls/. But we really only need to use what is in sc->arg_fmt to apply the arg beautifiers to the syscall argument values, so do it. With this we will be able to provide formatters to the "clone" syscall, which doesn't have entries in tracefs/events/syscalls/. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-y41nl41jrayjo5ucnde2peix@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-07-20perf trace: Allow allocating sc->arg_fmt even without the syscall tracepointArnaldo Carvalho de Melo1-10/+21
At least "clone" doesn't have (enter, exit) entries tracefs/events/syscalls/, but we can provide a syscall_fmt and use it instead, as will be done for "clone" in the next cset. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-o12kejgcxddyovn2hlg4gbim@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-07-20perf trace: Add missing ' = ' in the default formatting of syscall returnsArnaldo Carvalho de Melo1-1/+1
We lost it recently, put it back. Before: 789.499 ( 0.001 ms): libvirtd/1175 lseek(fd: 22, whence: CUR) 4328 After: 789.499 ( 0.001 ms): libvirtd/1175 lseek(fd: 22, whence: CUR) = 4328 Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Fixes: 1f63139c3f8a ("perf trace beauty: Simplify syscall return formatting") Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-07-18perf trace beauty: Simplify syscall return formattingArnaldo Carvalho de Melo1-128/+81
Removing syscall_fmt::err_msg and instead always formatting negative returns as errno values. With this we can remove a lot of entries that have no special handling besides the ones we can do by looking at the tracefs format files, i.e. the types for the fields (e.g. pid_t), well known names (e.g. fd). Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-rg9u7a3qqdnzo37d212vnz2o@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-07-18perf trace beauty fcntl: Do not suppress 'cmd' when zero, should be DUPFDArnaldo Carvalho de Melo1-1/+2
Before: 77059.513 ( 0.005 ms): bash/6649 fcntl(fd: 1</dev/pts/12>, arg: 10) = 10</dev/pts/12> After: 77059.513 ( 0.005 ms): bash/6649 fcntl(fd: 1</dev/pts/12>, cmd: DUPFD, arg: 10) = 10</dev/pts/12> Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-woois88uwcr4xu38xx1ihiwo@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-07-18perf trace: Allow syscall arg formatters to request non suppression of zerosArnaldo Carvalho de Melo1-1/+3
The 'perf trace' tool is suppressing args set to zero, with the exception of string tables (strarrays), which are kinda like enums, i.e. we have maps to go from numbers to strings. But the 'cmd' fcntl arg requires more specialized treatment, as its value will regulate if the next fcntl syscall arg, 'arg', should be ignored (not used) and also how to format the syscall return (fd, file flags, etc), so add a 'show_zero" bool to struct syscall_arg_fmt, to regulate this more explicitely. Will be used in a following patch with fcntl, here is just the mechanism. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-all738jctxets8ffyizp5lzo@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-07-18perf trace: Group per syscall arg formatter info into one structArnaldo Carvalho de Melo1-123/+133
Instead of having syscall_fmt.{arg_scnprintf,arg_parm}, introduce struct syscall_arg_fmt and have these two, paving the way for more state to change the formatting algorithms. For instance, in the 'fcntl' 'cmd' case it is better not to suppress it when being zero, showing instead its name "DUPFD". We had that in an ad-hoc way just for strarrays, but with more involved cases like fcntl, that can't be done with just a strarray, we'll need a ".show_zero" arg in the 'cmd' syscall_arg_fmt. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-ch06o2j72zbjx5xww4qp67au@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-07-18perf trace beauty: Export strarray for use in per-object beautifiersArnaldo Carvalho de Melo1-20/+7
Like will be done with fcntl(fd, F_GETLEASE, F_RDLCK|F_WRLCK|F_UNLCK) Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-3p11bgirtntjfmbixfkz8i2m@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-07-18perf trace beauty: Export the fd beautifier for use in more placesArnaldo Carvalho de Melo1-7/+1
Now that the beautifiers are being split into multiple source and object files, we will need more of them exported, do it for the 'fd' one, will be used to augment the return of some syscalls that may return an 'fd', such as fcntl(fd, F_DUPFD). Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-39sosu12hhywyunqf5s74ewf@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-07-18perf trace beauty: Give syscall return beautifier more contextArnaldo Carvalho de Melo1-3/+8
We need the current thread and the trace internal state so that we can use the fd beautifier to augment syscall returns, so use struct syscall_arg with some fields that make sense on returns (val, thread, trace). Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-lqag8e86ybidrh5zpqne05ov@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-07-18perf trace: Allow syscall_arg beautifiers to set a different return formatterArnaldo Carvalho de Melo1-1/+26
Things like fcntl will use this to set the right formatter based on its 'cmd' argument. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-4ea3wplb8b4j7aymj0d5uo0h@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-07-18perf trace: Beautify new write hint fcntl commandsArnaldo Carvalho de Melo1-0/+1
Those introduced by the commit c75b1d9421f8 ("fs: add fcntl() interface for setting/getting write life time hints"), tested using the proggie in that commit comment: # perf trace -e fcntl ./write_hint write_hint.c fcntl: F_GET_RW_HINT: Invalid argument 0.000 ( 0.006 ms): write_hint/7576 fcntl(fd: 3, cmd: GET_RW_HINT, arg: 0x7ffc6c918da0) = -1 EINVAL Invalid argument 0.014 ( 0.004 ms): write_hint/7576 fcntl(fd: 4, cmd: GETFL) = 33794 # perf trace -e fcntl ./write_hint write_hint.c 1 fcntl: F_SET_RW_HINT: Invalid argument 0.000 ( 0.007 ms): write_hint/7578 fcntl(fd: 3, cmd: SET_RW_HINT, arg: 0x7fff03866d70) = -1 EINVAL Invalid argument 0.019 ( 0.002 ms): write_hint/7578 fcntl(fd: 4, cmd: GETFL) = 33794 # Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jens Axboe <axboe@kernel.dk> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Martin K. Petersen <martin.petersen@oracle.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-iacglkc99cchou87k62736dn@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-07-18perf trace beauty fcntl: Basic 'arg' beautifierArnaldo Carvalho de Melo1-1/+2
Sometimes it should be printed as an hex number, like with F_SETLK, F_SETLKW and F_GETLK, that treat 'arg' as a struct flock pointer, in other cases it is just an integer. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-2gykg6enk7vos6q0m97hkgsg@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-07-18perf trace beauty: Introduce syscall arg beautifier for long integersArnaldo Carvalho de Melo1-0/+5
Will be used in the fcntl arg beautifier, that nowadays formats as '%ld' because there is no explicit arg beautifier attached, but as we will have to first decide what beautifier to use (i.e. it may be a pointer, etc) then we need to have this exported as a separate beautifier to be called from there. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-d7bfs3m8m70j3zckeam0kk5d@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-07-18perf trace beauty: Export the "int" and "hex" syscall arg formattersArnaldo Carvalho de Melo1-8/+2
The most basic ones, for pointers, unaugmented fds, etc, to be used in the initial fcntl 'arg' beautifier. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-g0lugj4vv6p4jtge32hid6q6@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-07-18perf trace beauty: Allow accessing syscall args values in a syscall arg formatterArnaldo Carvalho de Melo1-7/+16
For instance, fcntl's upcoming 'arg' formatter needs to look at the 'cmd' value to decide how to format its value, sometimes it is a file flags, sometimes an fd, a pointer to a structure, etc. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-2tw2jfaqm48dtw8a4addghze@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-07-18perf trace beauty: Mask ignored fcntl 'arg' parameterArnaldo Carvalho de Melo1-1/+1
A series of fcntl cmds ignore the third argument, so mask it. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-6vtl3zq1tauamrhm8o380ptn@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-07-18perf trace beauty: Export the strarrays scnprintf methodArnaldo Carvalho de Melo1-4/+2
As we'll call it from the fcntl cmd scnprintf method, that needs to look at the cmd to mask the next fcntl argument when it is ignored. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-fzlvkhew5vbxefneuciihgbc@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-07-18perf trace: Beautify linux specific fcntl commandsArnaldo Carvalho de Melo1-3/+54
We were only beautifying (transforming from an integer to its name) the non-linux specific fcntl syscall cmd args, fix it: Before: # perf trace -e fcntl -p 2472 0.000 ( 0.017 ms): gnome-terminal/2472 fcntl(fd: 55, cmd: 1030) = 56 ^C# After: # trace -e fcntl -p 2472 0.000 ( 0.015 ms): gnome-terminal/2472 fcntl(fd: 55, cmd: DUPFD_CLOEXEC) = 56 ^C# Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-zigsxruk4wbfn8iylboy9wzo@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-07-18perf trace: Remove F_ from some of the fcntl command stringsArnaldo Carvalho de Melo1-3/+3
The initial ones already had that "F_" prefix stripped to make things shorter, some hadn't, do it now. We do this to make the 'perf trace' output more compact. At some point perhaps the best thing to do is to have the tool do this stripping automatically, letting the user also decide if this is to be done or not. For now, be consistent. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-2iot106xkl8rgb0hb8zm3gq5@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-06-01perf trace: Add mmap alias for s390Jiri Olsa1-0/+4
The s390 architecture maps sys_mmap (nr 90) into sys_old_mmap. For this reason perf trace can't find the proper syscall event to get args format from and displays it wrongly as 'continued'. To fix that fill the "alias" field with "old_mmap" for trace's mmap record to get the correct translation. Before: 0.042 ( 0.011 ms): vest/43052 fstat(statbuf: 0x3ffff89fd90 ) = 0 0.042 ( 0.028 ms): vest/43052 ... [continued]: mmap()) = 0x3fffd6e2000 0.072 ( 0.025 ms): vest/43052 read(buf: 0x3fffd6e2000, count: 4096 ) = 6 After: 0.045 ( 0.011 ms): fstat(statbuf: 0x3ffff8a0930 ) = 0 0.057 ( 0.018 ms): mmap(arg: 0x3ffff8a0858 ) = 0x3fffd14a000 0.076 ( 0.025 ms): read(buf: 0x3fffd14a000, count: 4096 ) = 6 Signed-off-by: Jiri Olsa <jolsa@kernel.org> Cc: David Ahern <dsahern@gmail.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Peter Zijlstra <a.p.zijlstra@chello.nl> Link: http://lkml.kernel.org/r/20170531113557.19175-1-jolsa@kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-04-25perf tools: Move event prototypes from util.h to event.hArnaldo Carvalho de Melo1-0/+1
More needs to be done to have the actual functions and variables in a smaller .c file that can then be included in the python binding, avoiding dragging more stuff into it. Link: http://lkml.kernel.org/n/tip-uecxz7cqkssouj7tlxrkqpl4@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-04-24perf tools: Remove poll.h and wait.h from util.hArnaldo Carvalho de Melo1-0/+1
Not needed in this header, added to the places that need poll(), wait() and a few other prototypes. Link: http://lkml.kernel.org/n/tip-i39c7b6xmo1vwd9wxp6fmkl0@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-04-20perf tools: Add signal.h to places using its definitionsArnaldo Carvalho de Melo1-0/+1
And remove it from util.h, disentangling it a bit more. Link: http://lkml.kernel.org/n/tip-2zg9s5nx90yde64j3g4z2uhk@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-04-19perf tools: Move path related functions to util/path.hArnaldo Carvalho de Melo1-0/+1
Disentangling util.h header mess a bit more. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-aj6je8ly377i4upedmjzdsq6@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-04-19perf tools: Include errno.h where neededArnaldo Carvalho de Melo1-0/+1
Removing it from util.h, part of an effort to disentangle the includes hell, that makes changes to util.h or something included by it to cause a complete rebuild of the tools. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-ztrjy52q1rqcchuy3rubfgt2@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-04-19perf tools: Move extra string util functions to util/string2.hArnaldo Carvalho de Melo1-0/+1
Moving them from util.h, where they don't belong. Since libc already have string.h, name it slightly differently, as string2.h. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-eh3vz5sqxsrdd8lodoro4jrw@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-04-19perf tools: Move print_binary definitions to separate filesArnaldo Carvalho de Melo1-0/+1
Continuing the split of util.[ch] into more manageable bits. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-5eu367rwcwnvvn7fz09l7xpb@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-04-19perf tools: Move sane ctype stuff from util.h to sane_ctype.hArnaldo Carvalho de Melo1-0/+2
More stuff that came from git, out of the hodge-podge that is util.h Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-e3lana4gctz3ub4hn4y29hkw@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-04-19perf tools: Including missing inttypes.h headerArnaldo Carvalho de Melo1-0/+1
Needed to use the PRI[xu](32,64) formatting macros. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-wkbho8kaw24q67dd11q0j39f@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-04-19perf tools: Add include <linux/kernel.h> where ARRAY_SIZE() is usedArnaldo Carvalho de Melo1-0/+1
To pave the way for further cleanups where linux/kernel.h may stop being included in some header. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-qqxan6tfsl6qx3l0v3nwgjvk@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-03-31perf trace: Beautify statx syscall 'flag' and 'mask' argumentsArnaldo Carvalho de Melo1-9/+5
To test it, build samples/statx/test_statx, which I did as: $ make headers_install $ cc -I ~/git/linux/usr/include samples/statx/test-statx.c -o /tmp/statx And then use perf trace on it: # perf trace -e statx /tmp/statx /etc/passwd statx(/etc/passwd) = 0 results=7ff Size: 3496 Blocks: 8 IO Block: 4096 regular file Device: fd:00 Inode: 280156 Links: 1 Access: (0644/-rw-r--r--) Uid: 0 Gid: 0 Access: 2017-03-29 16:01:01.650073438-0300 Modify: 2017-03-10 16:25:14.156479354-0300 Change: 2017-03-10 16:25:14.171479328-0300 0.000 ( 0.007 ms): statx/30648 statx(dfd: CWD, filename: 0x7ef503f4, flags: SYMLINK_NOFOLLOW, mask: TYPE|MODE|NLINK|UID|GID|ATIME|MTIME|CTIME|INO|SIZE|BLOCKS|BTIME, buffer: 0x7fff7ef4eb10) = 0 # Using the test-stat.c options to change the mask: # perf trace -e statx /tmp/statx -O /etc/passwd > /dev/null 0.000 ( 0.008 ms): statx/30745 statx(dfd: CWD, filename: 0x3a0753f4, flags: SYMLINK_NOFOLLOW, mask: BTIME, buffer: 0x7ffd3a0735c0) = 0 # # perf trace -e statx /tmp/statx -A /etc/passwd > /dev/null 0.000 ( 0.010 ms): statx/30757 statx(dfd: CWD, filename: 0xa94e63f4, flags: SYMLINK_NOFOLLOW|NO_AUTOMOUNT, mask: TYPE|MODE|NLINK|UID|GID|ATIME|MTIME|CTIME|INO|SIZE|BLOCKS|BTIME, buffer: 0x7ffea94e49d0) = 0 # # trace --no-inherit -e statx /tmp/statx -F /etc/passwd > /dev/null 0.000 ( 0.011 ms): statx(dfd: CWD, filename: 0x3b02d3f3, flags: SYMLINK_NOFOLLOW|STATX_FORCE_SYNC, mask: TYPE|MODE|NLINK|UID|GID|ATIME|MTIME|CTIME|INO|SIZE|BLOCKS|BTIME, buffer: 0x7ffd3b02c850) = 0 # # trace --no-inherit -e statx /tmp/statx -F -L /etc/passwd > /dev/null 0.000 ( 0.008 ms): statx(dfd: CWD, filename: 0x15cff3f3, flags: STATX_FORCE_SYNC, mask: TYPE|MODE|NLINK|UID|GID|ATIME|MTIME|CTIME|INO|SIZE|BLOCKS|BTIME, buffer: 0x7fff15cfdda0) = 0 # # trace --no-inherit -e statx /tmp/statx -D -O /etc/passwd > /dev/null 0.000 ( 0.009 ms): statx(dfd: CWD, filename: 0xfa37f3f3, flags: SYMLINK_NOFOLLOW|STATX_DONT_SYNC, mask: BTIME, buffer: 0x7ffffa37da20) = 0 # Adding a probe to get the filename collected as well: # perf probe 'vfs_getname=getname_flags:72 pathname=result->name:string' Added new event: probe:vfs_getname (on getname_flags:72 with pathname=result->name:string) You can now use it in all perf tools, such as: perf record -e probe:vfs_getname -aR sleep 1 # trace --no-inherit -e statx /tmp/statx -D -O /etc/passwd > /dev/null 0.169 ( 0.007 ms): statx(dfd: CWD, filename: /etc/passwd, flags: SYMLINK_NOFOLLOW|STATX_DONT_SYNC, mask: BTIME, buffer: 0x7ffda9bf50f0) = 0 # Same technique could be used to collect and beautify the result put in the 'buffer' argument. Finally do a system wide 'perf trace' session looking for any use of statx, then run the test proggie with various flags: # trace -e statx 16612.967 ( 0.028 ms): statx/4562 statx(dfd: CWD, filename: /tmp/statx, flags: SYMLINK_NOFOLLOW, mask: TYPE|MODE|NLINK|UID|GID|ATIME|MTIME|CTIME|INO|SIZE|BLOCKS|BTIME, buffer: 0x7ffef195d660) = 0 33064.447 ( 0.011 ms): statx/4569 statx(dfd: CWD, filename: /tmp/statx, flags: SYMLINK_NOFOLLOW|STATX_FORCE_SYNC, mask: TYPE|MODE|NLINK|UID|GID|ATIME|MTIME|CTIME|INO|SIZE|BLOCKS|BTIME, buffer: 0x7ffc5484c790) = 0 36050.891 ( 0.023 ms): statx/4576 statx(dfd: CWD, filename: /tmp/statx, flags: SYMLINK_NOFOLLOW, mask: BTIME, buffer: 0x7ffeb18b66e0) = 0 38039.889 ( 0.023 ms): statx/4584 statx(dfd: CWD, filename: /tmp/statx, flags: SYMLINK_NOFOLLOW, mask: TYPE|MODE|NLINK|UID|GID|ATIME|MTIME|CTIME|INO|SIZE|BLOCKS|BTIME, buffer: 0x7fff1db0ea90) = 0 ^C# This one also starts moving the beautifiers from files directly included in builtin-trace.c to separate objects + a beauty.h header with prototypes, so that we can add test cases in tools/perf/tests/ to fire syscalls with various arguments and then get them intercepted as syscalls:sys_enter_foo or raw_syscalls:sys_enter + sys_exit to then format and check that the formatted output is the one we expect. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: Al Viro <viro@zeniv.linux.org.uk> Cc: David Ahern <dsahern@gmail.com> Cc: David Howells <dhowells@redhat.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-xvzw8eynffvez5czyzidhrno@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-03-29perf trace: Handle unpaired raw_syscalls:sys_exit eventArnaldo Carvalho de Melo1-9/+34
Which may happen when we start a tracing session and a thread is waiting for something like "poll" to return, in which case we better print "?" both for the syscall entry timestamp and for the duration. E.g.: Tracing existing mutt session: # perf trace -p `pidof mutt` ? ( ? ): mutt/17135 ... [continued]: poll()) = 1 0.027 ( 0.013 ms): mutt/17135 read(buf: 0x7ffcb3c42cef, count: 1) = 1 0.047 ( 0.008 ms): mutt/17135 poll(ufds: 0x7ffcb3c42c50, nfds: 1, timeout_msecs: 1000) = 1 0.059 ( 0.008 ms): mutt/17135 read(buf: 0x7ffcb3c42cef, count: 1) = 1 <SNIP> Before it would print a large number because we'd do: ttrace->entry_time - trace->base_time And entry_time would be 0, while base_time would be the timestamp for the first event 'perf trace' reads, oops. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Luis Claudio Gonçalves <lclaudio@redhat.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-wbcb93ofva2qdjd5ltn5eeqq@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-03-27perf tools: Remove unused 'prefix' from builtin functionsArnaldo Carvalho de Melo1-2/+2
We got it from the git sources but never used it for anything, with the place where this would be somehow used remaining: static int run_builtin(struct cmd_struct *p, int argc, const char **argv) { prefix = NULL; if (p->option & RUN_SETUP) prefix = NULL; /* setup_perf_directory(); */ Ditch it. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-uw5swz05vol0qpr32c5lpvus@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-03-24perf trace: Fixup thread refcountingArnaldo Carvalho de Melo1-9/+12
In trace__vfs_getname() and when checking if a thread is filtered in trace__process_sample() we were not dropping the reference obtained via machine__findnew_thread(), fix it. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-9gc470phavxwxv5d9w7ck8ev@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-03-24perf trace: Fix up error path indentationArnaldo Carvalho de Melo1-1/+1
Trivial fix removing a tab in an error path. Link: http://lkml.kernel.org/n/tip-c14mk6cqaiby8gf5rpft3d9r@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-03-24perf trace: Check for vfs_getname.pathname lengthArnaldo Carvalho de Melo1-0/+2
It shouldn't be zero, but if the 'perf probe' on getname_flags() (or elsewhere in the future we need to probe to catch the pathname for syscalls like 'open' being copied from userspace to the kernel) is misplaced somehow, then we will end up not allocating space and trying to copy the "" empty string to ttrace->filename.name, causing a segfault, fix it. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-c4f1t6sx1nczuzop19r5si5s@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-03-14perf tools: Add PERF_RECORD_NAMESPACES to include namespaces related infoHari Bathini1-1/+2
Introduce a new option to record PERF_RECORD_NAMESPACES events emitted by the kernel when fork, clone, setns or unshare are invoked. And update perf-record documentation with the new option to record namespace events. Committer notes: Combined it with a later patch to allow printing it via 'perf report -D' and be able to test the feature introduced in this patch. Had to move here also perf_ns__name(), that was introduced in another later patch. Also used PRIu64 and PRIx64 to fix the build in some enfironments wrt: util/event.c:1129:39: error: format '%lx' expects argument of type 'long unsigned int', but argument 6 has type 'long long unsigned int' [-Werror=format=] ret += fprintf(fp, "%u/%s: %lu/0x%lx%s", idx ^ Testing it: # perf record --namespaces -a ^C[ perf record: Woken up 1 times to write data ] [ perf record: Captured and wrote 1.083 MB perf.data (423 samples) ] # # perf report -D <SNIP> 3 2028902078892 0x115140 [0xa0]: PERF_RECORD_NAMESPACES 14783/14783 - nr_namespaces: 7 [0/net: 3/0xf0000081, 1/uts: 3/0xeffffffe, 2/ipc: 3/0xefffffff, 3/pid: 3/0xeffffffc, 4/user: 3/0xeffffffd, 5/mnt: 3/0xf0000000, 6/cgroup: 3/0xeffffffb] 0x1151e0 [0x30]: event: 9 . . ... raw event: size 48 bytes . 0000: 09 00 00 00 02 00 30 00 c4 71 82 68 0c 7f 00 00 ......0..q.h.... . 0010: a9 39 00 00 a9 39 00 00 94 28 fe 63 d8 01 00 00 .9...9...(.c.... . 0020: 03 00 00 00 00 00 00 00 ce c4 02 00 00 00 00 00 ................ <SNIP> NAMESPACES events: 1 <SNIP> # Signed-off-by: Hari Bathini <hbathini@linux.vnet.ibm.com> Acked-by: Jiri Olsa <jolsa@kernel.org> Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com> Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com> Cc: Alexei Starovoitov <ast@fb.com> Cc: Ananth N Mavinakayanahalli <ananth@linux.vnet.ibm.com> Cc: Aravinda Prasad <aravinda@linux.vnet.ibm.com> Cc: Brendan Gregg <brendan.d.gregg@gmail.com> Cc: Daniel Borkmann <daniel@iogearbox.net> Cc: Eric Biederman <ebiederm@xmission.com> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Sargun Dhillon <sargun@sargun.me> Cc: Steven Rostedt <rostedt@goodmis.org> Link: http://lkml.kernel.org/r/148891930386.25309.18412039920746995488.stgit@hbathini.in.ibm.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-02-20perf utils: Check verbose flag properlyNamhyung Kim1-3/+3
It now can have negative value to suppress the message entirely. So it needs to check it being positive. Signed-off-by: Namhyung Kim <namhyung@kernel.org> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Peter Zijlstra <a.p.zijlstra@chello.nl> Cc: kernel-team@lge.com Link: http://lkml.kernel.org/r/20170217081742.17417-3-namhyung@kernel.org [ Adjust fuzz on tools/perf/util/pmu.c, add > 0 checks in many other places ] Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-01-11perf trace: Allow specifying list of syscalls and events in -e/--expr/--eventArnaldo Carvalho de Melo1-28/+92
Makes it easier to specify both events and syscalls (to be formatter strace-like), i.e. previously one would have to do: # perf trace -e nanosleep --event sched:sched_switch usleep 1 Now it is possible to do: # perf trace -e nanosleep,sched:sched_switch usleep 1 0.000 ( 0.021 ms): usleep/17962 nanosleep(rqtp: 0x7ffdedd61ec0) ... 0.021 ( ): sched:sched_switch:usleep:17962 [120] S ==> swapper/1:0 [120]) 0.000 ( 0.066 ms): usleep/17962 ... [continued]: nanosleep()) = 0 # The old style --expr and using both -e and --event continues to work. Cc: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Milian Wolff <milian.wolff@kdab.com> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Wang Nan <wangnan0@huawei.com> Link: http://lkml.kernel.org/n/tip-ieg6bakub4657l9e6afn85r4@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>