lkml.org 
[lkml]   [2020]   [Jul]   [9]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Date
From
SubjectRe: [PATCH bpf-next 1/2] bpf: use dedicated bpf_trace_printk event instead of trace_printk()

On Tue, 7 Jul 2020, Andrii Nakryiko wrote:

> On Fri, Jul 3, 2020 at 7:47 AM Alan Maguire <alan.maguire@oracle.com> wrote:
> >
> > The bpf helper bpf_trace_printk() uses trace_printk() under the hood.
> > This leads to an alarming warning message originating from trace
> > buffer allocation which occurs the first time a program using
> > bpf_trace_printk() is loaded.
> >
> > We can instead create a trace event for bpf_trace_printk() and enable
> > it in-kernel when/if we encounter a program using the
> > bpf_trace_printk() helper. With this approach, trace_printk()
> > is not used directly and no warning message appears.
> >
> > This work was started by Steven (see Link) and finished by Alan; added
> > Steven's Signed-off-by with his permission.
> >
> > Link: https://lore.kernel.org/r/20200628194334.6238b933@oasis.local.home
> > Signed-off-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
> > Signed-off-by: Alan Maguire <alan.maguire@oracle.com>
> > ---
> > kernel/trace/Makefile | 2 ++
> > kernel/trace/bpf_trace.c | 41 +++++++++++++++++++++++++++++++++++++----
> > kernel/trace/bpf_trace.h | 34 ++++++++++++++++++++++++++++++++++
> > 3 files changed, 73 insertions(+), 4 deletions(-)
> > create mode 100644 kernel/trace/bpf_trace.h
> >
>
> [...]
>
> > +static DEFINE_SPINLOCK(trace_printk_lock);
> > +
> > +#define BPF_TRACE_PRINTK_SIZE 1024
> > +
> > +static inline int bpf_do_trace_printk(const char *fmt, ...)
> > +{
> > + static char buf[BPF_TRACE_PRINTK_SIZE];
> > + unsigned long flags;
> > + va_list ap;
> > + int ret;
> > +
> > + spin_lock_irqsave(&trace_printk_lock, flags);
> > + va_start(ap, fmt);
> > + ret = vsnprintf(buf, BPF_TRACE_PRINTK_SIZE, fmt, ap);
> > + va_end(ap);
> > + if (ret > 0)
> > + trace_bpf_trace_printk(buf);
>
> Is there any reason to artificially limit the case of printing empty
> string? It's kind of an awkward use case, for sure, but having
> guarantee that every bpf_trace_printk() invocation triggers tracepoint
> is a nice property, no?
>

True enough; I'll modify the above to support empty string display also.

> > + spin_unlock_irqrestore(&trace_printk_lock, flags);
> > +
> > + return ret;
> > +}
> > +
> > /*
> > * Only limited trace_printk() conversion specifiers allowed:
> > * %d %i %u %x %ld %li %lu %lx %lld %lli %llu %llx %p %pB %pks %pus %s
> > @@ -483,8 +510,7 @@ static void bpf_trace_copy_string(char *buf, void *unsafe_ptr, char fmt_ptype,
> > */
> > #define __BPF_TP_EMIT() __BPF_ARG3_TP()
> > #define __BPF_TP(...) \
> > - __trace_printk(0 /* Fake ip */, \
> > - fmt, ##__VA_ARGS__)
> > + bpf_do_trace_printk(fmt, ##__VA_ARGS__)
> >
> > #define __BPF_ARG1_TP(...) \
> > ((mod[0] == 2 || (mod[0] == 1 && __BITS_PER_LONG == 64)) \
> > @@ -518,13 +544,20 @@ static void bpf_trace_copy_string(char *buf, void *unsafe_ptr, char fmt_ptype,
> > .arg2_type = ARG_CONST_SIZE,
> > };
> >
> > +int bpf_trace_printk_enabled;
>
> static?
>

oops, will fix.

> > +
> > const struct bpf_func_proto *bpf_get_trace_printk_proto(void)
> > {
> > /*
> > * this program might be calling bpf_trace_printk,
> > - * so allocate per-cpu printk buffers
> > + * so enable the associated bpf_trace/bpf_trace_printk event.
> > */
> > - trace_printk_init_buffers();
> > + if (!bpf_trace_printk_enabled) {
> > + if (trace_set_clr_event("bpf_trace", "bpf_trace_printk", 1))
>
> just to double check, it's ok to simultaneously enable same event in
> parallel, right?
>

From an ftrace perspective, it looks fine since the actual enable is
mutex-protected. We could grab the trace_printk_lock here too I guess,
but I don't _think_ there's a need.

Thanks for reviewing! I'll spin up a v2 with the above fixes shortly
plus I'll change to using tp/raw_syscalls/sys_enter in the test as you
suggested.

Alan

\
 
 \ /
  Last update: 2020-07-09 18:06    [W:0.060 / U:2.324 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site