Greeting,
FYI, we noticed the following commit (built with gcc-9):
commit: c5c50fbea9049a89c51845ccaf2025fbf4d9be7b ("sched/fair: Prevent dead task
groups from regaining cfs_rq's")
url:
https://github.com/0day-ci/linux/commits/UPDATE-20211104-030717/Michal-Ko...
in testcase: boot
on test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+--------------------------------------------------------------------------------+------------+------------+
| |
7413431c62 | c5c50fbea9 |
+--------------------------------------------------------------------------------+------------+------------+
| boot_successes | 49
| 0 |
| WARNING:at_lib/debugobjects.c:#__debug_object_init | 0
| 55 |
| EIP:__debug_object_init | 0
| 55 |
| BUG:sleeping_function_called_from_invalid_context_at_kernel/sched/completion.c | 0
| 59 |
| BUG:scheduling_while_atomic | 0
| 59 |
| BUG:unable_to_handle_page_fault_for_address | 0
| 15 |
| Oops:#[##] | 0
| 36 |
| Kernel_panic-not_syncing:Fatal_exception_in_interrupt | 0
| 36 |
| WARNING:at_kernel/softirq.c:#__local_bh_disable_ip | 0
| 31 |
| EIP:__local_bh_disable_ip | 0
| 31 |
| EIP:default_idle | 0
| 10 |
| kernel/rcu/tree.c:#Illegal_synchronize_rcu()in_RCU_read-side_critical_section | 0
| 17 |
| WARNING:at_kernel/rcu/tree_plugin.h:#rcu_note_context_switch | 0
| 16 |
| EIP:rcu_note_context_switch | 0
| 16 |
| INFO:rcu_preempt_detected_stalls_on_CPUs/tasks | 0
| 11 |
| INFO:task_blocked_for_more_than#seconds | 0
| 15 |
| BUG:kernel_hang_in_test_stage | 0
| 14 |
| BUG:kernel_NULL_pointer_dereference,address | 0
| 21 |
+--------------------------------------------------------------------------------+------------+------------+
If you fix the issue, kindly add following tag
Reported-by: kernel test robot <oliver.sang(a)intel.com>
[ 51.124861][ C0] BUG: sleeping function called from invalid context at
kernel/sched/completion.c:101
[ 51.126085][ C0] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 14, name:
ksoftirqd/0
[ 51.127064][ C0] preempt_count: 100, expected: 0
[ 51.127500][ C0] RCU nest depth: 0, expected: 0
[ 51.127936][ C0] 1 lock held by ksoftirqd/0/14:
[ 51.128405][ C0] #0: c2078cfc (rcu_callback){....}-{0:0}, at: rcu_lock_acquire
(include/linux/rcupdate.h:266)
[ 51.129325][ C0] Preemption disabled at:
[ 51.129329][ C0] __do_softirq (kernel/softirq.c:491 kernel/softirq.c:535)
[ 51.130465][ C0] CPU: 0 PID: 14 Comm: ksoftirqd/0 Not tainted
5.15.0-rc5-00188-gc5c50fbea904 #1
[ 51.131440][ C0] Call Trace:
[ 51.131788][ C0] dump_stack_lvl (lib/dump_stack.c:107 (discriminator 4))
[ 51.132271][ C0] dump_stack (lib/dump_stack.c:114)
[ 51.132703][ C0] __might_resched (kernel/sched/core.c:9519)
[ 51.133202][ C0] ? __do_softirq (kernel/softirq.c:491 kernel/softirq.c:535)
[ 51.133687][ C0] __might_sleep (kernel/sched/core.c:9448 (discriminator 14))
[ 51.134172][ C0] __wait_for_common (include/linux/kernel.h:104
kernel/sched/completion.c:101)
[ 51.134655][ C0] ? usleep_range (kernel/time/timer.c:1843)
[ 51.135094][ C0] ? trace_hardirqs_on (kernel/trace/trace_preemptirq.c:51 (discriminator
22))
[ 51.135581][ C0] wait_for_completion (kernel/sched/completion.c:139)
[ 51.136054][ C0] __wait_rcu_gp (kernel/rcu/update.c:404)
[ 51.136477][ C0] synchronize_rcu (kernel/rcu/tree.c:3748)
[ 51.136924][ C0] ? __call_rcu (kernel/rcu/tree.c:3066)
[ 51.137347][ C0] ? rcu_tasks_pregp_step (kernel/rcu/update.c:363)
[ 51.137834][ C0] sched_offline_group (kernel/sched/core.c:9775)
[ 51.138342][ C0] autogroup_destroy (kernel/sched/autogroup.c:35)
[ 51.138778][ C0] kref_put (include/linux/kref.h:64)
[ 51.139243][ C0] sched_autogroup_exit (kernel/sched/autogroup.c:196)
[ 51.139796][ C0] free_signal_struct (kernel/fork.c:732)
[ 51.140324][ C0] __put_task_struct (kernel/fork.c:757)
[ 51.140879][ C0] put_task_struct (include/linux/sched/task.h:115)
[ 51.141370][ C0] delayed_put_task_struct (kernel/exit.c:176)
[ 51.141943][ C0] rcu_do_batch (include/linux/rcupdate.h:272 kernel/rcu/tree.c:2510)
[ 51.142435][ C0] rcu_core (kernel/rcu/tree.c:2747)
[ 51.142857][ C0] rcu_core_si (kernel/rcu/tree.c:2757)
[ 51.143262][ C0] __do_softirq (arch/x86/include/asm/atomic.h:29
include/linux/atomic/atomic-instrumented.h:28 include/linux/jump_label.h:266
include/linux/jump_label.h:276 include/trace/events/irq.h:142 kernel/softirq.c:559)
[ 51.143786][ C0] run_ksoftirqd (kernel/softirq.c:412 kernel/softirq.c:921)
[ 51.144263][ C0] smpboot_thread_fn (kernel/smpboot.c:164 (discriminator 3))
[ 51.144792][ C0] kthread (kernel/kthread.c:329)
[ 51.145187][ C0] ? smpboot_register_percpu_thread (kernel/smpboot.c:107)
[ 51.145820][ C0] ? set_kthread_struct (kernel/kthread.c:272)
[ 51.146429][ C0] ret_from_fork (arch/x86/entry/entry_32.S:775)
[ 51.146993][ C0] BUG: scheduling while atomic: ksoftirqd/0/14/0x00000101
[ 51.147709][ C0] 1 lock held by ksoftirqd/0/14:
[ 51.148193][ C0] #0: c2078cfc (rcu_callback){....}-{0:0}, at: rcu_lock_acquire
(include/linux/rcupdate.h:266)
[ 51.149019][ C0] Modules linked in: serio_raw floppy
[ 51.149523][ C0] Preemption disabled at:
[ 51.149526][ C0] __do_softirq (kernel/softirq.c:491 kernel/softirq.c:535)
[ 51.150518][ C0] CPU: 0 PID: 14 Comm: ksoftirqd/0 Tainted: G W
5.15.0-rc5-00188-gc5c50fbea904 #1
[ 51.151640][ C0] Call Trace:
[ 51.151965][ C0] dump_stack_lvl (lib/dump_stack.c:107 (discriminator 4))
[ 51.152441][ C0] dump_stack (lib/dump_stack.c:114)
[ 51.152840][ C0] __schedule_bug (kernel/sched/core.c:5494)
[ 51.153288][ C0] __schedule (arch/x86/include/asm/preempt.h:35 kernel/sched/core.c:5521
kernel/sched/core.c:6122)
[ 51.153712][ C0] ? kvm_clock_read (arch/x86/include/asm/preempt.h:95
arch/x86/kernel/kvmclock.c:80)
[ 51.154208][ C0] ? sched_clock (arch/x86/kernel/tsc.c:254)
[ 51.154645][ C0] schedule (kernel/sched/core.c:6305 (discriminator 1))
[ 51.155071][ C0] schedule_timeout (kernel/time/timer.c:1858)
[ 51.155542][ C0] ? _raw_spin_unlock_irq (arch/x86/include/asm/irqflags.h:45
arch/x86/include/asm/irqflags.h:80 include/linux/spinlock_api_smp.h:168
kernel/locking/spinlock.c:202)
[ 51.156065][ C0] ? __this_cpu_preempt_check (lib/smp_processor_id.c:67)
[ 51.156599][ C0] ? lockdep_hardirqs_on (kernel/locking/lockdep.c:4344)
[ 51.157093][ C0] ? trace_hardirqs_on (kernel/trace/trace_preemptirq.c:51 (discriminator
22))
[ 51.157566][ C0] __wait_for_common (kernel/sched/completion.c:85
kernel/sched/completion.c:106)
[ 51.158031][ C0] ? usleep_range (kernel/time/timer.c:1843)
[ 51.158488][ C0] wait_for_completion (kernel/sched/completion.c:139)
[ 51.158961][ C0] __wait_rcu_gp (kernel/rcu/update.c:404)
[ 51.159397][ C0] synchronize_rcu (kernel/rcu/tree.c:3748)
[ 51.159853][ C0] ? __call_rcu (kernel/rcu/tree.c:3066)
[ 51.160294][ C0] ? rcu_tasks_pregp_step (kernel/rcu/update.c:363)
[ 51.160818][ C0] ? __wait_for_common (kernel/sched/completion.c:74
kernel/sched/completion.c:106)
[ 51.161324][ C0] sched_offline_group (kernel/sched/core.c:9775)
[ 51.161811][ C0] autogroup_destroy (kernel/sched/autogroup.c:35)
[ 51.162305][ C0] kref_put (include/linux/kref.h:64)
[ 51.162825][ C0] sched_autogroup_exit (kernel/sched/autogroup.c:196)
[ 51.163314][ C0] free_signal_struct (kernel/fork.c:732)
[ 51.163814][ C0] __put_task_struct (kernel/fork.c:757)
[ 51.164294][ C0] put_task_struct (include/linux/sched/task.h:115)
[ 51.164780][ C0] delayed_put_task_struct (kernel/exit.c:176)
[ 51.165305][ C0] rcu_do_batch (include/linux/rcupdate.h:272 kernel/rcu/tree.c:2510)
[ 51.165764][ C0] rcu_core (kernel/rcu/tree.c:2747)
[ 51.166226][ C0] rcu_core_si (kernel/rcu/tree.c:2757)
[ 51.166629][ C0] __do_softirq (arch/x86/include/asm/atomic.h:29
include/linux/atomic/atomic-instrumented.h:28 include/linux/jump_label.h:266
include/linux/jump_label.h:276 include/trace/events/irq.h:142 kernel/softirq.c:559)
[ 51.167093][ C0] run_ksoftirqd (kernel/softirq.c:412 kernel/softirq.c:921)
[ 51.167580][ C0] smpboot_thread_fn (kernel/smpboot.c:164 (discriminator 3))
[ 51.168087][ C0] kthread (kernel/kthread.c:329)
[ 51.168483][ C0] ? smpboot_register_percpu_thread (kernel/smpboot.c:107)
[ 51.169056][ C0] ? set_kthread_struct (kernel/kthread.c:272)
[ 51.169531][ C0] ret_from_fork (arch/x86/entry/entry_32.S:775)
[ 51.180917][ T14] softirq: huh, entered softirq 9 RCU (ptrval) with preempt_count
00000100, exited with 00000000?
[ 51.182068][ C0] BUG: scheduling while atomic: ksoftirqd/0/14/0x00000101
[ 51.182831][ C0] 1 lock held by ksoftirqd/0/14:
[ 51.183329][ C0] #0: c2078cfc (rcu_callback){....}-{0:0}, at: rcu_lock_acquire
(include/linux/rcupdate.h:266)
[ 51.184027][ C0] Modules linked in: serio_raw floppy
[ 51.184541][ C0] Preemption disabled at:
[ 51.184546][ C0] __do_softirq (kernel/softirq.c:491 kernel/softirq.c:535)
[ 51.185291][ C0] CPU: 0 PID: 14 Comm: ksoftirqd/0 Tainted: G W
5.15.0-rc5-00188-gc5c50fbea904 #1
[ 51.186353][ C0] Call Trace:
[ 51.186705][ C0] dump_stack_lvl (lib/dump_stack.c:107 (discriminator 4))
[ 51.187145][ C0] dump_stack (lib/dump_stack.c:114)
[ 51.187408][ C0] __schedule_bug (kernel/sched/core.c:5494)
[ 51.187704][ C0] __schedule (arch/x86/include/asm/preempt.h:35 kernel/sched/core.c:5521
kernel/sched/core.c:6122)
[ 51.188165][ C0] ? kvm_clock_read (arch/x86/include/asm/preempt.h:95
arch/x86/kernel/kvmclock.c:80)
[ 51.188484][ C0] ? sched_clock (arch/x86/kernel/tsc.c:254)
[ 51.188805][ C0] schedule (kernel/sched/core.c:6305 (discriminator 1))
[ 51.189117][ C0] schedule_timeout (kernel/time/timer.c:1858)
[ 51.189498][ C0] ? _raw_spin_unlock_irq (arch/x86/include/asm/irqflags.h:45
arch/x86/include/asm/irqflags.h:80 include/linux/spinlock_api_smp.h:168
kernel/locking/spinlock.c:202)
[ 51.189846][ C0] ? __this_cpu_preempt_check (lib/smp_processor_id.c:67)
[ 51.194434][ C0] ? lockdep_hardirqs_on (kernel/locking/lockdep.c:4344)
[ 51.194990][ C0] ? trace_hardirqs_on (kernel/trace/trace_preemptirq.c:51 (discriminator
22))
[ 51.195408][ C0] __wait_for_common (kernel/sched/completion.c:85
kernel/sched/completion.c:106)
[ 51.195887][ C0] ? usleep_range (kernel/time/timer.c:1843)
[ 51.196336][ C0] wait_for_completion (kernel/sched/completion.c:139)
[ 51.196829][ C0] __wait_rcu_gp (kernel/rcu/update.c:404)
[ 51.197204][ C0] synchronize_rcu (kernel/rcu/tree.c:3748)
[ 51.197506][ C0] ? __call_rcu (kernel/rcu/tree.c:3066)
[ 51.197811][ C0] ? rcu_tasks_pregp_step (kernel/rcu/update.c:363)
[ 51.198295][ C0] ? __wait_for_common (kernel/sched/completion.c:74
kernel/sched/completion.c:106)
[ 51.198654][ C0] sched_offline_group (kernel/sched/core.c:9775)
[ 51.199016][ C0] autogroup_destroy (kernel/sched/autogroup.c:35)
[ 51.199399][ C0] kref_put (include/linux/kref.h:64)
[ 51.199837][ C0] sched_autogroup_exit (kernel/sched/autogroup.c:196)
[ 51.200206][ C0] free_signal_struct (kernel/fork.c:732)
[ 51.200622][ C0] __put_task_struct (kernel/fork.c:757)
[ 51.200979][ C0] put_task_struct (include/linux/sched/task.h:115)
[ 51.201272][ C0] delayed_put_task_struct (kernel/exit.c:176)
[ 51.201707][ C0] rcu_do_batch (include/linux/rcupdate.h:272 kernel/rcu/tree.c:2510)
[ 51.202071][ C0] rcu_core (kernel/rcu/tree.c:2747)
[ 51.202425][ C0] rcu_core_si (kernel/rcu/tree.c:2757)
[ 51.202797][ C0] __do_softirq (arch/x86/include/asm/atomic.h:29
include/linux/atomic/atomic-instrumented.h:28 include/linux/jump_label.h:266
include/linux/jump_label.h:276 include/trace/events/irq.h:142 kernel/softirq.c:559)
[ 51.203098][ C0] run_ksoftirqd (kernel/softirq.c:412 kernel/softirq.c:921)
[ 51.203378][ C0] smpboot_thread_fn (kernel/smpboot.c:164 (discriminator 3))
[ 51.203696][ C0] kthread (kernel/kthread.c:329)
[ 51.203975][ C0] ? smpboot_register_percpu_thread (kernel/smpboot.c:107)
[ 51.204359][ C0] ? set_kthread_struct (kernel/kthread.c:272)
[ 51.204735][ C0] ret_from_fork (arch/x86/entry/entry_32.S:775)
[ 51.205144][ T0] NOHZ tick-stop error: Non-RCU local softirq work is pending,
handler #282!!!
[ 51.208267][ T0] NOHZ tick-stop error: Non-RCU local softirq work is pending,
handler #282!!!
[ 51.224179][ C0] ------------[ cut here ]------------
[ 51.224184][ C0] WARNING: CPU: 0 PID: 14 at kernel/softirq.c:308 __local_bh_disable_ip
(kernel/softirq.c:308 (discriminator 1))
[ 51.224196][ C0] Modules linked in: serio_raw floppy
[ 51.224202][ C0] CPU: 0 PID: 14 Comm: ksoftirqd/0 Tainted: G W
5.15.0-rc5-00188-gc5c50fbea904 #1
[ 51.224206][ C0] EIP: __local_bh_disable_ip (kernel/softirq.c:308 (discriminator 1))
[ 51.224211][ C0] Code: 64 ff 0d 54 48 28 c2 75 0a 55 89 e5 e8 20 f6 84 00 5d c3 c3 55 89
e5 56 53 89 d3 64 8b 15 54 48 28 c2 81 e2 00 00 0f 00 74 02 <0f> 0b 9c 5e fa 64 01
1d 54 48 28 c2 64 8b 15 54 48 28 c2 31 da 80
All code
========
0: 64 ff 0d 54 48 28 c2 decl %fs:-0x3dd7b7ac(%rip) # 0xffffffffc228485b
7: 75 0a jne 0x13
9: 55 push %rbp
a: 89 e5 mov %esp,%ebp
c: e8 20 f6 84 00 callq 0x84f631
11: 5d pop %rbp
12: c3 retq
13: c3 retq
14: 55 push %rbp
15: 89 e5 mov %esp,%ebp
17: 56 push %rsi
18: 53 push %rbx
19: 89 d3 mov %edx,%ebx
1b: 64 8b 15 54 48 28 c2 mov %fs:-0x3dd7b7ac(%rip),%edx # 0xffffffffc2284876
22: 81 e2 00 00 0f 00 and $0xf0000,%edx
28: 74 02 je 0x2c
2a:* 0f 0b ud2 <-- trapping instruction
2c: 9c pushfq
2d: 5e pop %rsi
2e: fa cli
2f: 64 01 1d 54 48 28 c2 add %ebx,%fs:-0x3dd7b7ac(%rip) # 0xffffffffc228488a
36: 64 8b 15 54 48 28 c2 mov %fs:-0x3dd7b7ac(%rip),%edx # 0xffffffffc2284891
3d: 31 da xor %ebx,%edx
3f: 80 .byte 0x80
Code starting with the faulting instruction
===========================================
0: 0f 0b ud2
2: 9c pushfq
3: 5e pop %rsi
4: fa cli
5: 64 01 1d 54 48 28 c2 add %ebx,%fs:-0x3dd7b7ac(%rip) # 0xffffffffc2284860
c: 64 8b 15 54 48 28 c2 mov %fs:-0x3dd7b7ac(%rip),%edx # 0xffffffffc2284867
13: 31 da xor %ebx,%edx
15: 80 .byte 0x80
[ 51.224214][ C0] EAX: c10c59f5 EBX: 00000200 ECX: 7ffffe00 EDX: 000f0000
[ 51.224216][ C0] ESI: f5e41070 EDI: 00000005 EBP: c30d1ec0 ESP: c30d1eb8
[ 51.224218][ C0] DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068 EFLAGS: 00010206
[ 51.224223][ C0] CR0: 80050033 CR2: 0056fd78 CR3: 023d5000 CR4: 000406d0
[ 51.224225][ C0] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
[ 51.224226][ C0] DR6: fffe0ff0 DR7: 00000400
[ 51.224228][ C0] Call Trace:
[ 51.224231][ C0] rcu_do_batch (kernel/rcu/tree.c:2497)
[ 51.224242][ C0] rcu_core (kernel/rcu/tree.c:2747)
[ 51.224247][ C0] rcu_core_si (kernel/rcu/tree.c:2757)
[ 51.224250][ C0] __do_softirq (arch/x86/include/asm/atomic.h:29
include/linux/atomic/atomic-instrumented.h:28 include/linux/jump_label.h:266
include/linux/jump_label.h:276 include/trace/events/irq.h:142 kernel/softirq.c:559)
[ 51.224258][ C0] run_ksoftirqd (kernel/softirq.c:412 kernel/softirq.c:921)
[ 51.224262][ C0] smpboot_thread_fn (kernel/smpboot.c:164 (discriminator 3))
[ 51.224268][ C0] kthread (kernel/kthread.c:329)
[ 51.224274][ C0] ? smpboot_register_percpu_thread (kernel/smpboot.c:107)
[ 51.224277][ C0] ? set_kthread_struct (kernel/kthread.c:272)
[ 51.224281][ C0] ret_from_fork (arch/x86/entry/entry_32.S:775)
[ 51.224292][ C0] irq event stamp: 33620
[ 51.224293][ C0] hardirqs last enabled at (33622): vprintk_store
(arch/x86/include/asm/irqflags.h:29 (discriminator 3) arch/x86/include/asm/irqflags.h:70
(discriminator 3) arch/x86/include/asm/irqflags.h:132 (discriminator 3)
kernel/printk/printk.c:2205 (discriminator 3))
[ 51.224298][ C0] hardirqs last disabled at (33623): vprintk_store
(arch/x86/include/asm/preempt.h:27 (discriminator 3) kernel/printk/printk.c:1961
(discriminator 3) kernel/printk/printk.c:2124 (discriminator 3))
[ 51.224301][ C0] softirqs last enabled at (33390): __do_softirq
(arch/x86/include/asm/preempt.h:27 kernel/softirq.c:402 kernel/softirq.c:587)
hwclock: can't o[ 51.224303][ C0] softirqs last disabled at (33393): run_ksoftirqd
(kernel/softirq.c:412 kernel/softirq.c:921)
pen '/dev/misc/r[ 51.224307][ C0] ---[ end trace 6182f73633fd09b3 ]---
tc': No such fil[ 51.224336][ T14] softirq: huh, entered softirq 9 RCU (ptrval)
with preempt_count 00000100, exited with 00000000?
/lkp/lkp/src/bin/lkp-setup-rootfs: line 78: can't create
/sys/devices/system/cpu/microcode/reload: nonexistent directory
To reproduce:
# build kernel
cd linux
cp config-5.15.0-rc5-00188-gc5c50fbea904 .config
make HOSTCC=gcc-9 CC=gcc-9 ARCH=i386 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
# if come across any failure that blocks the test,
# please remove ~/.lkp and /lkp dir to run from a clean state.
---
0DAY/LKP+ Test Infrastructure Open Source Technology Center
https://lists.01.org/hyperkitty/list/lkp@lists.01.org Intel Corporation
Thanks,
Oliver Sang