Re: [PATCH] locking/ww_mutex: Adjust to lockdep nest_lock requirements

[kernel test robot <oliver.sang@intel.com>]

Hello,

kernel test robot noticed "WARNING:at_kernel/locking/lockdep.c:#__lock_acquire" on:

commit: 4f37585fa02f3eaebc72efa1260e6742478c00fa ("[PATCH] locking/ww_mutex: Adjust to lockdep nest_lock requirements")
url: https://github.com/intel-lab-lkp/linux/commits/Thomas-Hellstr-m/locking-ww_mutex-Adjust-to-lockdep-nest_lock-requirements/20231220-000906
base: https://git.kernel.org/cgit/linux/kernel/git/tip/tip.git a51749ab34d9e5dec548fe38ede7e01e8bb26454
patch link: https://lore.kernel.org/all/20231219160524.3646-1-thomas.hellstrom@linux.intel.com/
patch subject: [PATCH] locking/ww_mutex: Adjust to lockdep nest_lock requirements

in testcase: boot

compiler: gcc-7
test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G

(please refer to attached dmesg/kmsg for entire log/backtrace)


+-----------------------------------------------------+------------+------------+
|                                                     | a51749ab34 | 4f37585fa0 |
+-----------------------------------------------------+------------+------------+
| WARNING:at_kernel/locking/lockdep.c:#__lock_acquire | 0          | 6          |
| EIP:__lock_acquire                                  | 0          | 6          |
+-----------------------------------------------------+------------+------------+


If you fix the issue in a separate patch/commit (i.e. not just a new version of
the same patch/commit), kindly add following tags
| Reported-by: kernel test robot <oliver.sang@intel.com>
| Closes: https://lore.kernel.org/oe-lkp/202312221708.b143534-oliver.sang@intel.com


[    9.777113][   T10] ------------[ cut here ]------------
[    9.777784][   T10] DEBUG_LOCKS_WARN_ON(hlock->references < references)
[ 9.777795][ T10] WARNING: CPU: 0 PID: 10 at kernel/locking/lockdep.c:5055 __lock_acquire (kernel/locking/lockdep.c:5055 (discriminator 9)) 
[    9.778839][   T10] Modules linked in:
[    9.778839][   T10] CPU: 0 PID: 10 Comm: kworker/u2:0 Not tainted 6.7.0-rc1-00006-g4f37585fa02f #5
[    9.778839][   T10] Workqueue: test-ww_mutex stress_inorder_work
[ 9.778839][ T10] EIP: __lock_acquire (kernel/locking/lockdep.c:5055 (discriminator 9)) 
[ 9.778839][ T10] Code: e8 ae 10 2e 00 85 c0 0f 84 0e 0f 00 00 8b 1d 94 9c b5 ce 85 db 0f 85 00 0f 00 00 68 64 16 34 ce 68 fe 17 33 ce e8 09 22 fc ff <0f> 0b 58 5a e9 28 12 00 00 a1 90 ef 24 cf 85 c0 74 07 eb 2a 8d 74
All code
========
   0:	e8 ae 10 2e 00       	callq  0x2e10b3
   5:	85 c0                	test   %eax,%eax
   7:	0f 84 0e 0f 00 00    	je     0xf1b
   d:	8b 1d 94 9c b5 ce    	mov    -0x314a636c(%rip),%ebx        # 0xffffffffceb59ca7
  13:	85 db                	test   %ebx,%ebx
  15:	0f 85 00 0f 00 00    	jne    0xf1b
  1b:	68 64 16 34 ce       	pushq  $0xffffffffce341664
  20:	68 fe 17 33 ce       	pushq  $0xffffffffce3317fe
  25:	e8 09 22 fc ff       	callq  0xfffffffffffc2233
  2a:*	0f 0b                	ud2    		<-- trapping instruction
  2c:	58                   	pop    %rax
  2d:	5a                   	pop    %rdx
  2e:	e9 28 12 00 00       	jmpq   0x125b
  33:	a1 90 ef 24 cf 85 c0 	movabs 0x774c085cf24ef90,%eax
  3a:	74 07 
  3c:	eb 2a                	jmp    0x68
  3e:	8d                   	.byte 0x8d
  3f:	74                   	.byte 0x74

Code starting with the faulting instruction
===========================================
   0:	0f 0b                	ud2    
   2:	58                   	pop    %rax
   3:	5a                   	pop    %rdx
   4:	e9 28 12 00 00       	jmpq   0x1231
   9:	a1 90 ef 24 cf 85 c0 	movabs 0x774c085cf24ef90,%eax
  10:	74 07 
  12:	eb 2a                	jmp    0x3e
  14:	8d                   	.byte 0x8d
  15:	74                   	.byte 0x74
