netdev - Re: [PATCH v2 3/4] bpf: clarify when bpf_trace

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] [day] [month] [year] [list]

Message-ID: <CAADnVQ+hU6QOC_dPmpjnuv=9g4SQEeaMEMqXOS2WpMj=q=LdiQ@mail.gmail.com>
Date:   Wed, 21 Aug 2019 10:23:56 -0700
From:   Alexei Starovoitov <alexei.starovoitov@...il.com>
To:     Peter Wu <peter@...ensteyn.nl>
Cc:     Alexei Starovoitov <ast@...nel.org>,
        Daniel Borkmann <daniel@...earbox.net>,
        Network Development <netdev@...r.kernel.org>,
        bpf <bpf@...r.kernel.org>
Subject: Re: [PATCH v2 3/4] bpf: clarify when bpf_trace_printk discards lines

On Tue, Aug 20, 2019 at 5:04 PM Peter Wu <peter@...ensteyn.nl> wrote:
>
> On Tue, Aug 20, 2019 at 04:22:23PM -0700, Alexei Starovoitov wrote:
> > On Wed, Aug 21, 2019 at 12:08:59AM +0100, Peter Wu wrote:
> > > I opened /sys/kernel/tracing/trace once and kept reading from it.
> > > bpf_trace_printk somehow did not seem to work, no entries were appended
> > > to that trace file. It turns out that tracing is disabled when that file
> > > is open. Save the next person some time and document this.
> > >
> > > The trace file is described in Documentation/trace/ftrace.rst, however
> > > the implication "tracing is disabled" did not immediate translate to
> > > "bpf_trace_printk silently discards entries".
> > >
> > > Signed-off-by: Peter Wu <peter@...ensteyn.nl>
> > > ---
> > >  include/uapi/linux/bpf.h | 2 ++
> > >  1 file changed, 2 insertions(+)
> > >
> > > diff --git a/include/uapi/linux/bpf.h b/include/uapi/linux/bpf.h
> > > index 9ca333c3ce91..e4236e357ed9 100644
> > > --- a/include/uapi/linux/bpf.h
> > > +++ b/include/uapi/linux/bpf.h
> > > @@ -575,6 +575,8 @@ union bpf_attr {
> > >   *                 limited to five).
> > >   *
> > >   *                 Each time the helper is called, it appends a line to the trace.
> > > + *                 Lines are discarded while *\/sys/kernel/debug/tracing/trace* is
> > > + *                 open, use *\/sys/kernel/debug/tracing/trace_pipe* to avoid this.
> >
> > that's not quite correct.
> > Having 'trace' file open doesn't discard lines.
> > I think this type of comment in uapi header makes more confusion than helps.
>
> Having the 'trace' file open for reading results in discarding lines. It
> took me a while to figure that out. At first I was not even sure whether
> my eBPF program was executed or not due to lack of entries in the
> 'trace' file.
>
> I ended up setting a breakpoint and ended up with this call stack:
>
>   - bpf_trace_printk
>     - ____bpf_trace_printk
>       - __trace_printk
>         - trace_vprintk
>           - trace_array_vprintk
>             - __trace_array_vprintk
>               - __trace_array_vprintk
>                 - __trace_buffer_lock_reserve
>                   - ring_buffer_lock_reserve
>
> The function ends up skipping the even because record_disabled == 1:
>
>     if (unlikely(atomic_read(&buffer->record_disabled)))
>         goto out;
>
> Why is that? Well, I guessed that ring_buffer_record_disable and
> ring_buffer_record_enable would be related. Sure enough, the first one
> was hit when the 'trace' file is opened for reading while the latter is
> called when the file is closed.
>
> The relevant code from kernel/trace/trace.c (__tracing_open), "snapshot"
> is true when "trace" is opened, and "false" when "trace_pipe" is used:
>
>     /* stop the trace while dumping if we are not opening "snapshot" */
>     if (!iter->snapshot)
>         tracing_stop_tr(tr);
>
> So I think this supports the claim that lines are discarded. Do you
> think this is not the case?

Indeed.
I missed "(opened)" part in Documentation/trace/ftrace.rst:
  trace:
        This file holds the output of the trace in a human
        readable format (described below). Note, tracing is temporarily
        disabled while this file is being read (opened).

I always thought that reading disables it.
It's indeed odd part of the ftrace implementation that
worth documenting here.

Applied the set to bpf-next. Thanks