Re: [PATCH bpf-next 3/6] bpf: switch BPF verifier log to be a rotating log by default

Lorenz Bauer
2023-03-21T16:18:48Z

On Mon, Mar 20, 2023 at 6:55 PM Andrii Nakryiko
<andrii.nakryiko@gmail.com> wrote:
>
> Great feedback. Let me address all of it in one place.
>
> Let's start with right-sizing the buffer. Curiously, with existing
> (fixed) log behavior, verifier doesn't and can't know the full size of
> the buffer it needs, as we stop producing log after -ENOSPC condition
> was detected. log->ubuf is set to NULL, after which
> bpf_verifier_log_needed() will start returning false. So in existing
> "logging mode" it's impossible to support this without major changes.

I think that's fine, as long as we keep the door open to later on
extending the log_buf_max_size to append mode.

> On the other hand, with rotating log, we could determine this very
> easily! We can just maintain max(log->end_pos, last_max_end_pos)
> throughout the verification process (we need max due to log reset: it
> still might need bigger buffer than final log length).

Ah, tricky! Nitty gritty detail: can I get the max required size with
log_level > 0 but log_buf == NULL / log_size == 0?

> So, to get the full size, we need rotating log behavior.
>
> What if we just make rotating log still return -ENOSPC, and set this
> new "log_buf_max_size" field to actual required full size. That will
> keep existing retry/resize logic intact and would be backwards
> compatible, right?

There is a subtlety here: with this design it's impossible to load a
program with a rotating log and a buffer that is smaller than
log_buf_max_size. A contrived use case: for each program we load we'd
like to get the verifier stats printed as one of the last lines.
Without ENOSPC this can be done by allocating a buffer of 512 bytes or
something.

Tying errno to log buffer size is wrong imo, so it'd be nice if we
could fix the interface going forward.

> As for feature detecting this change. Yes, there is no UAPI change
> (unless we add extra field, of course), but as I implemented it right
> now it's trivial to detect the change in behavior: set small buffer
> (few bytes), try load trivial program. If you get -EINVAL, then we
> have old kernel that enforces >=128 bytes for buffer. If you specify a
> bit bigger buffer, you should get -ENOSPC. If you get success, it's
> the new behavior.

I think a better test would actually be to pass the new BPF_LOG flag
and check for EINVAL. Relying on buffer sizes is maybe a bit too
indirect?

> What I'm worried with switching this to opt-in
> (BPF_LOG_TRUNCATE_HEAD), is that for various application that would
> want to use log_level 1/2 for some diagnostics in runtime, *they*
> would need to perform this feature detection just to know that it's
> safe to provide BPF_LOG_TRUNCATE_HEAD.

Can you sketch this out a bit more, what kind of diagnostics do you
have in mind? If the application wants to parse the log it kind of
needs to know anyways? Going back to my "get verifier stats from prog
load" example above, if the rotating log isn't available I need to
either

- skip getting verifier stats
- allocate a possibly large buffer to get at it in append mode

That choice isn't one I can make as a library author.

> So I decided that it's better
> use experience to do opt-out. Just to explain my reasoning, I wanted
> to make users not care about this and just get useful log back.

Ah, this is probably where our disconnect is. In my mind, detecting
and passing BPF_LOG_TRUNCATE_HEAD is definitely the responsibility of
the library, not the users. At least for the happy / common path.
Rough sketch of how PROG_LOAD and log_buf is handled in Go (probably
similar to libbpf?)

if PROG_LOAD(user supplied log_level) < 0 && user supplied log_level == 0:
retry PROG_LOAD(log_level=1)

There is some trickery when the user passes a log_level != 0, but most
PROG_LOAD go through this logic. The way I'd go about it is to add
TRUNCATE_HEAD to the retry PROG_LOAD call if the feature exists. As a
result, most failed program loads would get the benefit of this
feature.

If a user explicitly requests a log I assume they know what they are
doing and it's probably best not to mess with it. To play the devil's
advocate, I think that making this behaviour opt out does break
expectations that user space has. See [0] for example which will have
to detect that rotating mode is used and deliberately disable that. We
can of course argue whether parsing the log is a wise thing to do, but
it's good to keep that fact in mind.

> Heh, it actually does automatically as it uses bpf_verifier_log struct
> as well. So all the BPF_PROG_LOAD changes for log apply to BPF_BTF_LOG
> command.

Nice :)

Best
Lorenz

0: https://github.com/cilium/coverbee