[<prev] [next>] [day] [month] [year] [list]
Message-ID: <20191201154749.GP18573@shao2-debian>
Date: Sun, 1 Dec 2019 23:47:49 +0800
From: kernel test robot <rong.a.chen@...el.com>
To: Davidlohr Bueso <dave@...olabs.net>
Cc: Ingo Molnar <mingo@...nel.org>, Davidlohr Bueso <dbueso@...e.de>,
Peter Zijlstra <peterz@...radead.org>,
Linus Torvalds <torvalds@...ux-foundation.org>,
Thomas Gleixner <tglx@...utronix.de>,
LKML <linux-kernel@...r.kernel.org>, lkp@...ts.01.org
Subject: [locking/mutex] a0855d24fc:
WARNING:at_kernel/locking/mutex.c:#mutex_trylock
FYI, we noticed the following commit (built with gcc-7):
commit: a0855d24fc22d49cdc25664fb224caee16998683 ("locking/mutex: Complain upon mutex API misuse in IRQ contexts")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
in testcase: boot
on test machine: qemu-system-i386 -enable-kvm -cpu SandyBridge -smp 2 -m 8G
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+------------------------------------------------------+------------+------------+
| | 751459043c | a0855d24fc |
+------------------------------------------------------+------------+------------+
| boot_successes | 1 | 1 |
| boot_failures | 35 | 35 |
| BUG:workqueue_lockup-pool | 10 | 9 |
| BUG:soft_lockup-CPU##stuck_for#s![dma-fence:#:#] | 24 | 25 |
| EIP:to_kthread | 3 | 2 |
| Kernel_panic-not_syncing:softlockup:hung_tasks | 25 | 26 |
| EIP:thread_signal_callback | 6 | 6 |
| calltrace:do_softirq_own_stack | 7 | 12 |
| EIP:lock_is_held_type | 10 | 10 |
| EIP:debug_lockdep_rcu_enabled | 2 | 5 |
| EIP:arch_local_save_flags | 3 | |
| EIP:kthread_should_stop | 1 | 1 |
| BUG:soft_lockup-CPU##stuck_for#s![rcu_torture_fak:#] | 1 | |
| WARNING:at_kernel/locking/mutex.c:#mutex_trylock | 0 | 26 |
| EIP:mutex_trylock | 0 | 26 |
| WARNING:at_kernel/locking/mutex.c:#mutex_unlock | 0 | 26 |
| EIP:mutex_unlock | 0 | 26 |
| BUG:soft_lockup-CPU##stuck_for#s![swapper:#] | 0 | 1 |
| EIP:rs_modnn | 0 | 1 |
| EIP:rcu_read_lock_held | 0 | 1 |
+------------------------------------------------------+------------+------------+
If you fix the issue, kindly add following tag
Reported-by: kernel test robot <rong.a.chen@...el.com>
[ 576.348903] watchdog: BUG: soft lockup - CPU#0 stuck for 134s! [dma-fence:0:230]
[ 576.348903] Modules linked in:
[ 576.348903] irq event stamp: 280712
[ 576.348903] hardirqs last enabled at (280711): [<dda010fb>] trace_hardirqs_on_thunk+0xc/0x10
[ 576.348903] hardirqs last disabled at (280712): [<dda0110b>] trace_hardirqs_off_thunk+0xc/0x10
[ 576.348903] softirqs last enabled at (526): [<de4568db>] __do_softirq+0x283/0x2b1
[ 576.348903] softirqs last disabled at (519): [<dda05bb1>] do_softirq_own_stack+0x21/0x27
[ 576.348903] CPU: 0 PID: 230 Comm: dma-fence:0 Not tainted 5.4.0-rc2-00042-ga0855d24fc22d #1
[ 576.348903] EIP: to_kthread+0x0/0x1a
[ 576.348903] Code: 43 08 ff d2 83 c3 14 eb e9 5b 5e 5d c3 3e 8d 74 26 00 55 89 e5 ff 70 2c 68 b8 e7 a1 de 68 00 10 00 00 51 e8 d7 65 a0 00 c9 c3 <f6> 40 16 20 75 0d 55 89 e5 0f 0b 8b 80 28 03 00 00 5d c3 8b 80 28
[ 576.348903] EAX: e9c3b380 EBX: ee6abea8 ECX: dec3053c EDX: e9c3b85c
[ 576.348903] ESI: 00000000 EDI: 00000000 EBP: eb3bff4c ESP: eb3bff48
[ 576.348903] DS: 007b ES: 007b FS: 0000 GS: 0000 SS: 0068 EFLAGS: 00000246
[ 576.348903] CR0: 80050033 CR2: 00000000 CR3: 1eea9000 CR4: 000406b0
[ 576.348903] Call Trace:
[ 576.348903] ? kthread_should_stop+0x12/0x1b
[ 576.348903] thread_signal_callback+0x122/0x243
[ 576.348903] kthread+0xdc/0xde
[ 576.348903] ? test_signaling+0x7b/0x7b
[ 576.348903] ? kthread_create_worker_on_cpu+0x1c/0x1c
[ 576.348903] ret_from_fork+0x19/0x24
[ 576.348903] Kernel panic - not syncing: softlockup: hung tasks
[ 576.348903] CPU: 0 PID: 230 Comm: dma-fence:0 Tainted: G L 5.4.0-rc2-00042-ga0855d24fc22d #1
[ 576.348903] Call Trace:
[ 576.348903] <IRQ>
[ 576.348903] dump_stack+0x16/0x18
[ 576.348903] panic+0xaa/0x259
[ 576.348903] watchdog_timer_fn+0x1ec/0x211
[ 576.348903] ? __touch_watchdog+0x1a/0x1a
[ 576.348903] __hrtimer_run_queues+0x165/0x256
[ 576.348903] ? __touch_watchdog+0x1a/0x1a
[ 576.348903] hrtimer_run_queues+0xc4/0xd9
[ 576.348903] run_local_timers+0xd/0x26
[ 576.348903] update_process_times+0x1c/0x3c
[ 576.348903] tick_periodic+0x99/0x9b
[ 576.348903] tick_handle_periodic+0x18/0x54
[ 576.348903] timer_interrupt+0x12/0x19
[ 576.348903] __handle_irq_event_percpu+0xa7/0x1ac
[ 576.348903] handle_irq_event_percpu+0x1c/0x42
[ 576.348903] handle_irq_event+0x2e/0x47
[ 576.348903] ? irq_set_chained_handler_and_data+0x4f/0x4f
[ 576.348903] handle_level_irq+0x57/0x83
[ 576.348903] handle_irq+0x3a/0x45
[ 576.348903] </IRQ>
[ 576.348903] do_IRQ+0x6a/0x8f
[ 576.348903] common_interrupt+0xfd/0x104
[ 576.348903] EIP: to_kthread+0x0/0x1a
[ 576.348903] Code: 43 08 ff d2 83 c3 14 eb e9 5b 5e 5d c3 3e 8d 74 26 00 55 89 e5 ff 70 2c 68 b8 e7 a1 de 68 00 10 00 00 51 e8 d7 65 a0 00 c9 c3 <f6> 40 16 20 75 0d 55 89 e5 0f 0b 8b 80 28 03 00 00 5d c3 8b 80 28
[ 576.348903] EAX: e9c3b380 EBX: ee6abea8 ECX: dec3053c EDX: e9c3b85c
[ 576.348903] ESI: 00000000 EDI: 00000000 EBP: eb3bff4c ESP: eb3bff48
[ 576.348903] DS: 007b ES: 007b FS: 0000 GS: 0000 SS: 0068 EFLAGS: 00000246
[ 576.348903] ? __modver_version_show+0x1d/0x1d
[ 576.348903] ? kthread_should_stop+0x12/0x1b
[ 576.348903] thread_signal_callback+0x122/0x243
[ 576.348903] kthread+0xdc/0xde
[ 576.348903] ? test_signaling+0x7b/0x7b
[ 576.348903] ? kthread_create_worker_on_cpu+0x1c/0x1c
[ 576.348903] ret_from_fork+0x19/0x24
[ 576.348903] ------------[ cut here ]------------
[ 576.348903] WARNING: CPU: 0 PID: 230 at kernel/locking/mutex.c:1419 mutex_trylock+0x4b/0x81
[ 576.348903] Modules linked in:
[ 576.348903] CPU: 0 PID: 230 Comm: dma-fence:0 Tainted: G L 5.4.0-rc2-00042-ga0855d24fc22d #1
[ 576.348903] EIP: mutex_trylock+0x4b/0x81
[ 576.348903] Code: 74 1c 83 3d 08 5f d7 de 00 75 13 68 68 53 8f de 68 97 76 8e de e8 fe af 5d ff 0f 0b 58 5a a1 d4 af ad de a9 00 ff 1f 00 74 02 <0f> 0b 89 d8 e8 d0 28 60 ff 84 c0 89 c6 74 1b ff 75 04 8d 43 38 6a
[ 576.348903] EAX: 00010002 EBX: dec36e60 ECX: 00000000 EDX: e9c3b380
[ 576.348903] ESI: 00000000 EDI: ee659ec8 EBP: ee659e7c ESP: ee659e74
[ 576.348903] DS: 007b ES: 007b FS: 0000 GS: 0000 SS: 0068 EFLAGS: 00010006
[ 576.348903] CR0: 80050033 CR2: 00000000 CR3: 1eea9000 CR4: 000406b0
[ 576.348903] Call Trace:
[ 576.348903] <IRQ>
[ 576.348903] __crash_kexec+0x26/0xa8
[ 576.348903] panic+0xba/0x259
[ 576.348903] watchdog_timer_fn+0x1ec/0x211
[ 576.348903] ? __touch_watchdog+0x1a/0x1a
[ 576.348903] __hrtimer_run_queues+0x165/0x256
[ 576.348903] ? __touch_watchdog+0x1a/0x1a
[ 576.348903] hrtimer_run_queues+0xc4/0xd9
[ 576.348903] run_local_timers+0xd/0x26
[ 576.348903] update_process_times+0x1c/0x3c
[ 576.348903] tick_periodic+0x99/0x9b
[ 576.348903] tick_handle_periodic+0x18/0x54
[ 576.348903] timer_interrupt+0x12/0x19
[ 576.348903] __handle_irq_event_percpu+0xa7/0x1ac
[ 576.348903] handle_irq_event_percpu+0x1c/0x42
[ 576.348903] handle_irq_event+0x2e/0x47
[ 576.348903] ? irq_set_chained_handler_and_data+0x4f/0x4f
[ 576.348903] handle_level_irq+0x57/0x83
[ 576.348903] handle_irq+0x3a/0x45
[ 576.348903] </IRQ>
[ 576.348903] do_IRQ+0x6a/0x8f
[ 576.348903] common_interrupt+0xfd/0x104
[ 576.348903] EIP: to_kthread+0x0/0x1a
[ 576.348903] Code: 43 08 ff d2 83 c3 14 eb e9 5b 5e 5d c3 3e 8d 74 26 00 55 89 e5 ff 70 2c 68 b8 e7 a1 de 68 00 10 00 00 51 e8 d7 65 a0 00 c9 c3 <f6> 40 16 20 75 0d 55 89 e5 0f 0b 8b 80 28 03 00 00 5d c3 8b 80 28
[ 576.348903] EAX: e9c3b380 EBX: ee6abea8 ECX: dec3053c EDX: e9c3b85c
[ 576.348903] ESI: 00000000 EDI: 00000000 EBP: eb3bff4c ESP: eb3bff48
[ 576.348903] DS: 007b ES: 007b FS: 0000 GS: 0000 SS: 0068 EFLAGS: 00000246
[ 576.348903] ? __modver_version_show+0x1d/0x1d
[ 576.348903] ? kthread_should_stop+0x12/0x1b
[ 576.348903] thread_signal_callback+0x122/0x243
[ 576.348903] kthread+0xdc/0xde
[ 576.348903] ? test_signaling+0x7b/0x7b
[ 576.348903] ? kthread_create_worker_on_cpu+0x1c/0x1c
[ 576.348903] ret_from_fork+0x19/0x24
[ 576.348903] irq event stamp: 280712
[ 576.348903] hardirqs last enabled at (280711): [<dda010fb>] trace_hardirqs_on_thunk+0xc/0x10
[ 576.348903] hardirqs last disabled at (280712): [<dda0110b>] trace_hardirqs_off_thunk+0xc/0x10
[ 576.348903] softirqs last enabled at (526): [<de4568db>] __do_softirq+0x283/0x2b1
[ 576.348903] softirqs last disabled at (519): [<dda05bb1>] do_softirq_own_stack+0x21/0x27
[ 576.348903] ---[ end trace a5329ee86dc626c2 ]---
To reproduce:
# build kernel
cd linux
cp config-5.4.0-rc2-00042-ga0855d24fc22d .config
make HOSTCC=gcc-7 CC=gcc-7 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
Thanks,
Rong Chen
View attachment "config-5.4.0-rc2-00042-ga0855d24fc22d" of type "text/plain" (126946 bytes)
View attachment "job-script" of type "text/plain" (4793 bytes)
Download attachment "dmesg.xz" of type "application/x-xz" (14496 bytes)
Powered by blists - more mailing lists