On Tue, Apr 4, 2023 at 5:37 AM Andrii Nakryiko <andrii@xxxxxxxxxx> wrote: > > This turned into a pretty sizable patch set with lots of arithmetics, but > hopefully the set of features added to verifier log in this patch set are both > useful for BPF users and are self-contained and isolated enough to not cause > troubles going forward. Hi Andrii, Thanks for pushing this forward, this will make all of the log handling so much nicer. Sorry it took a while to review, but it's quite a chunky series as you point out yourself :) Maybe it makes sense to pull out some of the acked bits (moving code around, etc.) into a separate patch set? I'll send out individual reviews shortly, but wanted to put my my main proposal here. It's only compile tested, but it's hopefully clearer than my words. Note that I didn't fix up whitespace to make the diff smaller. It should apply on top of your branch. >From 162afa86d109954a4951d052513580849bd5cc54 Mon Sep 17 00:00:00 2001 From: Lorenz Bauer <lmb@xxxxxxxxxxxxx> Date: Wed, 5 Apr 2023 18:24:42 +0100 Subject: [PATCH] bpf: simplify log nul termination and FIXED mode Signed-off-by: Lorenz Bauer <lmb@xxxxxxxxxxxxx> --- kernel/bpf/log.c | 105 ++++++++++++++++++++++------------------------- 1 file changed, 50 insertions(+), 55 deletions(-) diff --git a/kernel/bpf/log.c b/kernel/bpf/log.c index ab8149448724..b6b59047a594 100644 --- a/kernel/bpf/log.c +++ b/kernel/bpf/log.c @@ -54,45 +54,13 @@ static void bpf_vlog_update_len_max(struct bpf_verifier_log *log, u32 add_len) log->len_max = len; } -void bpf_verifier_vlog(struct bpf_verifier_log *log, const char *fmt, - va_list args) +static void bpf_vlog_emit(struct bpf_verifier_log *log, const char *kbuf, u32 n) { u64 cur_pos; - u32 new_n, n; - - n = vscnprintf(log->kbuf, BPF_VERIFIER_TMP_LOG_SIZE, fmt, args); - - WARN_ONCE(n >= BPF_VERIFIER_TMP_LOG_SIZE - 1, - "verifier log line truncated - local buffer too short\n"); - - if (log->level == BPF_LOG_KERNEL) { - bool newline = n > 0 && log->kbuf[n - 1] == '\n'; - - pr_err("BPF: %s%s", log->kbuf, newline ? "" : "\n"); - return; - } - - n += 1; /* include terminating zero */ - bpf_vlog_update_len_max(log, n); - - if (log->level & BPF_LOG_FIXED) { - /* check if we have at least something to put into user buf */ - new_n = 0; - if (log->end_pos + 1 < log->len_total) { - new_n = min_t(u32, log->len_total - log->end_pos, n); - log->kbuf[new_n - 1] = '\0'; - } - cur_pos = log->end_pos; - log->end_pos += n - 1; /* don't count terminating '\0' */ - - if (log->ubuf && new_n && - copy_to_user(log->ubuf + cur_pos, log->kbuf, new_n)) - goto fail; - } else { u64 new_end, new_start; u32 buf_start, buf_end, new_n; - log->kbuf[n - 1] = '\0'; + bpf_vlog_update_len_max(log, n); new_end = log->end_pos + n; if (new_end - log->start_pos >= log->len_total) @@ -101,7 +69,7 @@ void bpf_verifier_vlog(struct bpf_verifier_log *log, const char *fmt, new_start = log->start_pos; log->start_pos = new_start; - log->end_pos = new_end - 1; /* don't count terminating '\0' */ + log->end_pos = new_end; if (!log->ubuf) return; @@ -126,35 +94,60 @@ void bpf_verifier_vlog(struct bpf_verifier_log *log, const char *fmt, if (buf_start < buf_end) { /* message fits within contiguous chunk of ubuf */ if (copy_to_user(log->ubuf + buf_start, - log->kbuf + n - new_n, + kbuf + n - new_n, buf_end - buf_start)) goto fail; } else { /* message wraps around the end of ubuf, copy in two chunks */ if (copy_to_user(log->ubuf + buf_start, - log->kbuf + n - new_n, + kbuf + n - new_n, log->len_total - buf_start)) goto fail; if (copy_to_user(log->ubuf, - log->kbuf + n - buf_end, + kbuf + n - buf_end, buf_end)) goto fail; } - } - return; fail: log->ubuf = NULL; } -void bpf_vlog_reset(struct bpf_verifier_log *log, u64 new_pos) +static u32 bpf_vlog_available(const struct bpf_verifier_log *log) { - char zero = 0; - u32 pos; + return log->len_total - (log->end_pos - log->start_pos); +} + +void bpf_verifier_vlog(struct bpf_verifier_log *log, const char *fmt, + va_list args) +{ + /* NB: contrary to vsnprintf n can't be larger than sizeof(log->kbuf) */ + u32 n = vscnprintf(log->kbuf, sizeof(log->kbuf), fmt, args); + + if (log->level == BPF_LOG_KERNEL) { + bool newline = n > 0 && log->kbuf[n - 1] == '\n'; + + pr_err("BPF: %s%s", log->kbuf, newline ? "" : "\n"); + return; + } + if (log->level & BPF_LOG_FIXED) { + bpf_vlog_update_len_max(log, n); + /* avoid rotation by never emitting more than what's unused */ + n = min_t(u32, n, bpf_vlog_available(log)); + } + + bpf_vlog_emit(log, log->kbuf, n); +} + +void bpf_vlog_reset(struct bpf_verifier_log *log, u64 new_pos) +{ if (!bpf_verifier_log_needed(log) || log->level == BPF_LOG_KERNEL) return; + if (WARN_ON_ONCE(new_pos > log->end_pos)) + return; + /* if position to which we reset is beyond current log window, * then we didn't preserve any useful content and should adjust * start_pos to end up with an empty log (start_pos == end_pos) @@ -162,17 +155,6 @@ void bpf_vlog_reset(struct bpf_verifier_log *log, u64 new_pos) log->end_pos = new_pos; if (log->end_pos < log->start_pos) log->start_pos = log->end_pos; - - if (!log->ubuf) - return; - - if (log->level & BPF_LOG_FIXED) - pos = log->end_pos + 1; - else - div_u64_rem(new_pos, log->len_total, &pos); - - if (pos < log->len_total && put_user(zero, log->ubuf + pos)) - log->ubuf = NULL; } static void bpf_vlog_reverse_kbuf(char *buf, int len) @@ -228,6 +210,7 @@ static bool bpf_vlog_truncated(const struct bpf_verifier_log *log) int bpf_vlog_finalize(struct bpf_verifier_log *log, u32 *log_size_actual) { + char zero = 0; u32 sublen; int err; @@ -237,8 +220,20 @@ int bpf_vlog_finalize(struct bpf_verifier_log *log, u32 *log_size_actual) if (!log->ubuf) goto skip_log_rotate; + + if (log->level & BPF_LOG_FIXED) { + bpf_vlog_update_len_max(log, 1); + + /* terminate by (potentially) overwriting the last byte */ + if (put_user(zero, log->ubuf + min_t(u32, log->end_pos, log->len_total-1)) + return -EFAULT; + } else { + /* terminate by (potentially) rotating out the first byte */ + bpf_vlog_emit(log, &zero, 1); + } + /* If we never truncated log, there is nothing to move around. */ - if ((log->level & BPF_LOG_FIXED) || log->start_pos == 0) + if (log->start_pos == 0) goto skip_log_rotate; /* Otherwise we need to rotate log contents to make it start from the -- 2.39.2