Hello, kernel test robot noticed "WARNING:bad_unlock_balance_detected" on: commit: cc69506d19ada63803c37c09ff910217004db1e8 ("KVM: pfncache: simplify locking and make more self-contained") git://git.infradead.org/users/dwmw2/linux pfncache in testcase: kernel-selftests version: kernel-selftests-x86_64-60acb023-1_20230329 with following parameters: group: kvm compiler: gcc-12 test machine: 224 threads 2 sockets Intel(R) Xeon(R) Platinum 8480+ (Sapphire Rapids) with 256G memory (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@xxxxxxxxx> | Closes: https://lore.kernel.org/oe-lkp/202402191553.bd17cf2a-oliver.sang@xxxxxxxxx [ 124.479929][ T5856] WARNING: bad unlock balance detected! [ 124.487408][ T5856] 6.7.0-rc7-00250-gcc69506d19ad #1 Not tainted [ 124.495550][ T5856] ------------------------------------- [ 124.503030][ T5856] kvm_clock_test/5856 is trying to release lock (&gpc->refresh_lock) at: [ 124.513736][ T5856] __kvm_gpc_activate (arch/x86/kvm/../../../virt/kvm/pfncache.c:384) kvm [ 124.523274][ T5856] but there are no more locks to release! [ 124.531003][ T5856] [ 124.531003][ T5856] other info that might help us debug this: [ 124.542656][ T5856] 2 locks held by kvm_clock_test/5856: [ 124.550015][ T5856] #0: ff1100406be92470 (&vcpu->mutex){+.+.}-{3:3}, at: kvm_vcpu_ioctl (arch/x86/kvm/../../../virt/kvm/kvm_main.c:4418) kvm [ 124.562285][ T5856] #1: ffa000003456af10 (&kvm->srcu){.+.+}-{0:0}, at: vcpu_enter_guest+0x19b8/0x3770 kvm [ 124.575935][ T5856] [ 124.575935][ T5856] stack backtrace: [ 124.584919][ T5856] CPU: 207 PID: 5856 Comm: kvm_clock_test Not tainted 6.7.0-rc7-00250-gcc69506d19ad #1 [ 124.596895][ T5856] Call Trace: [ 124.601723][ T5856] <TASK> [ 124.606141][ T5856] dump_stack_lvl (lib/dump_stack.c:108) [ 124.612299][ T5856] __lock_release+0x2eb/0x440 [ 124.619377][ T5856] ? __kvm_gpc_activate (arch/x86/kvm/../../../virt/kvm/pfncache.c:384) kvm [ 124.626988][ T5856] ? reacquire_held_locks (kernel/locking/lockdep.c:5405) [ 124.634156][ T5856] ? __mutex_unlock_slowpath (arch/x86/include/asm/atomic64_64.h:109 include/linux/atomic/atomic-arch-fallback.h:4308 include/linux/atomic/atomic-long.h:1499 include/linux/atomic/atomic-instrumented.h:4446 kernel/locking/mutex.c:924) [ 124.641629][ T5856] ? bit_wait_timeout (kernel/locking/mutex.c:902) [ 124.648418][ T5856] ? __kvm_gpc_activate (arch/x86/kvm/../../../virt/kvm/pfncache.c:384) kvm [ 124.656056][ T5856] lock_release (kernel/locking/lockdep.c:467 kernel/locking/lockdep.c:5776) [ 124.662187][ T5856] __mutex_unlock_slowpath (include/linux/instrumented.h:68 include/linux/atomic/atomic-instrumented.h:3160 kernel/locking/mutex.c:916) [ 124.669408][ T5856] ? bit_wait_timeout (kernel/locking/mutex.c:902) [ 124.676233][ T5856] ? __kvm_gpc_refresh (arch/x86/kvm/../../../virt/kvm/pfncache.c:97 arch/x86/kvm/../../../virt/kvm/pfncache.c:328) kvm [ 124.683867][ T5856] ? lockdep_hardirqs_on_prepare (kernel/locking/lockdep.c:4566) [ 124.692378][ T5856] __kvm_gpc_activate (arch/x86/kvm/../../../virt/kvm/pfncache.c:384) kvm [ 124.699751][ T5856] kvm_set_msr_common (arch/x86/kvm/x86.c:4043 arch/x86/kvm/x86.c:4210) kvm [ 124.707296][ T5856] ? kvm_write_wall_clock+0x180/0x180 kvm [ 124.716209][ T5856] ? __lock_release+0x111/0x440 [ 124.723338][ T5856] ? kvm_msr_allowed (include/linux/srcu.h:122 include/linux/srcu.h:287 arch/x86/kvm/x86.c:1831) kvm [ 124.730488][ T5856] vmx_set_msr (arch/x86/kvm/vmx/vmx.c:2448) kvm_intel [ 124.737687][ T5856] __kvm_set_msr (arch/x86/kvm/x86.c:1845) kvm [ 124.744439][ T5856] ? kvm_msr_allowed (include/linux/srcu.h:122 include/linux/srcu.h:287 arch/x86/kvm/x86.c:1831) kvm [ 124.751591][ T5856] ? kvm_emulate_monitor (arch/x86/kvm/x86.c:1845) kvm [ 124.758933][ T5856] ? lock_release (kernel/locking/lockdep.c:467 kernel/locking/lockdep.c:5776) [ 124.765024][ T5856] ? kvm_msr_allowed (include/linux/srcu.h:288 arch/x86/kvm/x86.c:1831) kvm [ 124.772168][ T5856] kvm_emulate_wrmsr (arch/x86/kvm/x86.c:1908 arch/x86/kvm/x86.c:1976 arch/x86/kvm/x86.c:1972 arch/x86/kvm/x86.c:2086) kvm [ 124.779208][ T5856] vmx_handle_exit (arch/x86/kvm/vmx/vmx.c:6589) kvm_intel [ 124.786608][ T5856] vcpu_enter_guest+0x1ab2/0x3770 kvm [ 124.795030][ T5856] ? kvm_check_and_inject_events (arch/x86/kvm/x86.c:10778) kvm [ 124.803528][ T5856] ? lock_acquire (include/trace/events/lock.h:24 kernel/locking/lockdep.c:5725) [ 124.809634][ T5856] ? kvm_arch_vcpu_ioctl_run (include/linux/srcu.h:116 include/linux/srcu.h:215 include/linux/kvm_host.h:927 arch/x86/kvm/x86.c:11395) kvm [ 124.817682][ T5856] ? lock_sync (kernel/locking/lockdep.c:5722) [ 124.823629][ T5856] ? mark_held_locks (kernel/locking/lockdep.c:4274) [ 124.829965][ T5856] ? vcpu_run (arch/x86/kvm/x86.c:11258) kvm [ 124.836441][ T5856] vcpu_run (arch/x86/kvm/x86.c:11258) kvm [ 124.842720][ T5856] kvm_arch_vcpu_ioctl_run (arch/x86/kvm/x86.c:11484) kvm [ 124.850583][ T5856] ? lock_release (kernel/locking/lockdep.c:467 kernel/locking/lockdep.c:5776) [ 124.856744][ T5856] kvm_vcpu_ioctl (arch/x86/kvm/../../../virt/kvm/kvm_main.c:4442) kvm [ 124.863640][ T5856] ? kvm_vcpu_kick (arch/x86/kvm/../../../virt/kvm/kvm_main.c:4397) kvm [ 124.870633][ T5856] __x64_sys_ioctl (fs/ioctl.c:52 fs/ioctl.c:871 fs/ioctl.c:857 fs/ioctl.c:857) [ 124.877002][ T5856] do_syscall_64 (arch/x86/entry/common.c:52 arch/x86/entry/common.c:83) [ 124.882981][ T5856] entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:129) [ 124.890633][ T5856] RIP: 0033:0x7f1046845b5b [ 124.896609][ T5856] Code: 00 48 89 44 24 18 31 c0 48 8d 44 24 60 c7 04 24 10 00 00 00 48 89 44 24 08 48 8d 44 24 20 48 89 44 24 10 b8 10 00 00 00 0f 05 <89> c2 3d 00 f0 ff ff 77 1c 48 8b 44 24 18 64 48 2b 04 25 28 00 00 All code ======== 0: 00 48 89 add %cl,-0x77(%rax) 3: 44 24 18 rex.R and $0x18,%al 6: 31 c0 xor %eax,%eax 8: 48 8d 44 24 60 lea 0x60(%rsp),%rax d: c7 04 24 10 00 00 00 movl $0x10,(%rsp) 14: 48 89 44 24 08 mov %rax,0x8(%rsp) 19: 48 8d 44 24 20 lea 0x20(%rsp),%rax 1e: 48 89 44 24 10 mov %rax,0x10(%rsp) 23: b8 10 00 00 00 mov $0x10,%eax 28: 0f 05 syscall 2a:* 89 c2 mov %eax,%edx <-- trapping instruction 2c: 3d 00 f0 ff ff cmp $0xfffff000,%eax 31: 77 1c ja 0x4f 33: 48 8b 44 24 18 mov 0x18(%rsp),%rax 38: 64 fs 39: 48 rex.W 3a: 2b .byte 0x2b 3b: 04 25 add $0x25,%al 3d: 28 00 sub %al,(%rax) ... Code starting with the faulting instruction =========================================== 0: 89 c2 mov %eax,%edx 2: 3d 00 f0 ff ff cmp $0xfffff000,%eax 7: 77 1c ja 0x25 9: 48 8b 44 24 18 mov 0x18(%rsp),%rax e: 64 fs f: 48 rex.W 10: 2b .byte 0x2b 11: 04 25 add $0x25,%al 13: 28 00 sub %al,(%rax) ... [ 124.919748][ T5856] RSP: 002b:00007ffed26c1d10 EFLAGS: 00000246 ORIG_RAX: 0000000000000010 [ 124.930292][ T5856] RAX: ffffffffffffffda RBX: 00007f10467456c0 RCX: 00007f1046845b5b [ 124.940347][ T5856] RDX: 0000000000000000 RSI: 000000000000ae80 RDI: 0000000000000007 [ 124.950360][ T5856] RBP: 00000000019c2a70 R08: 00007ffed26c1e40 R09: 0000000000000002 [ 124.960375][ T5856] R10: 8c1ed6746cba2bb1 R11: 0000000000000246 R12: 0000000000427220 [ 124.970373][ T5856] R13: 0000000000000000 R14: 00000000019c0490 R15: 000000008030ae7c [ 124.980364][ T5856] </TASK> The kernel config and materials to reproduce are available at: https://download.01.org/0day-ci/archive/20240219/202402191553.bd17cf2a-oliver.sang@xxxxxxxxx -- 0-DAY CI Kernel Test Service https://github.com/intel/lkp-tests/wiki