linux-kernel - Re: [PATCH 1/8] perf: Allow to block process in syscall tracepoints

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

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Message-ID: <20181208104121.GD5289@hirez.programming.kicks-ass.net>
Date:   Sat, 8 Dec 2018 11:41:21 +0100
From:   Peter Zijlstra <peterz@...radead.org>
To:     Arnaldo Carvalho de Melo <acme@...nel.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

On Fri, Dec 07, 2018 at 12:49:21PM -0300, Arnaldo Carvalho de Melo wrote:
> 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:

> 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

>   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

> '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>

Right; and that is all nice. And exactly doesn't answer my question. Why
do we care about those LOST entries so much that we have to do such
horribly ugly things?

Esp. as you point out, they're clearly marked in the output and easily
avoided by using a slightly larger buffer.