3 a.m.
Greeting,
FYI, we noticed the following commit (built with gcc-9):
commit: 698d74a93f2e1047141df80bcdaa215f69555c6b ("printk: add pr_flush()")
https://git.kernel.org/cgit/linux/kernel/git/rt/linux-rt-devel.git linux-5.10.y-rt-rebase
in testcase: boot
on test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 8G
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+--------------------------------------------------------------+------------+------------+
| | 232e3aeb81 | 698d74a93f
|
+--------------------------------------------------------------+------------+------------+
| boot_successes | 4 | 2
|
| boot_failures | 0 | 6
|
| WARNING:at_kernel/rcu/tree_plugin.h:#rcu_note_context_switch | 0 | 6
|
| RIP:rcu_note_context_switch | 0 | 6
|
+--------------------------------------------------------------+------------+------------+
If you fix the issue, kindly add following tag
Reported-by: kernel test robot <oliver.sang(a)intel.com>
[ 58.773663] WARNING: CPU: 0 PID: 126 at kernel/rcu/tree_plugin.h:297
rcu_note_context_switch+0x82/0x600
[ 58.775771] Modules linked in: sr_mod cdrom ppdev joydev ata_generic parport_pc floppy
pata_acpi parport bochs_drm drm_vram_helper drm_ttm_helper ttm ata_piix libata i2c_piix4
[ 58.779412] CPU: 0 PID: 126 Comm: lkp-setup-rootf Not tainted
5.10.1-00101-g698d74a93f2e #1
[ 58.781308] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1
04/01/2014
[ 58.783233] RIP: 0010:rcu_note_context_switch+0x82/0x600
[ 58.784509] Code: f6 74 0f 65 8b 05 9e 2a 23 6c 85 c0 0f 84 3b 01 00 00 45 84 e4 75 15
65 48 8b 04 25 00 7f 01 00 8b 88 9c 07 00 00 85 c9 7e 02 <0f> 0b 65 48 8b 04 25 00
7f 01 00 8b 90 9c 07 00 00 85 d2 7e 0e 41
[ 58.789021] RSP: 0018:ffffad130073bc30 EFLAGS: 00010002
[ 58.790214] RAX: ffff8d6f17218000 RBX: ffff8d6fb7c2a780 RCX: 0000000000000001
[ 58.792037] RDX: 0000000000000000 RSI: 0000000000000001 RDI: ffffffff951d3177
[ 58.793706] RBP: ffffad130073bcc8 R08: 0000000000000001 R09: 0000000000000001
[ 58.795437] R10: ffffffff972b15e0 R11: 0000000000000001 R12: 0000000000000000
[ 58.797082] R13: ffff8d6f17218000 R14: 0000000000000000 R15: ffff8d6fb7c29958
[ 58.798684] FS: 00007fc12c59e700(0000) GS:ffff8d6fb7c00000(0000)
knlGS:0000000000000000
[ 58.804602] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 58.805881] CR2: 00007fc12bf502f0 CR3: 00000001ac284000 CR4: 00000000000406f0
[ 58.807306] Call Trace:
[ 58.807986] __schedule+0xe0/0xb60
[ 58.808854] ? mark_held_locks+0x49/0x80
[ 58.809853] schedule+0x4e/0x100
[ 58.810661] schedule_timeout+0x1c3/0x3a0
[ 58.811626] ? __next_timer_interrupt+0x100/0x100
[ 58.812692] ? msleep+0x25/0x60
[ 58.813408] msleep+0x39/0x60
[ 58.814111] pr_flush+0x13b/0x160
[ 58.814932] kmsg_dump+0x75/0x200
[ 58.815982] ? wake_up_klogd+0x4f/0x80
[ 58.817015] ? vprintk_emit+0x38/0x60
[ 58.817912] ? printk+0x62/0x79
[ 58.818656] ? emergency_restart+0xf/0x20
[ 58.819533] emergency_restart+0xf/0x20
[ 58.820468] __handle_sysrq.cold+0x51/0x138
[ 58.821514] write_sysrq_trigger+0x3f/0x60
[ 58.822546] proc_reg_write+0x53/0x80
[ 58.823724] vfs_write+0xee/0x3c0
[ 58.824544] ksys_write+0x68/0xe0
[ 58.825370] do_syscall_64+0x33/0x40
[ 58.826278] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[ 58.827565] RIP: 0033:0x7fc12bc7e100
[ 58.828505] Code: 73 01 c3 48 8b 0d 40 0d 2d 00 31 d2 48 29 c2 64 89 11 48 83 c8 ff eb
ea 90 90 83 3d dd 70 2d 00 00 75 10 b8 01 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 31
c3 48 83 ec 08 e8 de b0 01 00 48 89 04 24
[ 58.833215] RSP: 002b:00007fff429087a8 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
[ 58.835302] RAX: ffffffffffffffda RBX: 0000000000000002 RCX: 00007fc12bc7e100
[ 58.837209] RDX: 0000000000000002 RSI: 0000000001093808 RDI: 0000000000000001
[ 58.839443] RBP: 0000000001093808 R08: 000000000000000a R09: 00007fc12c59e700
[ 58.841536] R10: 00007fff42908618 R11: 0000000000000246 R12: 00007fc12bf50260
[ 58.843121] R13: 0000000000000002 R14: 0000000000000000 R15: 00000000011234c8
[ 58.844886] irq event stamp: 43466
[ 58.845746] hardirqs last enabled at (43465): [<ffffffff9498176f>]
_raw_spin_unlock_irqrestore+0x4f/0x60
[ 58.847866] hardirqs last disabled at (43466): [<ffffffff9497a148>]
__schedule+0x6e8/0xb60
[ 58.849630] softirqs last enabled at (43388): [<ffffffff94c0034e>]
__do_softirq+0x34e/0x49c
[ 58.851457] softirqs last disabled at (43379): [<ffffffff94a010f2>]
asm_call_irq_on_stack+0x12/0x20
[ 58.853970] ---[ end trace 240f55e0d36d2f4e ]---
To reproduce:
# build kernel
cd linux
cp config-5.10.1-00101-g698d74a93f2e .config
make HOSTCC=gcc-9 CC=gcc-9 ARCH=x86_64 olddefconfig prepare modules_prepare bzImage
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email
Thanks,
Oliver Sang