| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Date: Thu, 29 Oct 2015 12:27:42 -0300
From: Arnaldo Carvalho de Melo <acme@...nel.org>
To: Peter Zijlstra <peterz@...radead.org>
Cc: Frédéric Weisbecker <fweisbec@...il.com>,
Jiri Olsa <jolsa@...nel.org>, David Ahern <dsahern@...il.com>,
Adrian Hunter <adrian.hunter@...el.com>,
Wang Nan <wangnan0@...wei.com>,
Steven Rostedt <rostedt@...dmis.org>,
Linux Kernel Mailing List <linux-kernel@...r.kernel.org>
Subject: tracepoint filter problems
Hi,
In 'perf trace' we have an equivalent to strace's -e option, i.e. a way
to state which syscalls one wants to see, so, when we do:
[root@...icio linux]# trace -e open
0.348 ( 0.005 ms): ls/6887 open(filename: /etc/ld.so.cache, flags: CLOEXEC ) = 3
0.363 ( 0.005 ms): ls/6887 open(filename: /lib64/libselinux.so.1, flags: CLOEXEC ) = 3
0.400 ( 0.006 ms): ls/6887 open(filename: /lib64/libcap.so.2, flags: CLOEXEC ) = 3
0.427 ( 0.006 ms): ls/6887 open(filename: /lib64/libacl.so.1, flags: CLOEXEC ) = 3
0.454 ( 0.006 ms): ls/6887 open(filename: /lib64/libc.so.6, flags: CLOEXEC ) = 3
0.497 ( 0.006 ms): ls/6887 open(filename: /lib64/libpcre.so.1, flags: CLOEXEC ) = 3
0.533 ( 0.006 ms): ls/6887 open(filename: /lib64/liblzma.so.5, flags: CLOEXEC ) = 3
0.561 ( 0.006 ms): ls/6887 open(filename: /lib64/libdl.so.2, flags: CLOEXEC ) = 3
0.586 ( 0.006 ms): ls/6887 open(filename: /lib64/libattr.so.1, flags: CLOEXEC ) = 3
0.611 ( 0.006 ms): ls/6887 open(filename: /lib64/libpthread.so.0, flags: CLOEXEC ) = 3
0.859 ( 0.007 ms): ls/6887 open(filename: /usr/lib/locale/locale-archive, flags: CLOEXEC ) = 3
^C[root@...icio linux]#
I.e. tracing system wide, looking for any program that calls the open syscall, it works, as it
used the PERF_EVENT_IOC_SET_FILTER to set the relevant 'id == 486' to filter it:
[root@...icio linux]# head -2 /sys/kernel/debug/tracing/events/syscalls/sys_enter_open/format
name: sys_enter_open
ID: 486
Ok, this is how it should be, all works, but if I try instead calling a program
that in turn calls another, the filter will apply for the first in line, but
not for the calls made by another program called from it.
In the example below 'perf trace' will ask to see just the 'open' syscall, and
it works for the started workload, namely 'perf record', but then it'll call
'sleep 100000000000' and there the filter doesn't apply, bummer :-\
The inherit bit is set, sure, as we can see when adding -vv to the 'perf trace'
call, ideas?
I came accross this wanting to trace perf record with a bpf proggie that would
call another workload, and I wanted to see just the perf_event_open and bpf
syscalls, but ended up seeing all the syscalls in the leaf workload.
- Arnaldo
[root@...icio linux]# perf trace -e open perf record -e /tmp/foo.o sleep 100000000000
0.091 ( 0.007 ms): perf/6875 open(filename: 0x96590bf0, flags: CLOEXEC ) = -1 ENOENT No such file or directory
0.096 ( 0.002 ms): perf/6875 open(filename: 0x96590bf0, flags: CLOEXEC ) = -1 ENOENT No such file or directory
0.100 ( 0.002 ms): perf/6875 open(filename: 0x96590bf0, flags: CLOEXEC ) = -1 ENOENT No such file or directory
0.103 ( 0.002 ms): perf/6875 open(filename: 0x96590bf0, flags: CLOEXEC ) = -1 ENOENT No such file or directory
0.110 ( 0.003 ms): perf/6875 open(filename: 0x7629da98, flags: CLOEXEC ) = 3
386.185 ( 0.005 ms): perf/6875 open(filename: 0x965868a0, mode: 20 ) = 10
386.800 ( 0.008 ms): perf/6875 open(filename: 0x96588ae0, mode: 20 ) = 8
<SNIP tons of open syscalls>
387.426 ( 0.002 ms): :6876/6876 set_robust_list(head: 0x7faa76484a60, len: 24 ) = 0
387.446 ( 0.002 ms): :6876/6876 rt_sigaction(sig: TERM, act: 0x7ffe9658ebc0, oact: 0x7ffe9658ec60, sigsetsize: 8) = 0
387.449 ( 0.001 ms): :6876/6876 close(fd: 5 ) = 0
387.450 ( 0.001 ms): :6876/6876 close(fd: 8 ) = 0
<SNIP some syscalls for pid 6876>
391.573 ( 0.002 ms): perf/6876 execve(arg0: 140731420831140, arg1: 140731420841520, arg2: 140731420841568, arg3: 140731420830688, arg4: 7307199665339051828, arg5: 140731420830816) = -2
391.580 ( 0.006 ms): perf/6876 execve(arg0: 140731420831149, arg1: 140731420841520, arg2: 140731420841568, arg3: 140731420830688, arg4: 7307199665339051828, arg5: 140731420830816) = -2
392.009 ( 0.428 ms): sleep/6876 execve(arg0: 140731420831150, arg1: 140731420841520, arg2: 140731420841568, arg3: 140731420830688, arg4: 7307199665339051828, arg5: 140731420830816) = 0
392.030 ( 0.001 ms): sleep/6876 brk( ) = 0x14f1000
392.042 ( 0.003 ms): sleep/6876 mmap(len: 4096, prot: READ|WRITE, flags: PRIVATE|ANONYMOUS, fd: -1 ) = 0x7f9223117000
392.050 ( 0.004 ms): sleep/6876 access(filename: 0x22f151a0, mode: R ) = -1 ENOENT No such file or directory
392.058 ( 0.004 ms): sleep/6876 open(filename: 0x22f13a98, flags: CLOEXEC ) = 3
392.060 ( 0.001 ms): sleep/6876 fstat(fd: 3, statbuf: 0x7ffeb5f28660 ) = 0
392.064 ( 0.003 ms): sleep/6876 mmap(len: 62420, prot: READ, flags: PRIVATE, fd: 3 ) = 0x7f9223107000
392.066 ( 0.001 ms): sleep/6876 close(fd: 3 ) = 0
392.076 ( 0.005 ms): sleep/6876 open(filename: 0x23114dcf, flags: CLOEXEC ) = 3
<SNIP> some more
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Powered by blists - more mailing lists