lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [day] [month] [year] [list]
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

Powered by Openwall GNU/*/Linux Powered by OpenVZ