Re: printk.time causes rare kernel boot hangs

["Richard W.M. Jones" <rjones@redhat.com>]

On Wed, Jun 14, 2023 at 11:21:58AM +0200, Peter Zijlstra wrote:
> On Tue, Jun 13, 2023 at 02:41:05PM +0100, Richard W.M. Jones wrote:
> > [Being tracked in this bug which contains much more detail:
> > https://gitlab.com/qemu-project/qemu/-/issues/1696 ]
> 
> Can I please just get the detail in mail instead of having to go look at
> random websites?

Sure, the kernel hangs after printing:

[    0.070120] x86/cpu: User Mode Instruction Prevention (UMIP) activated
[    0.070120] Last level iTLB entries: 4KB 512, 2MB 255, 4MB 127
[    0.070120] Last level dTLB entries: 4KB 512, 2MB 255, 4MB 127, 1GB 0
[    0.070120] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
[    0.070120] Spectre V2 : Mitigation: Retpolines
[    0.070120] Spectre V2 : Spectre v2 / SpectreRSB mitigation: Filling RSB on context switch
[    0.070120] Spectre V2 : Spectre v2 / SpectreRSB : Filling RSB on VMEXIT
[    0.070120] Spectre V2 : Enabling Speculation Barrier for firmware calls
[    0.070120] RETBleed: Mitigation: untrained return thunk
[    0.070120] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier
[    0.070120] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl
[    0.070120] Freeing SMP alternatives memory: 48K

The next message we'd expect here would be:

[    0.070794] smpboot: CPU0: AMD Ryzen 9 3900X 12-Core Processor (family: 0x17, model: 0x71, stepping: 0x0)

I believe this bug would affect baremetal too, basically any kernel
compiled with CONFIG_PRINTK_TIME.  However the hang is very rare.

> > Recent kernels hang rarely when booted on qemu.  Usually you need to
> > boot 100s or 1,000s of times to see the hang, compared to 292,612 [sic]
> > successful boots which I was able to do before the problematic commit.
> > 
> > A reproducer (you'll probably need to use Fedora) is:
> 
> Debian only shop here... in fact, I still have machines without systemd.

Debian should work too actually, just run the following command until
it hangs:

> >   $ while guestfish -a /dev/null -v run >& /tmp/log; do echo -n . ; done
> > 
> > You will need to leave it running for probably several hours, and
> > examine the /tmp/log file at the end.
> > 
> > I tracked this down to the following commit:
> > 
> >   commit f31dcb152a3d0816e2f1deab4e64572336da197d
> >   Author: Aaron Thompson <dev@aaront.org>
> >   Date:   Thu Apr 13 17:50:12 2023 +0000
> > 
> >     sched/clock: Fix local_clock() before sched_clock_init()
> >     
> >     Have local_clock() return sched_clock() if sched_clock_init() has not
> >     yet run. sched_clock_cpu() has this check but it was not included in the
> >     new noinstr implementation of local_clock().
> > 
> >   (https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=f31dcb152a3d0816e2f1deab4e64572336da197d)
> > 
> > Reverting this commit fixes the problem.
> > 
> > I don't know _why_ this commit is wrong, but can we revert it as it
> > causes serious problems with libguestfs hanging randomly.
> > 
> > Or if there's anything you want me to try out then let me know,
> > because I can reproduce the problem locally quite easily.
> 
> Well, since it's virt and all, can you attach gdb to the gdb-stub and
> see where it's at? Any clue is better than no clue.

I'll see if this is possible, but I didn't have much luck with gdb on
qemu guests in the past.

Rich.

-- 
Richard Jones, Virtualization Group, Red Hat http://people.redhat.com/~rjones
Read my programming and virtualization blog: http://rwmj.wordpress.com
libguestfs lets you edit virtual machines.  Supports shell scripting,
bindings from many languages.  http://libguestfs.org