From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by smtp.lore.kernel.org (Postfix) with ESMTP id 43D96C74A5B for ; Fri, 17 Mar 2023 22:04:37 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S229517AbjCQWEg convert rfc822-to-8bit (ORCPT ); Fri, 17 Mar 2023 18:04:36 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:48814 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S230100AbjCQWEf (ORCPT ); Fri, 17 Mar 2023 18:04:35 -0400 Received: from mx0a-00082601.pphosted.com (mx0b-00082601.pphosted.com [67.231.153.30]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 3DCEF31BD2 for ; Fri, 17 Mar 2023 15:04:32 -0700 (PDT) Received: from pps.filterd (m0089730.ppops.net [127.0.0.1]) by m0089730.ppops.net (8.17.1.19/8.17.1.19) with ESMTP id 32HKEuV5001839 for ; Fri, 17 Mar 2023 15:04:31 -0700 Received: from maileast.thefacebook.com ([163.114.130.16]) by m0089730.ppops.net (PPS) with ESMTPS id 3pcsyutsv9-1 (version=TLSv1.2 cipher=ECDHE-RSA-AES128-GCM-SHA256 bits=128 verify=NOT) for ; Fri, 17 Mar 2023 15:04:31 -0700 Received: from twshared6687.46.prn1.facebook.com (2620:10d:c0a8:1b::d) by mail.thefacebook.com (2620:10d:c0a8:83::5) with Microsoft SMTP Server (version=TLS1_2, cipher=TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256) id 15.1.2507.17; Fri, 17 Mar 2023 15:04:08 -0700 Received: by devbig019.vll3.facebook.com (Postfix, from userid 137359) id 340462AEB756E; Fri, 17 Mar 2023 15:04:05 -0700 (PDT) From: Andrii Nakryiko To: , , , CC: , Subject: [PATCH bpf-next 6/6] selftests/bpf: add fixed vs rotating verifier log tests Date: Fri, 17 Mar 2023 15:03:51 -0700 Message-ID: <20230317220351.2970665-7-andrii@kernel.org> X-Mailer: git-send-email 2.34.1 In-Reply-To: <20230317220351.2970665-1-andrii@kernel.org> References: <20230317220351.2970665-1-andrii@kernel.org> MIME-Version: 1.0 Content-Transfer-Encoding: 8BIT X-FB-Internal: Safe Content-Type: text/plain X-Proofpoint-ORIG-GUID: Q1BISTPWBEKHKnulKx1qk1XT0a7ruF54 X-Proofpoint-GUID: Q1BISTPWBEKHKnulKx1qk1XT0a7ruF54 X-Proofpoint-Virus-Version: vendor=baseguard engine=ICAP:2.0.254,Aquarius:18.0.942,Hydra:6.0.573,FMLib:17.11.170.22 definitions=2023-03-17_17,2023-03-16_02,2023-02-09_01 Precedence: bulk List-ID: X-Mailing-List: bpf@vger.kernel.org Add selftests validating BPF_LOG_FIXED behavior, which used to be the only behavior, and now default rotating BPF verifier log, which returns just up to last N bytes of full verifier log, instead of returning -ENOSPC. To stress test correctness of in-kernel verifier log logic, we force it to truncate program's verifier log to all lengths from 1 all the way to its full size (about 450 bytes today). This was a useful stress test while developing the feature. Signed-off-by: Andrii Nakryiko --- .../selftests/bpf/prog_tests/verifier_log.c | 156 ++++++++++++++++++ 1 file changed, 156 insertions(+) create mode 100644 tools/testing/selftests/bpf/prog_tests/verifier_log.c diff --git a/tools/testing/selftests/bpf/prog_tests/verifier_log.c b/tools/testing/selftests/bpf/prog_tests/verifier_log.c new file mode 100644 index 000000000000..3c5cdf257014 --- /dev/null +++ b/tools/testing/selftests/bpf/prog_tests/verifier_log.c @@ -0,0 +1,156 @@ +// SPDX-License-Identifier: GPL-2.0 +/* Copyright (c) 2023 Meta Platforms, Inc. and affiliates. */ + +#include +#include + +#include "test_log_buf.skel.h" + + +static bool check_prog_load(int prog_fd, bool expect_err, const char *tag) +{ + if (expect_err) { + if (!ASSERT_LT(prog_fd, 0, tag)) { + close(prog_fd); + return false; + } + } else /* !expect_err */ { + if (!ASSERT_GT(prog_fd, 0, tag)) + return false; + } + return true; +} + +static void verif_log_subtest(const char *name, bool expect_load_error, int log_level) +{ + LIBBPF_OPTS(bpf_prog_load_opts, opts); + struct { + /* strategically placed before others to avoid accidental modification by kernel */ + char filler[1024]; + char buf[1024]; + /* strategically placed after buf[] to catch more accidental corruptions */ + char reference[1024]; + } logs; + char *exp_log, prog_name[16], op_name[32]; + struct test_log_buf *skel; + struct bpf_program *prog; + const struct bpf_insn *insns; + size_t insn_cnt, fixed_log_sz; + int i, err, prog_fd; + + skel = test_log_buf__open(); + if (!ASSERT_OK_PTR(skel, "skel_open")) + return; + + bpf_object__for_each_program(prog, skel->obj) { + if (strcmp(bpf_program__name(prog), name) == 0) + bpf_program__set_autoload(prog, true); + else + bpf_program__set_autoload(prog, false); + } + + err = test_log_buf__load(skel); + if (!expect_load_error && !ASSERT_OK(err, "unexpected_load_failure")) + goto cleanup; + if (expect_load_error && !ASSERT_ERR(err, "unexpected_load_success")) + goto cleanup; + + insns = bpf_program__insns(skel->progs.good_prog); + insn_cnt = bpf_program__insn_cnt(skel->progs.good_prog); + + opts.log_buf = logs.reference; + opts.log_size = sizeof(logs.reference); + opts.log_level = log_level | 8 /* BPF_LOG_FIXED */; + prog_fd = bpf_prog_load(BPF_PROG_TYPE_RAW_TRACEPOINT, "log_fixed", + "GPL", insns, insn_cnt, &opts); + if (!check_prog_load(prog_fd, expect_load_error, "fixed_buf_prog_load")) + goto cleanup; + close(prog_fd); + + fixed_log_sz = strlen(logs.reference) + 1; + if (!ASSERT_GT(fixed_log_sz, 50, "fixed_log_sz")) + goto cleanup; + + /* validate BPF_LOG_FIXED works as verifier log used to work, that is: + * we get -ENOSPC and beginning of the full verifier log. This only + * works for log_level 2 and log_level 1 + failed program. For log + * level 2 we don't reset log at all. For log_level 1 + failed program + * we don't get to verification stats output. With log level 1 + * for successful program final result will be just verifier stats. + * But if provided too short log buf, kernel will NULL-out log->ubuf + * and will stop emitting further log. This means we'll never see + * predictable verifier stats. + * Long story short, we do the following -ENOSPC test only for + * predictable combinations. + */ + if (log_level >= 2 || expect_load_error) { + opts.log_buf = logs.buf; + opts.log_level = log_level | 8; /* fixed-length log */ + opts.log_size = 25; + + prog_fd = bpf_prog_load(BPF_PROG_TYPE_RAW_TRACEPOINT, "log_fixed50", + "GPL", insns, insn_cnt, &opts); + if (!ASSERT_EQ(prog_fd, -ENOSPC, "unexpected_log_fixed_prog_load_result")) { + if (prog_fd >= 0) + close(prog_fd); + goto cleanup; + } + if (!ASSERT_EQ(strlen(logs.buf), 24, "log_fixed_25")) + goto cleanup; + if (!ASSERT_STRNEQ(logs.buf, logs.reference, 24, op_name)) + goto cleanup; + } + + /* validate rolling verifier log logic: try all variations of log buf + * length to force various truncation scenarios + */ + opts.log_buf = logs.buf; + opts.log_level = log_level; /* rolling log */ + + /* prefill logs.buf with 'A's to detect any write beyond allowed length */ + memset(logs.filler, 'A', sizeof(logs.filler)); + logs.filler[sizeof(logs.filler) - 1] = '\0'; + memset(logs.buf, 'A', sizeof(logs.buf)); + logs.buf[sizeof(logs.buf) - 1] = '\0'; + + for (i = 1; i <= fixed_log_sz; i++) { + opts.log_size = i; + + snprintf(prog_name, sizeof(prog_name), "log_roll_%d", i); + prog_fd = bpf_prog_load(BPF_PROG_TYPE_RAW_TRACEPOINT, prog_name, + "GPL", insns, insn_cnt, &opts); + + snprintf(op_name, sizeof(op_name), "log_roll_prog_load_%d", i); + if (!check_prog_load(prog_fd, expect_load_error, op_name)) + goto cleanup; + close(prog_fd); + + exp_log = logs.reference + fixed_log_sz - i; + snprintf(op_name, sizeof(op_name), "log_roll_contents_%d", i); + if (!ASSERT_STREQ(logs.buf, exp_log, op_name)) + goto cleanup; + + printf("CMP:%d\nS1:'%s'\nS2:'%s'\n", strcmp(logs.buf + i, logs.filler + i), + logs.buf + i, logs.filler + i); + + /* check that unused portions of logs.buf is not overwritten */ + snprintf(op_name, sizeof(op_name), "log_roll_unused_tail_%d", i); + if (!ASSERT_STREQ(logs.buf + i, logs.filler + i, op_name)) + goto cleanup; + } + +cleanup: + test_log_buf__destroy(skel); +} + +void test_verifier_log(void) +{ + if (test__start_subtest("good_prog-level1")) + verif_log_subtest("good_prog", false, 1); + if (test__start_subtest("good_prog-level2")) + verif_log_subtest("good_prog", false, 2); + if (test__start_subtest("bad_prog-level1")) + verif_log_subtest("bad_prog", true, 1); + if (test__start_subtest("bad_prog-level2")) + verif_log_subtest("bad_prog", true, 2); +} -- 2.34.1