Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) client-ip=2620:137:e000::1:20;
MIME-Version: 1.0
References: <CABPqkBRVF9qmxKFgmjZpzN3tx=U+_8udECMLHs7BrtzfPwmuhQ@mail.gmail.com>
 <YqyVFsbviKjVGGZ9@worktop.programming.kicks-ass.net>
In-Reply-To: <YqyVFsbviKjVGGZ9@worktop.programming.kicks-ass.net>
From:   Stephane Eranian <eranian@google.com>
Date:   Wed, 22 Jun 2022 19:51:02 +0200
Message-ID: <CABPqkBRRFhPcYL25TX6H7vWN=VKNR2+8e2_sO01Pka_R625Lqw@mail.gmail.com>
Subject: Re: [RFC] pr_warn_once() issue in x86 MSR extable code
To:     Peter Zijlstra <peterz@infradead.org>
Cc:     LKML <linux-kernel@vger.kernel.org>,
        Eric Dumazet <edumazet@google.com>, jpoimboe@redhat.com,
        Steven Rostedt <rostedt@goodmis.org>
Content-Type: text/plain; charset="UTF-8"
Precedence: bulk

Hi Peter,

Thanks for taking a quick look at this.
I am currently OOO and I cannot test this proposed patch.
I am okay with your suggestion.

Thanks.

On Fri, Jun 17, 2022 at 4:52 PM Peter Zijlstra <peterz@infradead.org> wrote:
>
> On Fri, Jun 17, 2022 at 02:08:52PM +0300, Stephane Eranian wrote:
> > Hi,
> >
> > Some changes to the way invalid MSR accesses are reported by the kernel is
> > causing some problems with messages printed on the console.
> >
> > We have seen several cases of ex_handler_msr() printing invalid MSR
> > accesses once but
> > the callstack multiple times causing confusion on the console.
> >
> > The last time the exception MSR code was modified (5.16) by PeterZ was:
> >
> >   d52a7344bdfa x86/msr: Remove .fixup usage:
> >
> >   if (!safe && wrmsr &&  pr_warn_once("unchecked MSR access error: ..."))
> >                show_stack_regs(regs);
> >
> > Note that this code pattern was also present, though in a different
> > form, before this commit.
> >
> > The problem here is that another earlier commit (5.13):
> >
> > a358f40600b3 once: implement DO_ONCE_LITE for non-fast-path "do once"
> > functionality
> >
> > Modifies all the pr_*_once() calls to always return true claiming that
> > no caller is ever
> > checking the return value of the functions.
> >
> > This is why we are seeing the callstack printed without the associated
> > printk() msg.
> >
> > I believe that having the pr_*_once() functions return true the first
> > time they are called
> > is useful especially when extra information, such as callstack, must
> > be printed to help
> > track the origin of the problem.
> >
> > The exception handling code seems to be the only place where the
> > return value is checked
> > for pr_warn_once(). A minimal change would be to create another
> > version of that function
> > that calls DO_ONCE() instead of DO_ONCE_LITE(), e.g., pr_warn_once_return().
> >
> > I can post a patch to that effect if we all agree on the approach.
> >
> > Thanks.
>
> How about something like this?
>
> diff --git a/arch/x86/mm/extable.c b/arch/x86/mm/extable.c
> index dba2197c05c3..331310c29349 100644
> --- a/arch/x86/mm/extable.c
> +++ b/arch/x86/mm/extable.c
> @@ -94,16 +94,18 @@ static bool ex_handler_copy(const struct exception_table_entry *fixup,
>  static bool ex_handler_msr(const struct exception_table_entry *fixup,
>                            struct pt_regs *regs, bool wrmsr, bool safe, int reg)
>  {
> -       if (!safe && wrmsr &&
> -           pr_warn_once("unchecked MSR access error: WRMSR to 0x%x (tried to write 0x%08x%08x) at rIP: 0x%lx (%pS)\n",
> -                        (unsigned int)regs->cx, (unsigned int)regs->dx,
> -                        (unsigned int)regs->ax,  regs->ip, (void *)regs->ip))
> +       if (__ONCE_LITE_IF(!safe && wrmsr)) {
> +               pr_warn("unchecked MSR access error: WRMSR to 0x%x (tried to write 0x%08x%08x) at rIP: 0x%lx (%pS)\n",
> +                       (unsigned int)regs->cx, (unsigned int)regs->dx,
> +                       (unsigned int)regs->ax,  regs->ip, (void *)regs->ip);
>                 show_stack_regs(regs);
> +       }
>
> -       if (!safe && !wrmsr &&
> -           pr_warn_once("unchecked MSR access error: RDMSR from 0x%x at rIP: 0x%lx (%pS)\n",
> -                        (unsigned int)regs->cx, regs->ip, (void *)regs->ip))
> +       if (__ONCE_LITE_IF(!safe && !wrmsr)) {
> +               pr_warn("unchecked MSR access error: RDMSR from 0x%x at rIP: 0x%lx (%pS)\n",
> +                       (unsigned int)regs->cx, regs->ip, (void *)regs->ip);
>                 show_stack_regs(regs);
> +       }
>
>         if (!wrmsr) {
>                 /* Pretend that the read succeeded and returned 0. */
> diff --git a/include/linux/once_lite.h b/include/linux/once_lite.h
> index 861e606b820f..63c3bbcef694 100644
> --- a/include/linux/once_lite.h
> +++ b/include/linux/once_lite.h
> @@ -9,15 +9,27 @@
>   */
>  #define DO_ONCE_LITE(func, ...)                                                \
>         DO_ONCE_LITE_IF(true, func, ##__VA_ARGS__)
> -#define DO_ONCE_LITE_IF(condition, func, ...)                          \
> +
> +#define __ONCE_LITE_IF(condition)                                      \
>         ({                                                              \
>                 static bool __section(".data.once") __already_done;     \
> -               bool __ret_do_once = !!(condition);                     \
> +               bool __ret_cond = !!(condition);                        \
> +               bool __ret_once = false;                                \
>                                                                         \
>                 if (unlikely(__ret_do_once && !__already_done)) {       \
>                         __already_done = true;                          \
> -                       func(__VA_ARGS__);                              \
> +                       __ret_once = true;                              \
>                 }                                                       \
> +               unlikely(__ret_once);                                   \
> +       })
> +
> +#define DO_ONCE_LITE_IF(condition, func, ...)                          \
> +       ({                                                              \
> +               bool __ret_do_once = !!(condition);                     \
> +                                                                       \
> +               if (__ONCE_LITE_IF(__ret_do_once))                      \
> +                       func(__VA_ARGS__);                              \
> +                                                                       \
>                 unlikely(__ret_do_once);                                \
>         })
>