| 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
| ||
|
Message-ID: <20181207154921.GB28174@kernel.org>
Date: Fri, 7 Dec 2018 12:49:21 -0300
From: Arnaldo Carvalho de Melo <acme@...nel.org>
To: Peter Zijlstra <peterz@...radead.org>
Cc: Steven Rostedt <rostedt@...dmis.org>, Jiri Olsa <jolsa@...nel.org>,
lkml <linux-kernel@...r.kernel.org>,
Ingo Molnar <mingo@...nel.org>,
Namhyung Kim <namhyung@...nel.org>,
Alexander Shishkin <alexander.shishkin@...ux.intel.com>,
Thomas Gleixner <tglx@...utronix.de>,
"Luis Claudio R. Goncalves" <lclaudio@...g.org>, ldv@...linux.org,
esyr@...hat.com, Frederic Weisbecker <fweisbec@...il.com>
Subject: Re: [PATCH 1/8] perf: Allow to block process in syscall tracepoints
Em Fri, Dec 07, 2018 at 04:11:05PM +0100, Peter Zijlstra escreveu:
> On Fri, Dec 07, 2018 at 08:41:18AM -0500, Steven Rostedt wrote:
> > On Fri, 7 Dec 2018 09:58:39 +0100 Peter Zijlstra <peterz@...radead.org> wrote:
> > > These patches give no justification *what*so*ever* for why we're doing
> > > ugly arse things like this. And why does this, whatever this is, need to
> > > be done in perf?
> > > IOW, what problem are we solving ?
> > I guess the cover letter should have had a link (or copy) of this:
> > http://lkml.kernel.org/r/20181128134700.212ed035@gandalf.local.home
> That doesn't even begin to explain. Who cares about strace and why? And
> why is it such a bad thing to loose the occasional record etc..
The following almost addresses all the details for doing such a perf
based strace tool (modulo signals), was started by Thomas a long time
ago [1] and is in the tree for a long time, with BPF attached to the
raw_syscalls:sys_{enter,exit} (that -e augmented_raw_syscalls.c thing
that lives in tools/perf/examples/bpf now but would be put in place
transparently and pre-compiled as augmented_raw_syscalls.o) to collect
pointer contents without using ptrace:
[root@...enth bpf]# perf trace --no-inherit -e augmented_raw_syscalls.c sleep 1
0.019 ( 0.001 ms): brk( ) = 0x559ca9dd7000
0.031 ( 0.004 ms): access(filename: , mode: R ) = -1 ENOENT No such file or directory
0.039 ( 0.003 ms): openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC ) = 3
0.043 ( 0.002 ms): fstat(fd: 3, statbuf: 0x7ffdfa50e940 ) = 0
0.045 ( 0.003 ms): mmap(len: 103484, prot: READ, flags: PRIVATE, fd: 3 ) = 0x7fa76b2ce000
0.049 ( 0.001 ms): close(fd: 3 ) = 0
0.056 ( 0.003 ms): openat(dfd: CWD, filename: /lib64/libc.so.6, flags: CLOEXEC ) = 3
0.060 ( 0.002 ms): read(fd: 3, buf: 0x7ffdfa50eb08, count: 832 ) = 832
0.063 ( 0.001 ms): fstat(fd: 3, statbuf: 0x7ffdfa50e9a0 ) = 0
0.065 ( 0.002 ms): mmap(len: 8192, prot: READ|WRITE, flags: PRIVATE|ANONYMOUS ) = 0x7fa76b2cc000
0.070 ( 0.003 ms): mmap(len: 3889792, prot: EXEC|READ, flags: PRIVATE|DENYWRITE, fd: 3 ) = 0x7fa76ad0e000
0.075 ( 0.005 ms): mprotect(start: 0x7fa76aebb000, len: 2093056 ) = 0
0.081 ( 0.005 ms): mmap(addr: 0x7fa76b0ba000, len: 24576, prot: READ|WRITE, flags: PRIVATE|FIXED|DENYWRITE, fd: 3, off: 1753088) = 0x7fa76b0ba000
0.089 ( 0.002 ms): mmap(addr: 0x7fa76b0c0000, len: 14976, prot: READ|WRITE, flags: PRIVATE|FIXED|ANONYMOUS) = 0x7fa76b0c0000
0.095 ( 0.001 ms): close(fd: 3 ) = 0
0.105 ( 0.001 ms): arch_prctl(option: 4098, arg2: 140357034366208 ) = 0
0.144 ( 0.004 ms): mprotect(start: 0x7fa76b0ba000, len: 16384, prot: READ ) = 0
0.159 ( 0.002 ms): mprotect(start: 0x559ca81aa000, len: 4096, prot: READ ) = 0
0.163 ( 0.002 ms): mprotect(start: 0x7fa76b2e8000, len: 4096, prot: READ ) = 0
0.167 ( 0.008 ms): munmap(addr: 0x7fa76b2ce000, len: 103484 ) = 0
0.218 ( 0.001 ms): brk( ) = 0x559ca9dd7000
0.220 ( 0.002 ms): brk(brk: 0x559ca9df8000 ) = 0x559ca9df8000
0.224 ( 0.001 ms): brk( ) = 0x559ca9df8000
0.228 ( 0.004 ms): open(filename: /usr/lib/locale/locale-archive, flags: CLOEXEC ) = 3
0.233 ( 0.001 ms): fstat(fd: 3, statbuf: 0x7fa76b0bfaa0 ) = 0
0.235 ( 0.003 ms): mmap(len: 113045344, prot: READ, flags: PRIVATE, fd: 3 ) = 0x7fa76413f000
0.241 ( 0.001 ms): close(fd: 3 ) = 0
0.264 (1000.163 ms): nanosleep(rqtp: 0x7ffdfa50f680 ) = 0
1000.440 ( 0.002 ms): close(fd: 1 ) = 0
1000.443 ( 0.001 ms): close(fd: 2 ) = 0
1000.449 ( ): exit_group( )
[root@...enth bpf]#
doing just:
# perf trace --filter-pids pid-of-your-local-xterm,gnome-shell-pid-for-your-term
For system wide stracing elliminating the feedback loop of your GUI
components will most of the time work with the default ring buffer size
and when it doesn't, you'll get things like that "LOST events!" message,
and for such extreme cases, just use '-m' to bump the rb size some more.
# trace --filter-pids 2279,1643
<SNIP>
8793.387 ( 0.003 ms): cc1/19097 openat(dfd: CWD, filename: 0x3df9940, flags: NOCTTY ) = 21
8793.390 ( 0.001 ms): cc1/19097 fstat(fd: 21, statbuf: 0x3df9648 ) = 0
8793.394 ( 0.003 ms): cc1/19097 read(fd: 21, buf: 0x3d6e0f0, count: 5804 ) = 5804
8793.398 ( 0.001 ms): cc1/19097 close(fd: 21 ) = 0
8793.403 ( 0.002 ms): cc1/19097 openat(dfd: CWD, filename: 0x3dfca70, flags: NOCTTY ) = -1 ENOENT No such file or directory
8793.406 ( 0.001 ms): cc1/19097 openat(dfd: CWD, filename: 0x3dfca70, flags: NOCTTY ) = -1 ENOENT No such file or directory
8793.409 ( 0.002 ms): cc1/19097 openat(dfd: CWD, filename: 0x3dfca70, flags: NOCTTY ) = 21
8793.412 ( 0.001 ms): cc1/19097 fstat(fd: 21, statbuf: 0x3df9738 ) = 0
8793.414 ( 0.022 ms): cc1/19097 read(fd: 21, buf: 0x3eb6d90, count: 25315 ) = 25315
8793.437 ( 0.001 ms): cc1/19097 close(fd: 21 ) = 0
8793.605 ( 0.005 ms): cc1/19097 openat(dfd: CWD, filename: 0x3dfca70 ) = 21
8793.614 ( 0.001 ms): cc1/19097 close(fd: 5 ) = 0
8793.618 ( 0.001 ms): cc1/19097 fstat(fd: 21, statbuf: 0x7ffd653ed380 ) = 0
8793.621 ( 0.002 ms): cc1/19097 read(fd: 21, buf: 0x3d41e30, count: 8192 ) = 8192
8793.626 ( 0.002 ms): cc1/19097 read(fd: 21, buf: 0x3ebf090, count: 8192 ) = 8192
8793.635 ( 0.003 ms): cc1/19097 read(fd: 21, buf: 0x3ed4730, count: 16384 ) = 8931
8793.640 ( 0.001 ms): cc1/19097 read(fd: 21, buf: 0x3ed6a13, count: 4096 ) = 0
LOST 34956 events!
9497.921 ( 0.006 ms): gcc/19180 openat(dfd: CWD, filename: 0x3115e20, flags: NOCTTY ) = -1 ENOENT No such file or directory
9497.935 ( 0.002 ms): gcc/19180 openat(dfd: CWD, filename: 0x3115e20, flags: NOCTTY ) = -1 ENOENT No such file or directory
9497.939 ( 0.003 ms): gcc/19180 openat(dfd: CWD, filename: 0x3115e20, flags: NOCTTY ) = 9
9497.943 ( 0.001 ms): gcc/19180 fstat(fd: 9</home/acme/git/linux/include/linux/page_ref.h>, statbuf: 0x3153568) = 0
9497.945 ( 0.006 ms): gcc/19180 read(fd: 9</home/acme/git/linux/include/linux/page_ref.h>, buf: 0x31c00a0, count: 40574) = 40574
9497.952 ( 0.001 ms): gcc/19180 close(fd: 9</home/acme/git/linux/include/linux/page_ref.h> ) = 0
9497.959 ( 0.002 ms): gcc/19180 openat(dfd: CWD, filename: 0x31540a0, flags: NOCTTY ) = -1 ENOENT No such file or directory
9497.962 ( 0.002 ms): gcc/19180 openat(dfd: CWD, filename: 0x31540a0, flags: NOCTTY ) = -1 ENOENT No such file or directory
9497.965 ( 0.002 ms): gcc/19180 openat(dfd: CWD, filename: 0x31540a0, flags: NOCTTY ) = 9
9497.969 ( 0.001 ms): gcc/19180 fstat(fd: 9</home/acme/git/linux/include/linux/page_ref.h>, statbuf: 0x30dcf38) = 0
9497.970 ( 0.003 ms): gcc/19180 read(fd: 9</home/acme/git/linux/include/linux/page_ref.h>, buf: 0x31b8320, count: 23058) = 23058
9497.975 ( 0.001 ms): gcc/19180 close(fd: 9</home/acme/git/linux/include/linux/page_ref.h> ) = 0
9497.979 ( 0.002 ms): gcc/19180 openat(dfd: CWD, filename: 0x3154020, flags: NOCTTY ) = -1 ENOENT No such file or directory
9497.982 ( 0.002 ms): gcc/19180 openat(dfd: CWD, filename: 0x3154020, flags: NOCTTY ) = -1 ENOENT No such file or directory
9497.986 ( 0.002 ms): gcc/19180 openat(dfd: CWD, filename: 0x3154020, flags: NOCTTY ) = 9
9497.989 ( 0.001 ms): gcc/19180 fstat(fd: 9</home/acme/git/linux/include/linux/page_ref.h>, statbuf: 0x3116178) = 0
9497.990 ( 0.001 ms): gcc/19180 read(fd: 9</home/acme/git/linux/include/linux/page_ref.h>, buf: 0x31509c0, count: 1948) = 1948
9497.993 ( 0.001 ms): gcc/19180 close(fd: 9</home/acme/git/linux/include/linux/page_ref.h> ) = 0
9498.039 ( 0.003 ms): gcc/19180 openat(dfd: CWD, filename: 0x3154060, flags: NOCTTY ) = -1 ENOENT No such file or directory
9498.043 ( 0.002 ms): gcc/19180 openat(dfd: CWD, filename: 0x3154060, flags: NOCTTY ) = -1 ENOENT No such file or directory
9498.046 ( 0.002 ms): gcc/19180 openat(dfd: CWD, filename: 0x3154060, flags: NOCTTY ) = 9
9498.049 ( 0.001 ms): gcc/19180 fstat(fd: 9</home/acme/git/linux/include/linux/page_ref.h>, statbuf: 0x3153a08) = 0
'trace' is just 'perf trace', perf has logic to see if argv[0] is
'trace', then it goes and does a 'perf trace'. The above case does't use
bpf at all, gets details from /proc.
With bpf we get the 'filename' contents:
[root@...enth bpf]# trace -e augmented_raw_syscalls.c --filter-pids 2279,1643
<SNIP>
19766.027 ( 0.003 ms): gcc/27524 openat(dfd: CWD, filename: /lib64/libz.so.1, flags: CLOEXEC ) = 5
19766.035 ( 0.001 ms): gcc/27524 fstat(fd: 5, statbuf: 0x7ffe9323e2a0 ) = 0
19766.037 ( 0.003 ms): gcc/27524 mmap(len: 2187272, prot: EXEC|READ, flags: PRIVATE|DENYWRITE, fd: 5 ) = 0x7fa2df435000
19766.042 ( 0.003 ms): gcc/27524 mprotect(start: 0x7fa2df44b000, len: 2093056 ) = 0
19766.046 ( 0.004 ms): gcc/27524 mmap(addr: 0x7fa2df64a000, len: 4096, prot: READ|WRITE, flags: PRIVATE|FIXED|DENYWRITE, fd: 5, off: 86016) = 0x7fa2df64a000
19766.051 ( 0.002 ms): gcc/27524 mmap(addr: 0x7fa2df64b000, len: 8, prot: READ|WRITE, flags: PRIVATE|FIXED|ANONYMOUS) = 0x7fa2df64b000
19766.057 ( 0.001 ms): gcc/27524 close(fd: 5 ) = 0
19766.062 ( 0.003 ms): gcc/27524 openat(dfd: CWD, filename: /lib64/libc.so.6, flags: CLOEXEC ) = 5
<SNIP>
- Arnaldo
[1] https://lwn.net/Articles/415728/
Powered by blists - more mailing lists