bpf.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
From: Florent Revest <revest@chromium.org>
To: Rasmus Villemoes <linux@rasmusvillemoes.dk>
Cc: Andrii Nakryiko <andrii.nakryiko@gmail.com>,
	bpf <bpf@vger.kernel.org>, Alexei Starovoitov <ast@kernel.org>,
	Daniel Borkmann <daniel@iogearbox.net>,
	Andrii Nakryiko <andrii@kernel.org>, Yonghong Song <yhs@fb.com>,
	KP Singh <kpsingh@kernel.org>,
	Brendan Jackman <jackmanb@chromium.org>,
	open list <linux-kernel@vger.kernel.org>
Subject: Re: [PATCH bpf-next v5 6/6] selftests/bpf: Add a series of tests for bpf_snprintf
Date: Wed, 5 May 2021 16:25:31 +0200	[thread overview]
Message-ID: <CABRcYmLvR-9WS2M7d3vYmgapVuEHXqXTY1gv3PmfW5DzhDCbHA@mail.gmail.com> (raw)
In-Reply-To: <f0888d2a-3a31-e454-001c-e46cc21b1664@rasmusvillemoes.dk>

On Wed, May 5, 2021 at 8:55 AM Rasmus Villemoes
<linux@rasmusvillemoes.dk> wrote:
>
> On 28/04/2021 16.59, Florent Revest wrote:
> > On Tue, Apr 27, 2021 at 8:03 PM Andrii Nakryiko
> > <andrii.nakryiko@gmail.com> wrote:
> >>
> >> On Tue, Apr 27, 2021 at 2:51 AM Florent Revest <revest@chromium.org> wrote:
> >>>
> >>> On Tue, Apr 27, 2021 at 8:35 AM Rasmus Villemoes
> >>> <linux@rasmusvillemoes.dk> wrote:
> >>>> Probably the test cases are not run in parallel, but this is the kind of
> >>>> thing that would give those symptoms.
> >>>
> >>> I think it's a separate issue from what Andrii reported though because
> >>> the flaky test exercises the bpf_snprintf helper and this buf spinlock
> >>> bug you just found only affects the bpf_trace_printk helper.
> >>>
> >>> That being said, it does smell a little bit like a concurrency issue
> >>> too, indeed. The bpf_snprintf test program is a raw_tp/sys_enter so it
> >>> attaches to all syscall entries and most likely gets executed many
> >>> more times than necessary and probably on parallel CPUs. The "pad_out"
> >>> buffer they write to is unique and not locked so maybe the test's
> >>> userspace reads pad_out while another CPU is writing on it and if the
> >>> string output goes through a stage where it is "    4 0000" before
> >>> being "    4 000", we might read at the wrong time. That being said, I
> >>> would find it weird that this happens as much as 50% of the time and
> >>> always specifically on that test case.
> >>>
> >>> Andrii could you maybe try changing the prog type to
> >>> "tp/syscalls/sys_enter_nanosleep" on the machine where you can
> >>> reproduce this bug ?
> >>
> >> Yes, it helps. I can't repro it easily anymore.
> >
> > Good, so it does sound like a concurrency issue indeed
> >
> >> I think the right fix, though, should be to filter by tid, not change the tracepoint.
> >
> > Agreed, I'll send a patch for that today. :)
> >
> >> I think what's happening is we see the string right before bstr_printf
> >> does zero-termination with end[-1] = '\0'; So in some cases we see
> >> truncated string, in others we see untruncated one.
> >
> > Makes sense but I still wonder why it happens so often (50% of the
> > time is really a lot) and why it is consistently that one test case
> > that fails and not the "overflow" case for example. But I'm confident
> > that this is not a bug in the helper now and that the tid filter will
> > fix the test.
> >
>
> If the caller, or one of its sibling threads, inspects the buffer before
> (v)snprintf has returned it's very obviously a bug in the caller. As for

Absolutely

> why that particular case exposes the race: It seems to be the only one
> that "expects" an insanely long result, and it takes a very very long
> time (several cycles per byte I'd assume) for the vsnprintf code to very
> carefully go through the
>
>   if (buf < end)
>      *buf = /* '0' or ' ' or whatever it is it is emitting here */
>   buf++;
>
> 900k times. So there's simply a very large window where the buffer
> contents is "    4 0000" while number() is still 'emitting' 0s until
> control returns to vsnprintf() which does that final end[-1] = '\0'.

Aaah, of course, it makes complete sense! :) Thank you Rasmus

  reply	other threads:[~2021-05-05 14:25 UTC|newest]

Thread overview: 23+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2021-04-19 15:52 [PATCH bpf-next v5 0/6] Add a snprintf eBPF helper Florent Revest
2021-04-19 15:52 ` [PATCH bpf-next v5 1/6] bpf: Factorize bpf_trace_printk and bpf_seq_printf Florent Revest
2021-04-19 15:52 ` [PATCH bpf-next v5 2/6] bpf: Add a ARG_PTR_TO_CONST_STR argument type Florent Revest
2021-04-19 22:54   ` Alexei Starovoitov
2021-04-20 12:35     ` Florent Revest
2021-04-20 15:23       ` Alexei Starovoitov
2021-04-22  8:41         ` Florent Revest
2021-04-19 15:52 ` [PATCH bpf-next v5 3/6] bpf: Add a bpf_snprintf helper Florent Revest
2021-04-19 15:52 ` [PATCH bpf-next v5 4/6] libbpf: Initialize the bpf_seq_printf parameters array field by field Florent Revest
2021-04-19 15:52 ` [PATCH bpf-next v5 5/6] libbpf: Introduce a BPF_SNPRINTF helper macro Florent Revest
2021-04-19 15:52 ` [PATCH bpf-next v5 6/6] selftests/bpf: Add a series of tests for bpf_snprintf Florent Revest
2021-04-23 22:38   ` Andrii Nakryiko
2021-04-26 10:10     ` Florent Revest
2021-04-26 16:19       ` Andrii Nakryiko
2021-04-26 21:08         ` Florent Revest
2021-04-27  6:35           ` Rasmus Villemoes
2021-04-27  9:50             ` Florent Revest
2021-04-27 18:03               ` Andrii Nakryiko
2021-04-28 14:59                 ` Florent Revest
2021-05-05  6:55                   ` Rasmus Villemoes
2021-05-05 14:25                     ` Florent Revest [this message]
2021-04-19 19:33 ` [PATCH bpf-next v5 0/6] Add a snprintf eBPF helper Andrii Nakryiko
2021-04-20 12:02   ` Florent Revest

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=CABRcYmLvR-9WS2M7d3vYmgapVuEHXqXTY1gv3PmfW5DzhDCbHA@mail.gmail.com \
    --to=revest@chromium.org \
    --cc=andrii.nakryiko@gmail.com \
    --cc=andrii@kernel.org \
    --cc=ast@kernel.org \
    --cc=bpf@vger.kernel.org \
    --cc=daniel@iogearbox.net \
    --cc=jackmanb@chromium.org \
    --cc=kpsingh@kernel.org \
    --cc=linux-kernel@vger.kernel.org \
    --cc=linux@rasmusvillemoes.dk \
    --cc=yhs@fb.com \
    --subject='Re: [PATCH bpf-next v5 6/6] selftests/bpf: Add a series of tests for bpf_snprintf' \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).