[    9.778839][   T10] EAX: 00000033 EBX: 00000000 ECX: c0245cb4 EDX: ce9da1ac
[    9.778839][   T10] ESI: c26cb37c EDI: c02569ac EBP: c0245db0 ESP: c0245d60
[    9.778839][   T10] DS: 007b ES: 007b FS: 0000 GS: 0000 SS: 0068 EFLAGS: 00010002
[    9.778839][   T10] CR0: 80050033 CR2: ffdda000 CR3: 0ec21000 CR4: 00040690
[    9.778839][   T10] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
[    9.778839][   T10] DR6: fffe0ff0 DR7: 00000400
[    9.778839][   T10] Call Trace:
[ 9.778839][ T10] ? show_regs (arch/x86/kernel/dumpstack.c:478) 
[ 9.778839][ T10] ? __warn (kernel/panic.c:677) 
[ 9.778839][ T10] ? __lock_acquire (kernel/locking/lockdep.c:5055 (discriminator 9)) 
[ 9.778839][ T10] ? report_bug (lib/bug.c:201 lib/bug.c:219) 
[ 9.778839][ T10] ? exc_overflow (arch/x86/kernel/traps.c:250) 
[ 9.778839][ T10] ? handle_bug (arch/x86/kernel/traps.c:237) 
[ 9.778839][ T10] ? exc_invalid_op (arch/x86/kernel/traps.c:258 (discriminator 1)) 
[ 9.778839][ T10] ? handle_exception (arch/x86/entry/entry_32.S:1056) 
[ 9.778839][ T10] ? __lock_acquire (kernel/locking/lockdep.c:5047) 
[ 9.778839][ T10] ? exc_overflow (arch/x86/kernel/traps.c:250) 
[ 9.778839][ T10] ? __lock_acquire (kernel/locking/lockdep.c:5055 (discriminator 9)) 
[ 9.778839][ T10] ? exc_overflow (arch/x86/kernel/traps.c:250) 
[ 9.778839][ T10] ? __lock_acquire (kernel/locking/lockdep.c:5055 (discriminator 9)) 
[ 9.778839][ T10] ? kvm_sched_clock_read (arch/x86/kernel/kvmclock.c:91) 
[ 9.778839][ T10] lock_acquire (kernel/locking/lockdep.c:467 kernel/locking/lockdep.c:5755) 
[ 9.778839][ T10] ? stress_inorder_work (kernel/locking/test-ww_mutex.c:457) 
[ 9.778839][ T10] ? lock_is_held_type (kernel/locking/lockdep.c:5494 kernel/locking/lockdep.c:5824) 
[ 9.778839][ T10] __ww_mutex_lock+0xb1/0xd84 
[ 9.778839][ T10] ? stress_inorder_work (kernel/locking/test-ww_mutex.c:457) 
[ 9.778839][ T10] ww_mutex_lock (kernel/locking/mutex.c:878) 
[ 9.778839][ T10] stress_inorder_work (kernel/locking/test-ww_mutex.c:457) 
[ 9.778839][ T10] process_scheduled_works (kernel/workqueue.c:2630 include/linux/jump_label.h:207 include/trace/events/workqueue.h:108 kernel/workqueue.c:2635 kernel/workqueue.c:2703) 
[ 9.778839][ T10] worker_thread (include/linux/list.h:373 kernel/workqueue.c:841 kernel/workqueue.c:2785) 
[ 9.778839][ T10] kthread (kernel/kthread.c:390) 
[ 9.778839][ T10] ? rescuer_thread (kernel/workqueue.c:2730) 
[ 9.778839][ T10] ? kthread_complete_and_exit (kernel/kthread.c:341) 
[ 9.778839][ T10] ret_from_fork (arch/x86/kernel/process.c:153) 
[ 9.778839][ T10] ? kthread_complete_and_exit (kernel/kthread.c:341) 
[ 9.778839][ T10] ret_from_fork_asm (arch/x86/entry/entry_32.S:741) 
[ 9.778839][ T10] entry_INT80_32 (arch/x86/entry/entry_32.S:947) 
[    9.778839][   T10] irq event stamp: 14037
[ 9.778839][ T10] hardirqs last enabled at (14037): irqentry_exit (kernel/entry/common.c:435) 
[ 9.778839][ T10] hardirqs last disabled at (14036): common_interrupt (arch/x86/kernel/irq.c:247) 
[ 9.778839][ T10] softirqs last enabled at (8978): __do_softirq (arch/x86/include/asm/preempt.h:27 kernel/softirq.c:400 kernel/softirq.c:582) 
[ 9.778839][ T10] softirqs last disabled at (8969): do_softirq_own_stack (arch/x86/kernel/irq_32.c:57 arch/x86/kernel/irq_32.c:147) 
[    9.778839][   T10] ---[ end trace 0000000000000000 ]---
[    9.917906][   T36] torture_spin_lock_write_delay: delay = 25 jiffies.
[   10.273181][   T36] torture_spin_lock_write_delay: delay = 25 jiffies.
[   10.621916][   T36] torture_spin_lock_write_delay: delay = 25 jiffies.
[   10.788923][   T36] torture_spin_lock_write_delay: delay = 25 jiffies.
[   10.919665][   T36] torture_spin_lock_write_delay: delay = 26 jiffies.
[   11.085916][   T36] torture_spin_lock_write_delay: delay = 25 jiffies.
[   11.471931][   T35] torture_spin_lock_write_delay: delay = 25 jiffies.
[   11.784602][    T1] All ww mutex selftests passed



The kernel config and materials to reproduce are available at:
https://download.01.org/0day-ci/archive/20231222/202312221708.b143534-oliver.sang@intel.com



-- 
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests/wiki