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:

quoted

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...

quoted

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