linux-kernel - Re: [PATCH bpf-next] bpf: btf: don't log ignored BTF mismatches

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Message-ID: <0b9023b6-9742-b317-7596-98026a0c5d03@meta.com>
Date:   Thu, 8 Dec 2022 10:01:08 -0800
From:   Yonghong Song <yhs@...a.com>
To:     Connor O'Brien <connoro@...gle.com>
Cc:     bpf@...r.kernel.org, Martin KaFai Lau <martin.lau@...ux.dev>,
        Alexei Starovoitov <ast@...nel.org>,
        Daniel Borkmann <daniel@...earbox.net>,
        Andrii Nakryiko <andrii@...nel.org>,
        Song Liu <song@...nel.org>, Yonghong Song <yhs@...com>,
        John Fastabend <john.fastabend@...il.com>,
        KP Singh <kpsingh@...nel.org>,
        Stanislav Fomichev <sdf@...gle.com>,
        Hao Luo <haoluo@...gle.com>, Jiri Olsa <jolsa@...nel.org>,
        linux-kernel@...r.kernel.org
Subject: Re: [PATCH bpf-next] bpf: btf: don't log ignored BTF mismatches



On 12/7/22 6:19 PM, Connor O'Brien wrote:
> On Wed, Nov 9, 2022 at 8:45 AM Yonghong Song <yhs@...a.com> wrote:
>>
>>
>>
>> On 11/8/22 6:41 PM, Connor O'Brien wrote:
>>> Enabling CONFIG_MODULE_ALLOW_BTF_MISMATCH is an indication that BTF
>>> mismatches are expected and module loading should proceed
>>> anyway. Logging with pr_warn() on every one of these "benign"
>>> mismatches creates unnecessary noise when many such modules are
>>> loaded. Instead, limit logging to the case where a BTF mismatch
>>> actually prevents a module form loading.
>>>
>>> Signed-off-by: Connor O'Brien <connoro@...gle.com>
>>> ---
>>>    kernel/bpf/btf.c | 7 ++++---
>>>    1 file changed, 4 insertions(+), 3 deletions(-)
>>>
>>> diff --git a/kernel/bpf/btf.c b/kernel/bpf/btf.c
>>> index 5579ff3a5b54..406370487413 100644
>>> --- a/kernel/bpf/btf.c
>>> +++ b/kernel/bpf/btf.c
>>> @@ -7190,11 +7190,12 @@ static int btf_module_notify(struct notifier_block *nb, unsigned long op,
>>>                }
>>>                btf = btf_parse_module(mod->name, mod->btf_data, mod->btf_data_size);
>>>                if (IS_ERR(btf)) {
>>> -                     pr_warn("failed to validate module [%s] BTF: %ld\n",
>>> -                             mod->name, PTR_ERR(btf));
>>
>> I think such warning still useful even with
>> CONFIG_MODULE_ALLOW_BTF_MISMATCH.
>> Can we use pr_warn_ratelimited instead of pr_warn in the above to
>> avoid excessive warnings?
> 
> I gave this a try on a Pixel 6 but I'm not sure it quite addresses the
> issue. The amount of logging doesn't seem to decrease much, I think
> because the interval between loading one mismatched module and the
> next can be greater than the default rate limit. To my mind, the issue
> is the total volume of these messages more so than their rate.
> 
> For context, Android devices using the GKI may load hundreds of
> separately-built modules, and BTF mismatches are possible for any/all
> of these. It was pointed out to me that btf_verifier_log_type can also
> print several more lines per mismatched module. ~5 lines of logging
> for each mismatched module can start to add up, in terms of both
> overhead and the noise added to the kernel logs.
> 
> This is more subjective but I think the warnings also read as though
> this is a more serious failure that might prevent affected modules
> from working correctly; anecdotally, I've gotten multiple questions
> about them asking if something is broken. This can be a red herring
> for anyone unfamiliar with BTF who is reading the logs to debug
> unrelated issues. In the CONFIG_MODULE_ALLOW_BTF_MISMATCH=y case the
> flood of warnings seems out of proportion to the actual result
> (modules still load successfully, just without debug info) especially
> since the user has explicitly enabled a config saying they expect
> mismatches.
> 
> If there needs to be some logging in the "mismatch allowed" case,
> could an acceptable middle ground be to use pr_warn_once to send a

So it looks like pr_warn_ratelimited still produces a lot of warning.
In this case, I guess pr_warn_once should be okay.

> single message reporting that mismatches were detected & module BTF
> debug info might be unavailable? Alternatively, if we could opt out of
> module BTF loading then that would also avoid this issue, but that's
> already been proposed before ([1], [2]) so I thought working with the
> existing config option might be preferred.
> 
> [1] https://lore.kernel.org/bpf/20220209052141.140063-1-connoro@google.com/
> [2] https://lore.kernel.org/bpf/20221004222725.2813510-1-sdf@google.com/