Received-SPF: pass (google.com: domain of linux-kernel+bounces-59147-linux.lists.archive=gmail.com@vger.kernel.org designates 2604:1380:4601:e00::3 as permitted sender) client-ip=2604:1380:4601:e00::3;
From: John Ogness <john.ogness@linutronix.de>
To: "John B. Wyatt IV" <jwyatt@redhat.com>
Cc: Petr Mladek <pmladek@suse.com>, Clark Williams <williams@redhat.com>,
 jlelli@redhat.com, Derek Barbosa <debarbos@redhat.com>, "John B. Wyatt IV"
 <sageofredondo@gmail.com>, LKML <linux-kernel@vger.kernel.org>,
 linux-rt-users <linux-rt-users@vger.kernel.org>
Subject: Re: NMI Reported with console_blast.sh
In-Reply-To: <ZcQjxa4UA6hzXHnU@thinkpad2021>
References: <ZcQjxa4UA6hzXHnU@thinkpad2021>
Date: Fri, 09 Feb 2024 10:17:48 +0106
Message-ID: <87v86yc88b.fsf@jogness.linutronix.de>
Precedence: bulk
MIME-Version: 1.0
Content-Type: text/plain

Hi John,

On 2024-02-07, "John B. Wyatt IV" <jwyatt@redhat.com> wrote:
> You asked me to test the upstream kernel with a printk torture
> (console_blash.sh) with the different scheduler settings on a very
> large core system. Wanted to post to the mailing list to show what I
> tested with.

Thanks for your efforts here!

> As far as I can tell; all the scheduler settings correctly get to and
> trip the sysrq trigger to make it crash at the end of the script.
>
> But, with every state, except for fully pre-emeptive, I got an NMI
> call trace before the sysrq trigger that expectedly crashes the
> system.
>
> This is on a Fedora 39 Server installed on a 2x56 core, 224 thread
> machine in Red Hat's lab with the lscpu below with 6.7.0-rt6. I have
> only decoded and attached NoForcedPreemption below. Please ask if you
> want additional ones but they all look similar when I checked.
>
> NMI Call Trace for NoForcedPreemption
> ---
> task:cpuhp/222       state:S stack:0     pid:1349  tgid:1349  ppid:2      flags:0x00004000
> Call Trace:
> <TASK>
> __schedule (kernel/sched/core.c:5396 kernel/sched/core.c:6708) 
> ? try_to_wake_up (./arch/x86/include/asm/preempt.h:104 ./include/linux/preempt.h:484 ./include/linux/preempt.h:484 kernel/sched/core.c:4217) 
> ? __pfx_smpboot_thread_fn (kernel/smpboot.c:107) 
> schedule (kernel/sched/core.c:6784 kernel/sched/core.c:6798) 
> smpboot_thread_fn (kernel/smpboot.c:160) 
> kthread (kernel/kthread.c:388) 
> ? __pfx_kthread (kernel/kthread.c:341) 
> ret_from_fork (arch/x86/kernel/process.c:147) 
> ? __pfx_kthread (kernel/kthread.c:341) 
> ret_from_fork_asm (arch/x86/entry/entry_64.S:250) 
> </TASK>
> sysrq: Trigger a crash
> Kernel panic - not syncing: sysrq triggered crash
> NMI backtrace for cpu 56
> Hardware name: Intel Corporation D50DNP1SBB/D50DNP1SBB, BIOS SE5C7411.86B.9409.D04.2212261349 12/26/2022
> RIP: 0010:io_serial_in (arch/x86/kernel/early_printk.c:100)

I am curious why early_printk is here. Are you using KDB or KGDB?

Could you provide me your kernel config and boot args?

On a side note, it is helpful to use a kernel that prints timing and
caller information:

CONFIG_PRINTK_TIME=y
CONFIG_PRINTK_CALLER=y

Timing information can also be turned on dynamically with the boot arg
"printk.time=1" but the caller information (which is more interesting)
can only be enabled in the kernel build.

John Ogness