linux-kernel - Re: [PATCH] x86/mce/dev-mcelog: Call mce_register_decode

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]

Date:   Mon, 23 Aug 2021 11:45:47 -0700
From:   "Luck, Tony" <tony.luck@...el.com>
To:     Borislav Petkov <bp@...en8.de>
Cc:     x86@...nel.org, linux-edac@...r.kernel.org,
        linux-kernel@...r.kernel.org,
        Sumanth Kamatala <skamatala@...iper.net>
Subject: Re: [PATCH] x86/mce/dev-mcelog: Call mce_register_decode_chain()
 much earlier

On Fri, Aug 20, 2021 at 05:48:21PM +0200, Borislav Petkov wrote:
> On Fri, Aug 20, 2021 at 07:43:14AM -0700, Luck, Tony wrote:
> > How can the kernel tell that all consumers have registered? Is there
> > some new kernel crystal ball functionality that can predict that an
> > EDAC driver module is going to be loaded at some point in the future
> > when user space is up and running :-)
> 
> The crystal ball is called mcheck_late_init(). There's even:
> 
>         /*
>          * Flush out everything that has been logged during early boot, now that
>          * everything has been initialized (workqueues, decoders, ...).
>          */
>         mce_schedule_work();
> 
> in there. That thing is late_initcall() and by that time mcelog should
> have been registered. And I wonder why isn't that working as expected...
> 
> > I think the best we could do would be to set a timer for some point
> > far enough out (one minute?, two minutes?) to give a chance for
> > modules to load.
> 
> Forget modules - only the built-in stuff. We cannot be waiting
> indefinitely until someone loads mcelog for decoding.

I added some traces:

$ dmesg | grep mce:
[    0.033648] mce: mce_register_decode_chain fn=mce_early_notifier+0x0/0x50 pri=6
[    0.033655] mce: mce_register_decode_chain fn=uc_decode_notifier+0x0/0xd0 pri=5
[    0.033659] mce: mce_register_decode_chain fn=mce_default_notifier+0x0/0x30 pri=0
[    4.392631] mce: [Hardware Error]: Machine check events logged
[    4.393356] mce: [Hardware Error]: CPU 0: Machine Check: 0 Bank 0: a000000000004321
[    4.395352] mce: [Hardware Error]: TSC 0
[    4.396352] mce: [Hardware Error]: PROCESSOR 0:406f1 TIME 1629743651 SOCKET 0 APIC 0 microcode b000019
[   15.172861] mce: mce_register_decode_chain fn=dev_mce_log+0x0/0x110 pri=1
[   15.192101] mce: mcheck_late_init: calling mce_schedule_work()
[   31.618245] mce: mce_register_decode_chain fn=sbridge_mce_check_error+0x0/0x92 [sb_edac] pri=2

So you are right that mcheck_late_init() is called after dev_mce_log()
is registered.  But it seems someone kicks the queue long before that
happens.  Probably this:

void mce_log(struct mce *m)
{
        if (!mce_gen_pool_add(m))
                irq_work_queue(&mce_irq_work);
}

Could we add a flag:

static bool mce_ready_to_rock; // better name needed :-)

Which gets set in mcheck_late_init(). Then mce_log() becomes:

void mce_log(struct mce *m)
{
        if (!mce_gen_pool_add(m) && mce_ready_to_rock)
                irq_work_queue(&mce_irq_work);
}

-Tony