[<prev] [next>] [<thread-prev] [day] [month] [year] [list]
Message-ID: <202306282154.58062c2f-oliver.sang@intel.com>
Date: Wed, 28 Jun 2023 21:54:08 +0800
From: kernel test robot <oliver.sang@...el.com>
To: You Kangren <youkangren@...o.com>
CC: <oe-lkp@...ts.linux.dev>, <lkp@...el.com>,
<linux-kernel@...r.kernel.org>,
Thomas Gleixner <tglx@...utronix.de>,
<opensource.kernel@...o.com>, <youkangren@...o.com>,
<oliver.sang@...el.com>
Subject: Re: [PATCH] posix-timers: Release the acquired lock before returning
Hello,
kernel test robot noticed "WARNING:bad_unlock_balance_detected" on:
commit: a33a94dbedf738c4e9e4b264883fbfd9a01b1e29 ("[PATCH] posix-timers: Release the acquired lock before returning")
url: https://github.com/intel-lab-lkp/linux/commits/You-Kangren/posix-timers-Release-the-acquired-lock-before-returning/20230626-200132
base: https://git.kernel.org/cgit/linux/kernel/git/tip/tip.git d2b32be7debd6c0deeae95844997bd89fbe4769d
patch link: https://lore.kernel.org/all/20230626120017.3030-1-youkangren@vivo.com/
patch subject: [PATCH] posix-timers: Release the acquired lock before returning
in testcase: trinity
version: trinity-i386-abe9de86-1_20230429
with following parameters:
runtime: 600s
test-description: Trinity is a linux system call fuzz tester.
test-url: http://codemonkey.org.uk/projects/trinity/
compiler: gcc-12
test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G
(please refer to attached dmesg/kmsg for entire log/backtrace)
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@...el.com>
| Closes: https://lore.kernel.org/oe-lkp/202306282154.58062c2f-oliver.sang@intel.com
[ 40.691875][ T648] WARNING: bad unlock balance detected!
[ 40.692294][ T648] 6.4.0-rc4-00041-ga33a94dbedf7 #17 Not tainted
[ 40.692764][ T648] -------------------------------------
[ 40.693174][ T648] trinity-c1/648 is trying to release lock (&posix_cpu_timers_key) at:
[ 40.693798][ T648] do_timer_gettime (kbuild/src/rand-4/kernel/time/posix-timers.c:716)
[ 40.694256][ T648] but there are no more locks to release!
[ 40.694687][ T648]
[ 40.694687][ T648] other info that might help us debug this:
[ 40.695297][ T648] no locks held by trinity-c1/648.
[ 40.695683][ T648]
[ 40.695683][ T648] stack backtrace:
[ 40.696130][ T648] CPU: 1 PID: 648 Comm: trinity-c1 Not tainted 6.4.0-rc4-00041-ga33a94dbedf7 #17 52a599974c7ffcbcfb7dedc40a8a8b5005ce7907
[ 40.697075][ T648] Call Trace:
[ 40.697333][ T648] dump_stack_lvl (kbuild/src/rand-4/lib/dump_stack.c:107 (discriminator 4))
[ 40.697681][ T648] dump_stack (kbuild/src/rand-4/lib/dump_stack.c:114)
[ 40.697992][ T648] print_unlock_imbalance_bug (kbuild/src/rand-4/kernel/locking/lockdep.c:5145 kbuild/src/rand-4/kernel/locking/lockdep.c:5121)
[ 40.698432][ T648] ? do_timer_gettime (kbuild/src/rand-4/kernel/time/posix-timers.c:716)
[ 40.698806][ T648] ? do_timer_gettime (kbuild/src/rand-4/kernel/time/posix-timers.c:716)
[ 40.699182][ T648] ? do_timer_gettime (kbuild/src/rand-4/kernel/time/posix-timers.c:716)
[ 40.699555][ T648] __lock_release+0x61/0x111
[ 40.699955][ T648] ? do_timer_gettime (kbuild/src/rand-4/kernel/time/posix-timers.c:716)
[ 40.700334][ T648] lock_release (kbuild/src/rand-4/kernel/locking/lockdep.c:467 kbuild/src/rand-4/kernel/locking/lockdep.c:5727)
[ 40.700667][ T648] _raw_spin_unlock_irqrestore (kbuild/src/rand-4/include/linux/spinlock_api_smp.h:150 kbuild/src/rand-4/kernel/locking/spinlock.c:194)
[ 40.701104][ T648] do_timer_gettime (kbuild/src/rand-4/kernel/time/posix-timers.c:716)
[ 40.701460][ T648] __ia32_sys_timer_gettime32 (kbuild/src/rand-4/kernel/time/posix-timers.c:741 kbuild/src/rand-4/kernel/time/posix-timers.c:735 kbuild/src/rand-4/kernel/time/posix-timers.c:735)
[ 40.701881][ T648] __do_fast_syscall_32 (kbuild/src/rand-4/arch/x86/entry/common.c:112 kbuild/src/rand-4/arch/x86/entry/common.c:178)
[ 40.706369][ T648] do_fast_syscall_32 (kbuild/src/rand-4/arch/x86/entry/common.c:203)
[ 40.706751][ T648] do_SYSENTER_32 (kbuild/src/rand-4/arch/x86/entry/common.c:247)
[ 40.707100][ T648] entry_SYSENTER_32 (kbuild/src/rand-4/arch/x86/entry/entry_32.S:867)
[ 40.707473][ T648] EIP: 0x37f7256d
[ 40.707755][ T648] Code: c4 01 10 03 03 74 c0 01 10 05 03 74 b8 01 10 06 03 74 b4 01 10 07 03 74 b0 01 10 08 03 74 d8 01 00 51 52 55 89 e5 0f 34 cd 80 <5d> 5a 59 c3 90 90 90 90 8d 76 00 58 b8 77 00 00 00 cd 80 90 8d 76
All code
========
0: c4 01 10 03 (bad)
4: 03 74 c0 01 add 0x1(%rax,%rax,8),%esi
8: 10 05 03 74 b8 01 adc %al,0x1b87403(%rip) # 0x1b87411
e: 10 06 adc %al,(%rsi)
10: 03 74 b4 01 add 0x1(%rsp,%rsi,4),%esi
14: 10 07 adc %al,(%rdi)
16: 03 74 b0 01 add 0x1(%rax,%rsi,4),%esi
1a: 10 08 adc %cl,(%rax)
1c: 03 74 d8 01 add 0x1(%rax,%rbx,8),%esi
20: 00 51 52 add %dl,0x52(%rcx)
23: 55 push %rbp
24: 89 e5 mov %esp,%ebp
26: 0f 34 sysenter
28: cd 80 int $0x80
2a:* 5d pop %rbp <-- trapping instruction
2b: 5a pop %rdx
2c: 59 pop %rcx
2d: c3 retq
2e: 90 nop
2f: 90 nop
30: 90 nop
31: 90 nop
32: 8d 76 00 lea 0x0(%rsi),%esi
35: 58 pop %rax
36: b8 77 00 00 00 mov $0x77,%eax
3b: cd 80 int $0x80
3d: 90 nop
3e: 8d .byte 0x8d
3f: 76 .byte 0x76
Code starting with the faulting instruction
===========================================
0: 5d pop %rbp
1: 5a pop %rdx
2: 59 pop %rcx
3: c3 retq
4: 90 nop
5: 90 nop
6: 90 nop
7: 90 nop
8: 8d 76 00 lea 0x0(%rsi),%esi
b: 58 pop %rax
c: b8 77 00 00 00 mov $0x77,%eax
11: cd 80 int $0x80
13: 90 nop
14: 8d .byte 0x8d
15: 76 .byte 0x76
[ 40.709247][ T648] EAX: ffffffda EBX: 00000000 ECX: 369e1000 EDX: 000000c8
[ 40.709776][ T648] ESI: fffffffe EDI: 0000cfa5 EBP: 0000d3ee ESP: 3ffe77cc
[ 40.710325][ T648] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b EFLAGS: 00000216
[ 40.710964][ T648] ------------[ cut here ]------------
[ 40.711429][ T648] raw_local_irq_restore() called with IRQs enabled
[ 40.711945][ T648] WARNING: CPU: 1 PID: 648 at kernel/locking/irqflag-debug.c:10 warn_bogus_irq_restore (kbuild/src/rand-4/kernel/locking/irqflag-debug.c:10 (discriminator 3))
[ 40.712739][ T648] Modules linked in: rose mpls_router phonet bluetooth ecdh_generic rfkill can_raw cn scsi_transport_iscsi scsi_mod atm netrom appletalk ax25 evbug crc32c_intel input_leds evdev button fuse autofs4
[ 40.714207][ T648] CPU: 1 PID: 648 Comm: trinity-c1 Not tainted 6.4.0-rc4-00041-ga33a94dbedf7 #17 52a599974c7ffcbcfb7dedc40a8a8b5005ce7907
[ 40.715159][ T648] EIP: warn_bogus_irq_restore (kbuild/src/rand-4/kernel/locking/irqflag-debug.c:10 (discriminator 3))
[ 40.715579][ T648] Code: 5b 89 fa 5e 5f 5d 8d 67 f8 5f 31 c9 c3 80 3d ab 1d 1b 42 00 75 1b 55 89 e5 c6 05 ab 1d 1b 42 01 68 28 1a bc 41 e8 a5 b7 82 ff <0f> 0b 58 c9 31 c0 c3 31 c0 c3 55 89 e5 56 53 64 8b 1d 80 d2 2a 42
All code
========
0: 5b pop %rbx
1: 89 fa mov %edi,%edx
3: 5e pop %rsi
4: 5f pop %rdi
5: 5d pop %rbp
6: 8d 67 f8 lea -0x8(%rdi),%esp
9: 5f pop %rdi
a: 31 c9 xor %ecx,%ecx
c: c3 retq
d: 80 3d ab 1d 1b 42 00 cmpb $0x0,0x421b1dab(%rip) # 0x421b1dbf
14: 75 1b jne 0x31
16: 55 push %rbp
17: 89 e5 mov %esp,%ebp
19: c6 05 ab 1d 1b 42 01 movb $0x1,0x421b1dab(%rip) # 0x421b1dcb
20: 68 28 1a bc 41 pushq $0x41bc1a28
25: e8 a5 b7 82 ff callq 0xffffffffff82b7cf
2a:* 0f 0b ud2 <-- trapping instruction
2c: 58 pop %rax
2d: c9 leaveq
2e: 31 c0 xor %eax,%eax
30: c3 retq
31: 31 c0 xor %eax,%eax
33: c3 retq
34: 55 push %rbp
35: 89 e5 mov %esp,%ebp
37: 56 push %rsi
38: 53 push %rbx
39: 64 8b 1d 80 d2 2a 42 mov %fs:0x422ad280(%rip),%ebx # 0x422ad2c0
Code starting with the faulting instruction
===========================================
0: 0f 0b ud2
2: 58 pop %rax
3: c9 leaveq
4: 31 c0 xor %eax,%eax
6: c3 retq
7: 31 c0 xor %eax,%eax
9: c3 retq
a: 55 push %rbp
b: 89 e5 mov %esp,%ebp
d: 56 push %rsi
e: 53 push %rbx
f: 64 8b 1d 80 d2 2a 42 mov %fs:0x422ad280(%rip),%ebx # 0x422ad296
[ 40.717015][ T648] EAX: 00000000 EBX: 531a37e0 ECX: 00000000 EDX: 00000000
[ 40.717541][ T648] ESI: 00000202 EDI: bec97f78 EBP: bec97f30 ESP: bec97f2c
[ 40.718085][ T648] DS: 007b ES: 007b FS: 00d8 GS: 0033 SS: 0068 EFLAGS: 00010246
[ 40.718678][ T648] CR0: 80050033 CR2: 00ef2f74 CR3: 7e6d5ac0 CR4: 000406b0
[ 40.719224][ T648] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
[ 40.719766][ T648] DR6: fffe0ff0 DR7: 00000400
[ 40.720126][ T648] Call Trace:
[ 40.720383][ T648] ? show_regs (kbuild/src/rand-4/arch/x86/kernel/dumpstack.c:479 kbuild/src/rand-4/arch/x86/kernel/dumpstack.c:465)
[ 40.720707][ T648] ? warn_bogus_irq_restore (kbuild/src/rand-4/kernel/locking/irqflag-debug.c:10 (discriminator 3))
[ 40.721129][ T648] ? __warn (kbuild/src/rand-4/kernel/panic.c:673)
[ 40.721436][ T648] ? report_bug (kbuild/src/rand-4/lib/bug.c:201 kbuild/src/rand-4/lib/bug.c:219)
[ 40.721769][ T648] ? warn_bogus_irq_restore (kbuild/src/rand-4/kernel/locking/irqflag-debug.c:10 (discriminator 3))
[ 40.722178][ T648] ? exc_overflow (kbuild/src/rand-4/arch/x86/kernel/traps.c:337)
[ 40.722519][ T648] ? handle_bug (kbuild/src/rand-4/arch/x86/kernel/traps.c:324)
[ 40.722847][ T648] ? exc_invalid_op (kbuild/src/rand-4/arch/x86/kernel/traps.c:345 (discriminator 1))
[ 40.723198][ T648] ? handle_exception (kbuild/src/rand-4/arch/x86/entry/entry_32.S:1083)
[ 40.723575][ T648] ? exc_overflow (kbuild/src/rand-4/arch/x86/kernel/traps.c:337)
[ 40.723915][ T648] ? warn_bogus_irq_restore (kbuild/src/rand-4/kernel/locking/irqflag-debug.c:10 (discriminator 3))
[ 40.724309][ T648] ? exc_overflow (kbuild/src/rand-4/arch/x86/kernel/traps.c:337)
[ 40.724647][ T648] ? warn_bogus_irq_restore (kbuild/src/rand-4/kernel/locking/irqflag-debug.c:10 (discriminator 3))
[ 40.725053][ T648] _raw_spin_unlock_irqrestore (kbuild/src/rand-4/arch/x86/include/asm/irqflags.h:42 kbuild/src/rand-4/arch/x86/include/asm/irqflags.h:77 kbuild/src/rand-4/arch/x86/include/asm/irqflags.h:135 kbuild/src/rand-4/include/linux/spinlock_api_smp.h:151 kbuild/src/rand-4/kernel/locking/spinlock.c:194)
[ 40.725483][ T648] do_timer_gettime (kbuild/src/rand-4/kernel/time/posix-timers.c:716)
[ 40.725842][ T648] __ia32_sys_timer_gettime32 (kbuild/src/rand-4/kernel/time/posix-timers.c:741 kbuild/src/rand-4/kernel/time/posix-timers.c:735 kbuild/src/rand-4/kernel/time/posix-timers.c:735)
[ 40.726271][ T648] __do_fast_syscall_32 (kbuild/src/rand-4/arch/x86/entry/common.c:112 kbuild/src/rand-4/arch/x86/entry/common.c:178)
[ 40.726656][ T648] do_fast_syscall_32 (kbuild/src/rand-4/arch/x86/entry/common.c:203)
[ 40.727024][ T648] do_SYSENTER_32 (kbuild/src/rand-4/arch/x86/entry/common.c:247)
[ 40.727370][ T648] entry_SYSENTER_32 (kbuild/src/rand-4/arch/x86/entry/entry_32.S:867)
[ 40.727741][ T648] EIP: 0x37f7256d
[ 40.728023][ T648] Code: c4 01 10 03 03 74 c0 01 10 05 03 74 b8 01 10 06 03 74 b4 01 10 07 03 74 b0 01 10 08 03 74 d8 01 00 51 52 55 89 e5 0f 34 cd 80 <5d> 5a 59 c3 90 90 90 90 8d 76 00 58 b8 77 00 00 00 cd 80 90 8d 76
All code
========
0: c4 01 10 03 (bad)
4: 03 74 c0 01 add 0x1(%rax,%rax,8),%esi
8: 10 05 03 74 b8 01 adc %al,0x1b87403(%rip) # 0x1b87411
e: 10 06 adc %al,(%rsi)
10: 03 74 b4 01 add 0x1(%rsp,%rsi,4),%esi
14: 10 07 adc %al,(%rdi)
16: 03 74 b0 01 add 0x1(%rax,%rsi,4),%esi
1a: 10 08 adc %cl,(%rax)
1c: 03 74 d8 01 add 0x1(%rax,%rbx,8),%esi
20: 00 51 52 add %dl,0x52(%rcx)
23: 55 push %rbp
24: 89 e5 mov %esp,%ebp
26: 0f 34 sysenter
28: cd 80 int $0x80
2a:* 5d pop %rbp <-- trapping instruction
2b: 5a pop %rdx
2c: 59 pop %rcx
2d: c3 retq
2e: 90 nop
2f: 90 nop
30: 90 nop
31: 90 nop
32: 8d 76 00 lea 0x0(%rsi),%esi
35: 58 pop %rax
36: b8 77 00 00 00 mov $0x77,%eax
3b: cd 80 int $0x80
3d: 90 nop
3e: 8d .byte 0x8d
3f: 76 .byte 0x76
Code starting with the faulting instruction
===========================================
0: 5d pop %rbp
1: 5a pop %rdx
2: 59 pop %rcx
3: c3 retq
4: 90 nop
5: 90 nop
6: 90 nop
7: 90 nop
8: 8d 76 00 lea 0x0(%rsi),%esi
b: 58 pop %rax
c: b8 77 00 00 00 mov $0x77,%eax
11: cd 80 int $0x80
13: 90 nop
14: 8d .byte 0x8d
15: 76 .byte 0x76
To reproduce:
# build kernel
cd linux
cp config-6.4.0-rc4-00041-ga33a94dbedf7 .config
make HOSTCC=gcc-12 CC=gcc-12 ARCH=i386 olddefconfig prepare modules_prepare bzImage modules
make HOSTCC=gcc-12 CC=gcc-12 ARCH=i386 INSTALL_MOD_PATH=<mod-install-dir> modules_install
cd <mod-install-dir>
find lib/ | cpio -o -H newc --quiet | gzip > modules.cgz
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> -m modules.cgz 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.
--
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests/wiki
View attachment "config-6.4.0-rc4-00041-ga33a94dbedf7" of type "text/plain" (149441 bytes)
View attachment "job-script" of type "text/plain" (4921 bytes)
Download attachment "dmesg.xz" of type "application/x-xz" (18200 bytes)
Powered by blists - more mailing lists