* [linus:master] [locking/lockdep] de4b59d652: BUG:KASAN:slab-use-after-free_in_raw_spin_lock_irq
@ 2025-06-30 2:34 kernel test robot
2025-06-30 4:13 ` Waiman Long
0 siblings, 1 reply; 3+ messages in thread
From: kernel test robot @ 2025-06-30 2:34 UTC (permalink / raw)
To: Waiman Long
Cc: oe-lkp, lkp, linux-kernel, Ingo Molnar, Marco Elver, Boqun Feng,
Andrey Konovalov, oliver.sang
Hello,
kernel test robot noticed "BUG:KASAN:slab-use-after-free_in_raw_spin_lock_irq" on:
commit: de4b59d652646cf00cf632174348ca2266099edc ("locking/lockdep: Add kasan_check_byte() check in lock_acquire()")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
[test failed on linus/master afa9a6f4f5744d907954f5b708d76c9bffa43234]
[test failed on linux-next/master 2aeda9592360c200085898a258c4754bfe879921]
in testcase: trinity
version:
with following parameters:
runtime: 600s
config: x86_64-randconfig-104-20250415
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)
the issue does not always happen. 23 times out of 142 runs as below.
parent keeps clean.
ee57ab5a32129f59 de4b59d652646cf00cf63217434
---------------- ---------------------------
fail:runs %reproduction fail:runs
| | |
:142 16% 23:142 dmesg.BUG:KASAN:slab-use-after-free_in_raw_spin_lock_irq
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/202506300447.102c9e45-lkp@intel.com
[ 154.326222][ T1658] BUG: KASAN: slab-use-after-free in _raw_spin_lock_irq (include/linux/spinlock_api_smp.h:120 kernel/locking/spinlock.c:170)
[ 154.327485][ T1658] Read of size 1 at addr ffff888101655868 by task trinity-c3/1658
[ 154.328688][ T1658]
[ 154.329089][ T1658] CPU: 0 UID: 536870912 PID: 1658 Comm: trinity-c3 Tainted: G T 6.14.0-rc5-00228-gde4b59d65264 #1
[ 154.330915][ T1658] Tainted: [T]=RANDSTRUCT
[ 154.331547][ T1658] Call Trace:
[ 154.332090][ T1658] <TASK>
[ 154.332553][ T1658] dump_stack_lvl (lib/dump_stack.c:123)
[ 154.333291][ T1658] print_address_description+0x8a/0x34b
[ 154.334384][ T1658] print_report (mm/kasan/report.c:522)
[ 154.335159][ T1658] ? __virt_addr_valid (arch/x86/mm/physaddr.c:66)
[ 154.335979][ T1658] ? _raw_spin_lock_irq (include/linux/spinlock_api_smp.h:120 kernel/locking/spinlock.c:170)
[ 154.336775][ T1658] kasan_report (mm/kasan/report.c:636)
[ 154.337475][ T1658] ? _raw_spin_lock_irq (include/linux/spinlock_api_smp.h:120 kernel/locking/spinlock.c:170)
[ 154.338283][ T1658] ? _raw_spin_lock_irq (include/linux/spinlock_api_smp.h:120 kernel/locking/spinlock.c:170)
[ 154.339112][ T1658] ? __wait_for_common (kernel/sched/completion.c:84 kernel/sched/completion.c:116)
[ 154.339920][ T1658] __kasan_check_byte (mm/kasan/common.c:561)
[ 154.340707][ T1658] lock_acquire (include/trace/events/lock.h:24 include/trace/events/lock.h:24 kernel/locking/lockdep.c:5829)
[ 154.341554][ T1658] ? pci_mmcfg_reserved (kernel/sched/core.c:6646)
[ 154.342337][ T1658] ? __sanitizer_cov_trace_pc (kernel/kcov.c:217)
[ 154.343252][ T1658] ? irq_trace (kernel/trace/trace_irqsoff.c:59 (discriminator 6))
[ 154.343968][ T1658] ? write_comp_data (kernel/kcov.c:246)
[ 154.344741][ T1658] ? usleep_range_state (kernel/time/sleep_timeout.c:62)
[ 154.345597][ T1658] _raw_spin_lock_irq (include/linux/spinlock_api_smp.h:120 kernel/locking/spinlock.c:170)
[ 154.346429][ T1658] ? __wait_for_common (kernel/sched/completion.c:84 kernel/sched/completion.c:116)
[ 154.347266][ T1658] __wait_for_common (kernel/sched/completion.c:84 kernel/sched/completion.c:116)
[ 154.348111][ T1658] ? _printk (kernel/printk/printk.c:2452)
[ 154.348825][ T1658] ? out_of_line_wait_on_bit_lock (kernel/sched/completion.c:110)
[ 154.349775][ T1658] wait_for_completion_state (kernel/sched/completion.c:268)
[ 154.350731][ T1658] kmod_dup_request_exists_wait (kernel/module/dups.c:210)
[ 154.351725][ T1658] ? inet_create (net/ipv4/af_inet.c:1382)
[ 154.352749][ T1658] __request_module (kernel/module/kmod.c:167)
[ 154.353587][ T1658] ? free_modprobe_argv (kernel/module/kmod.c:132)
[ 154.354406][ T1658] ? mark_lock (kernel/locking/lockdep.c:4726 (discriminator 3))
[ 154.355134][ T1658] ? __lock_acquire (kernel/locking/lockdep.c:5235)
[ 154.355920][ T1658] ? rcu_read_unlock (include/linux/rcupdate.h:347 include/linux/rcupdate.h:880)
[ 154.356711][ T1658] ? kvm_sched_clock_read (arch/x86/kernel/kvmclock.c:91)
[ 154.357535][ T1658] ? local_clock_noinstr (kernel/sched/clock.c:301)
[ 154.358370][ T1658] ? __lock_release+0xc0/0x16f
[ 154.358993][ T1658] ? inet_create (net/ipv4/af_inet.c:1382)
[ 154.359749][ T1658] inet_create (net/ipv4/af_inet.c:1382)
[ 154.360375][ T1658] ? kvm_sched_clock_read (arch/x86/kernel/kvmclock.c:91)
[ 154.360824][ T1658] inet_create (net/ipv4/af_inet.c:266)
[ 154.361197][ T1658] ? rcu_read_unlock (include/linux/rcupdate.h:878)
[ 154.361659][ T1658] __sock_create (net/socket.c:1549)
[ 154.362058][ T1658] __sys_socket_create (net/socket.c:1644)
[ 154.362599][ T1658] ? sock_create (net/socket.c:1629)
[ 154.363222][ T1658] ? rcu_read_unlock (include/linux/rcupdate.h:347 include/linux/rcupdate.h:880)
[ 154.363796][ T1658] __sys_socket (net/socket.c:1692)
[ 154.364376][ T1658] __x64_sys_socket (net/socket.c:1702)
[ 154.364848][ T1658] do_syscall_64 (arch/x86/entry/common.c:52 arch/x86/entry/common.c:83)
[ 154.365258][ T1658] ? lockdep_hardirqs_on_prepare (kernel/locking/lockdep.c:4663)
[ 154.366074][ T1658] ? syscall_exit_to_user_mode (include/linux/entry-common.h:362 kernel/entry/common.c:220)
[ 154.366845][ T1658] ? do_syscall_64 (arch/x86/entry/common.c:102)
[ 154.367412][ T1658] ? rcu_read_unlock (include/linux/rcupdate.h:347 include/linux/rcupdate.h:880)
[ 154.367834][ T1658] ? kvm_sched_clock_read (arch/x86/kernel/kvmclock.c:91)
[ 154.368274][ T1658] ? local_clock_noinstr (kernel/sched/clock.c:301)
[ 154.368702][ T1658] ? local_clock (arch/x86/include/asm/preempt.h:84 kernel/sched/clock.c:316)
[ 154.369074][ T1658] ? __lock_release+0xc0/0x16f
[ 154.369792][ T1658] ? __sanitizer_cov_trace_pc (kernel/kcov.c:217)
[ 154.370652][ T1658] ? __sanitizer_cov_trace_pc (kernel/kcov.c:217)
[ 154.371504][ T1658] ? irq_trace (kernel/trace/trace_irqsoff.c:59 (discriminator 6))
[ 154.372218][ T1658] ? write_comp_data (kernel/kcov.c:246)
[ 154.372976][ T1658] ? tracer_hardirqs_on (kernel/trace/trace_irqsoff.c:630)
[ 154.373837][ T1658] ? lockdep_hardirqs_on_prepare (kernel/locking/lockdep.c:4663)
[ 154.374908][ T1658] ? syscall_exit_to_user_mode (include/linux/entry-common.h:362 kernel/entry/common.c:220)
[ 154.375824][ T1658] ? do_syscall_64 (arch/x86/entry/common.c:102)
[ 154.376619][ T1658] ? __sanitizer_cov_trace_pc (kernel/kcov.c:217)
[ 154.377531][ T1658] ? __sanitizer_cov_trace_pc (kernel/kcov.c:217)
[ 154.378445][ T1658] ? irq_trace (kernel/trace/trace_irqsoff.c:59 (discriminator 6))
[ 154.379157][ T1658] ? write_comp_data (kernel/kcov.c:246)
[ 154.379923][ T1658] ? tracer_hardirqs_on (kernel/trace/trace_irqsoff.c:630)
[ 154.380723][ T1658] ? lockdep_hardirqs_on_prepare (kernel/locking/lockdep.c:4663)
[ 154.381723][ T1658] ? syscall_exit_to_user_mode (include/linux/entry-common.h:362 kernel/entry/common.c:220)
[ 154.382608][ T1658] ? do_syscall_64 (arch/x86/entry/common.c:102)
[ 154.383220][ T1658] ? rcu_read_unlock (include/linux/rcupdate.h:347 include/linux/rcupdate.h:880)
[ 154.383811][ T1658] ? kvm_sched_clock_read (arch/x86/kernel/kvmclock.c:91)
[ 154.384524][ T1658] ? local_clock_noinstr (kernel/sched/clock.c:301)
[ 154.385261][ T1658] ? local_clock (arch/x86/include/asm/preempt.h:84 kernel/sched/clock.c:316)
[ 154.385979][ T1658] ? __lock_release+0xc0/0x16f
[ 154.386876][ T1658] ? __sanitizer_cov_trace_pc (kernel/kcov.c:217)
[ 154.387784][ T1658] ? __sanitizer_cov_trace_pc (kernel/kcov.c:217)
[ 154.388666][ T1658] ? irq_trace (kernel/trace/trace_irqsoff.c:59 (discriminator 6))
[ 154.389383][ T1658] ? write_comp_data (kernel/kcov.c:246)
[ 154.390168][ T1658] ? tracer_hardirqs_on (kernel/trace/trace_irqsoff.c:630)
[ 154.390997][ T1658] ? lockdep_hardirqs_on_prepare (kernel/locking/lockdep.c:4663)
[ 154.392108][ T1658] ? syscall_exit_to_user_mode (include/linux/entry-common.h:362 kernel/entry/common.c:220)
[ 154.393047][ T1658] ? clear_bhb_loop (arch/x86/entry/entry_64.S:1538)
[ 154.393829][ T1658] ? clear_bhb_loop (arch/x86/entry/entry_64.S:1538)
[ 154.394600][ T1658] ? clear_bhb_loop (arch/x86/entry/entry_64.S:1538)
[ 154.395191][ T1658] ? clear_bhb_loop (arch/x86/entry/entry_64.S:1538)
[ 154.395845][ T1658] entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:130)
[ 154.396678][ T1658] RIP: 0033:0x463519
[ 154.397279][ T1658] Code: 00 f3 c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 0f 83 db 59 00 00 c3 66 2e 0f 1f 84 00 00 00 00
All code
========
0: 00 f3 add %dh,%bl
2: c3 ret
3: 66 2e 0f 1f 84 00 00 cs nopw 0x0(%rax,%rax,1)
a: 00 00 00
d: 0f 1f 40 00 nopl 0x0(%rax)
11: 48 89 f8 mov %rdi,%rax
14: 48 89 f7 mov %rsi,%rdi
17: 48 89 d6 mov %rdx,%rsi
1a: 48 89 ca mov %rcx,%rdx
1d: 4d 89 c2 mov %r8,%r10
20: 4d 89 c8 mov %r9,%r8
23: 4c 8b 4c 24 08 mov 0x8(%rsp),%r9
28: 0f 05 syscall
2a:* 48 3d 01 f0 ff ff cmp $0xfffffffffffff001,%rax <-- trapping instruction
30: 0f 83 db 59 00 00 jae 0x5a11
36: c3 ret
37: 66 data16
38: 2e cs
39: 0f .byte 0xf
3a: 1f (bad)
3b: 84 00 test %al,(%rax)
3d: 00 00 add %al,(%rax)
...
Code starting with the faulting instruction
===========================================
0: 48 3d 01 f0 ff ff cmp $0xfffffffffffff001,%rax
6: 0f 83 db 59 00 00 jae 0x59e7
c: c3 ret
d: 66 data16
e: 2e cs
f: 0f .byte 0xf
10: 1f (bad)
11: 84 00 test %al,(%rax)
13: 00 00 add %al,(%rax)
The kernel config and materials to reproduce are available at:
https://download.01.org/0day-ci/archive/20250630/202506300447.102c9e45-lkp@intel.com
--
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests/wiki
^ permalink raw reply [flat|nested] 3+ messages in thread
* Re: [linus:master] [locking/lockdep] de4b59d652: BUG:KASAN:slab-use-after-free_in_raw_spin_lock_irq
2025-06-30 2:34 [linus:master] [locking/lockdep] de4b59d652: BUG:KASAN:slab-use-after-free_in_raw_spin_lock_irq kernel test robot
@ 2025-06-30 4:13 ` Waiman Long
2025-06-30 5:32 ` Waiman Long
0 siblings, 1 reply; 3+ messages in thread
From: Waiman Long @ 2025-06-30 4:13 UTC (permalink / raw)
To: kernel test robot
Cc: oe-lkp, lkp, linux-kernel, Ingo Molnar, Marco Elver, Boqun Feng,
Andrey Konovalov
On 6/29/25 10:34 PM, kernel test robot wrote:
>
> Hello,
>
> kernel test robot noticed "BUG:KASAN:slab-use-after-free_in_raw_spin_lock_irq" on:
>
> commit: de4b59d652646cf00cf632174348ca2266099edc ("locking/lockdep: Add kasan_check_byte() check in lock_acquire()")
> https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
I don't believe commit de4b59d65264 ("locking/lockdep: Add
kasan_check_byte() check in lock_acquire()") is the cause of the KASAN
error. The previous commit ee57ab5a3212 ("locking/lockdep: Disable KASAN
instrumentation of lockdep.c") explicitly disables KASAN instrumentation
to improve lockdep performance. If bisection happens to land in between
these two commits, the bisection algorithm can incorrectly think commit
de4b59d65264 is the culprit.
Anyway, it is the caller of the spin_lock_irq() that passes in a lock
pointer that are in a memory area that has been freed. In this
particular case, kmod_dup_request_exists_wait() is handling a duplicated
kmod_req returned by kmod_dup_request_lookup(). The duplicated kmod_req
has been freed somehow.
Cheers,
Longman
>
> [test failed on linus/master afa9a6f4f5744d907954f5b708d76c9bffa43234]
> [test failed on linux-next/master 2aeda9592360c200085898a258c4754bfe879921]
>
> in testcase: trinity
> version:
> with following parameters:
>
> runtime: 600s
>
>
> config: x86_64-randconfig-104-20250415
> 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)
>
>
> the issue does not always happen. 23 times out of 142 runs as below.
> parent keeps clean.
>
>
> ee57ab5a32129f59 de4b59d652646cf00cf63217434
> ---------------- ---------------------------
> fail:runs %reproduction fail:runs
> | | |
> :142 16% 23:142 dmesg.BUG:KASAN:slab-use-after-free_in_raw_spin_lock_irq
>
>
> 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/202506300447.102c9e45-lkp@intel.com
>
>
> [ 154.326222][ T1658] BUG: KASAN: slab-use-after-free in _raw_spin_lock_irq (include/linux/spinlock_api_smp.h:120 kernel/locking/spinlock.c:170)
> [ 154.327485][ T1658] Read of size 1 at addr ffff888101655868 by task trinity-c3/1658
> [ 154.328688][ T1658]
> [ 154.329089][ T1658] CPU: 0 UID: 536870912 PID: 1658 Comm: trinity-c3 Tainted: G T 6.14.0-rc5-00228-gde4b59d65264 #1
> [ 154.330915][ T1658] Tainted: [T]=RANDSTRUCT
> [ 154.331547][ T1658] Call Trace:
> [ 154.332090][ T1658] <TASK>
> [ 154.332553][ T1658] dump_stack_lvl (lib/dump_stack.c:123)
> [ 154.333291][ T1658] print_address_description+0x8a/0x34b
> [ 154.334384][ T1658] print_report (mm/kasan/report.c:522)
> [ 154.335159][ T1658] ? __virt_addr_valid (arch/x86/mm/physaddr.c:66)
> [ 154.335979][ T1658] ? _raw_spin_lock_irq (include/linux/spinlock_api_smp.h:120 kernel/locking/spinlock.c:170)
> [ 154.336775][ T1658] kasan_report (mm/kasan/report.c:636)
> [ 154.337475][ T1658] ? _raw_spin_lock_irq (include/linux/spinlock_api_smp.h:120 kernel/locking/spinlock.c:170)
> [ 154.338283][ T1658] ? _raw_spin_lock_irq (include/linux/spinlock_api_smp.h:120 kernel/locking/spinlock.c:170)
> [ 154.339112][ T1658] ? __wait_for_common (kernel/sched/completion.c:84 kernel/sched/completion.c:116)
> [ 154.339920][ T1658] __kasan_check_byte (mm/kasan/common.c:561)
> [ 154.340707][ T1658] lock_acquire (include/trace/events/lock.h:24 include/trace/events/lock.h:24 kernel/locking/lockdep.c:5829)
> [ 154.341554][ T1658] ? pci_mmcfg_reserved (kernel/sched/core.c:6646)
> [ 154.342337][ T1658] ? __sanitizer_cov_trace_pc (kernel/kcov.c:217)
> [ 154.343252][ T1658] ? irq_trace (kernel/trace/trace_irqsoff.c:59 (discriminator 6))
> [ 154.343968][ T1658] ? write_comp_data (kernel/kcov.c:246)
> [ 154.344741][ T1658] ? usleep_range_state (kernel/time/sleep_timeout.c:62)
> [ 154.345597][ T1658] _raw_spin_lock_irq (include/linux/spinlock_api_smp.h:120 kernel/locking/spinlock.c:170)
> [ 154.346429][ T1658] ? __wait_for_common (kernel/sched/completion.c:84 kernel/sched/completion.c:116)
> [ 154.347266][ T1658] __wait_for_common (kernel/sched/completion.c:84 kernel/sched/completion.c:116)
> [ 154.348111][ T1658] ? _printk (kernel/printk/printk.c:2452)
> [ 154.348825][ T1658] ? out_of_line_wait_on_bit_lock (kernel/sched/completion.c:110)
> [ 154.349775][ T1658] wait_for_completion_state (kernel/sched/completion.c:268)
> [ 154.350731][ T1658] kmod_dup_request_exists_wait (kernel/module/dups.c:210)
> [ 154.351725][ T1658] ? inet_create (net/ipv4/af_inet.c:1382)
> [ 154.352749][ T1658] __request_module (kernel/module/kmod.c:167)
> [ 154.353587][ T1658] ? free_modprobe_argv (kernel/module/kmod.c:132)
> [ 154.354406][ T1658] ? mark_lock (kernel/locking/lockdep.c:4726 (discriminator 3))
> [ 154.355134][ T1658] ? __lock_acquire (kernel/locking/lockdep.c:5235)
> [ 154.355920][ T1658] ? rcu_read_unlock (include/linux/rcupdate.h:347 include/linux/rcupdate.h:880)
> [ 154.356711][ T1658] ? kvm_sched_clock_read (arch/x86/kernel/kvmclock.c:91)
> [ 154.357535][ T1658] ? local_clock_noinstr (kernel/sched/clock.c:301)
> [ 154.358370][ T1658] ? __lock_release+0xc0/0x16f
> [ 154.358993][ T1658] ? inet_create (net/ipv4/af_inet.c:1382)
> [ 154.359749][ T1658] inet_create (net/ipv4/af_inet.c:1382)
> [ 154.360375][ T1658] ? kvm_sched_clock_read (arch/x86/kernel/kvmclock.c:91)
> [ 154.360824][ T1658] inet_create (net/ipv4/af_inet.c:266)
> [ 154.361197][ T1658] ? rcu_read_unlock (include/linux/rcupdate.h:878)
> [ 154.361659][ T1658] __sock_create (net/socket.c:1549)
> [ 154.362058][ T1658] __sys_socket_create (net/socket.c:1644)
> [ 154.362599][ T1658] ? sock_create (net/socket.c:1629)
> [ 154.363222][ T1658] ? rcu_read_unlock (include/linux/rcupdate.h:347 include/linux/rcupdate.h:880)
> [ 154.363796][ T1658] __sys_socket (net/socket.c:1692)
> [ 154.364376][ T1658] __x64_sys_socket (net/socket.c:1702)
> [ 154.364848][ T1658] do_syscall_64 (arch/x86/entry/common.c:52 arch/x86/entry/common.c:83)
> [ 154.365258][ T1658] ? lockdep_hardirqs_on_prepare (kernel/locking/lockdep.c:4663)
> [ 154.366074][ T1658] ? syscall_exit_to_user_mode (include/linux/entry-common.h:362 kernel/entry/common.c:220)
> [ 154.366845][ T1658] ? do_syscall_64 (arch/x86/entry/common.c:102)
> [ 154.367412][ T1658] ? rcu_read_unlock (include/linux/rcupdate.h:347 include/linux/rcupdate.h:880)
> [ 154.367834][ T1658] ? kvm_sched_clock_read (arch/x86/kernel/kvmclock.c:91)
> [ 154.368274][ T1658] ? local_clock_noinstr (kernel/sched/clock.c:301)
> [ 154.368702][ T1658] ? local_clock (arch/x86/include/asm/preempt.h:84 kernel/sched/clock.c:316)
> [ 154.369074][ T1658] ? __lock_release+0xc0/0x16f
> [ 154.369792][ T1658] ? __sanitizer_cov_trace_pc (kernel/kcov.c:217)
> [ 154.370652][ T1658] ? __sanitizer_cov_trace_pc (kernel/kcov.c:217)
> [ 154.371504][ T1658] ? irq_trace (kernel/trace/trace_irqsoff.c:59 (discriminator 6))
> [ 154.372218][ T1658] ? write_comp_data (kernel/kcov.c:246)
> [ 154.372976][ T1658] ? tracer_hardirqs_on (kernel/trace/trace_irqsoff.c:630)
> [ 154.373837][ T1658] ? lockdep_hardirqs_on_prepare (kernel/locking/lockdep.c:4663)
> [ 154.374908][ T1658] ? syscall_exit_to_user_mode (include/linux/entry-common.h:362 kernel/entry/common.c:220)
> [ 154.375824][ T1658] ? do_syscall_64 (arch/x86/entry/common.c:102)
> [ 154.376619][ T1658] ? __sanitizer_cov_trace_pc (kernel/kcov.c:217)
> [ 154.377531][ T1658] ? __sanitizer_cov_trace_pc (kernel/kcov.c:217)
> [ 154.378445][ T1658] ? irq_trace (kernel/trace/trace_irqsoff.c:59 (discriminator 6))
> [ 154.379157][ T1658] ? write_comp_data (kernel/kcov.c:246)
> [ 154.379923][ T1658] ? tracer_hardirqs_on (kernel/trace/trace_irqsoff.c:630)
> [ 154.380723][ T1658] ? lockdep_hardirqs_on_prepare (kernel/locking/lockdep.c:4663)
> [ 154.381723][ T1658] ? syscall_exit_to_user_mode (include/linux/entry-common.h:362 kernel/entry/common.c:220)
> [ 154.382608][ T1658] ? do_syscall_64 (arch/x86/entry/common.c:102)
> [ 154.383220][ T1658] ? rcu_read_unlock (include/linux/rcupdate.h:347 include/linux/rcupdate.h:880)
> [ 154.383811][ T1658] ? kvm_sched_clock_read (arch/x86/kernel/kvmclock.c:91)
> [ 154.384524][ T1658] ? local_clock_noinstr (kernel/sched/clock.c:301)
> [ 154.385261][ T1658] ? local_clock (arch/x86/include/asm/preempt.h:84 kernel/sched/clock.c:316)
> [ 154.385979][ T1658] ? __lock_release+0xc0/0x16f
> [ 154.386876][ T1658] ? __sanitizer_cov_trace_pc (kernel/kcov.c:217)
> [ 154.387784][ T1658] ? __sanitizer_cov_trace_pc (kernel/kcov.c:217)
> [ 154.388666][ T1658] ? irq_trace (kernel/trace/trace_irqsoff.c:59 (discriminator 6))
> [ 154.389383][ T1658] ? write_comp_data (kernel/kcov.c:246)
> [ 154.390168][ T1658] ? tracer_hardirqs_on (kernel/trace/trace_irqsoff.c:630)
> [ 154.390997][ T1658] ? lockdep_hardirqs_on_prepare (kernel/locking/lockdep.c:4663)
> [ 154.392108][ T1658] ? syscall_exit_to_user_mode (include/linux/entry-common.h:362 kernel/entry/common.c:220)
> [ 154.393047][ T1658] ? clear_bhb_loop (arch/x86/entry/entry_64.S:1538)
> [ 154.393829][ T1658] ? clear_bhb_loop (arch/x86/entry/entry_64.S:1538)
> [ 154.394600][ T1658] ? clear_bhb_loop (arch/x86/entry/entry_64.S:1538)
> [ 154.395191][ T1658] ? clear_bhb_loop (arch/x86/entry/entry_64.S:1538)
> [ 154.395845][ T1658] entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:130)
> [ 154.396678][ T1658] RIP: 0033:0x463519
> [ 154.397279][ T1658] Code: 00 f3 c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 0f 83 db 59 00 00 c3 66 2e 0f 1f 84 00 00 00 00
> All code
> ========
> 0: 00 f3 add %dh,%bl
> 2: c3 ret
> 3: 66 2e 0f 1f 84 00 00 cs nopw 0x0(%rax,%rax,1)
> a: 00 00 00
> d: 0f 1f 40 00 nopl 0x0(%rax)
> 11: 48 89 f8 mov %rdi,%rax
> 14: 48 89 f7 mov %rsi,%rdi
> 17: 48 89 d6 mov %rdx,%rsi
> 1a: 48 89 ca mov %rcx,%rdx
> 1d: 4d 89 c2 mov %r8,%r10
> 20: 4d 89 c8 mov %r9,%r8
> 23: 4c 8b 4c 24 08 mov 0x8(%rsp),%r9
> 28: 0f 05 syscall
> 2a:* 48 3d 01 f0 ff ff cmp $0xfffffffffffff001,%rax <-- trapping instruction
> 30: 0f 83 db 59 00 00 jae 0x5a11
> 36: c3 ret
> 37: 66 data16
> 38: 2e cs
> 39: 0f .byte 0xf
> 3a: 1f (bad)
> 3b: 84 00 test %al,(%rax)
> 3d: 00 00 add %al,(%rax)
> ...
>
> Code starting with the faulting instruction
> ===========================================
> 0: 48 3d 01 f0 ff ff cmp $0xfffffffffffff001,%rax
> 6: 0f 83 db 59 00 00 jae 0x59e7
> c: c3 ret
> d: 66 data16
> e: 2e cs
> f: 0f .byte 0xf
> 10: 1f (bad)
> 11: 84 00 test %al,(%rax)
> 13: 00 00 add %al,(%rax)
>
>
> The kernel config and materials to reproduce are available at:
> https://download.01.org/0day-ci/archive/20250630/202506300447.102c9e45-lkp@intel.com
>
>
>
^ permalink raw reply [flat|nested] 3+ messages in thread
* Re: [linus:master] [locking/lockdep] de4b59d652: BUG:KASAN:slab-use-after-free_in_raw_spin_lock_irq
2025-06-30 4:13 ` Waiman Long
@ 2025-06-30 5:32 ` Waiman Long
0 siblings, 0 replies; 3+ messages in thread
From: Waiman Long @ 2025-06-30 5:32 UTC (permalink / raw)
To: kernel test robot
Cc: oe-lkp, lkp, linux-kernel, Ingo Molnar, Marco Elver, Boqun Feng,
Andrey Konovalov
On 6/30/25 12:13 AM, Waiman Long wrote:
> On 6/29/25 10:34 PM, kernel test robot wrote:
>>
>> Hello,
>>
>> kernel test robot noticed
>> "BUG:KASAN:slab-use-after-free_in_raw_spin_lock_irq" on:
>>
>> commit: de4b59d652646cf00cf632174348ca2266099edc ("locking/lockdep:
>> Add kasan_check_byte() check in lock_acquire()")
>> https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
>
> I don't believe commit de4b59d65264 ("locking/lockdep: Add
> kasan_check_byte() check in lock_acquire()") is the cause of the KASAN
> error. The previous commit ee57ab5a3212 ("locking/lockdep: Disable
> KASAN instrumentation of lockdep.c") explicitly disables KASAN
> instrumentation to improve lockdep performance. If bisection happens
> to land in between these two commits, the bisection algorithm can
> incorrectly think commit de4b59d65264 is the culprit.
>
> Anyway, it is the caller of the spin_lock_irq() that passes in a lock
> pointer that are in a memory area that has been freed. In this
> particular case, kmod_dup_request_exists_wait() is handling a
> duplicated kmod_req returned by kmod_dup_request_lookup(). The
> duplicated kmod_req has been freed somehow.
>
> Cheers,
> Longman
>
>
>
>>
>> [test failed on linus/master afa9a6f4f5744d907954f5b708d76c9bffa43234]
>> [test failed on linux-next/master
>> 2aeda9592360c200085898a258c4754bfe879921]
>>
>> in testcase: trinity
>> version:
>> with following parameters:
>>
>> runtime: 600s
>>
>>
>> config: x86_64-randconfig-104-20250415
>> 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)
>>
>>
>> the issue does not always happen. 23 times out of 142 runs as below.
>> parent keeps clean.
>>
>>
>> ee57ab5a32129f59 de4b59d652646cf00cf63217434
>> ---------------- ---------------------------
>> fail:runs %reproduction fail:runs
>> | | |
>> :142 16% 23:142
>> dmesg.BUG:KASAN:slab-use-after-free_in_raw_spin_lock_irq
>>
>>
>> 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/202506300447.102c9e45-lkp@intel.com
>>
>>
>> [ 154.326222][ T1658] BUG: KASAN: slab-use-after-free in
>> _raw_spin_lock_irq (include/linux/spinlock_api_smp.h:120
>> kernel/locking/spinlock.c:170)
>> [ 154.327485][ T1658] Read of size 1 at addr ffff888101655868 by
>> task trinity-c3/1658
>> [ 154.328688][ T1658]
>> [ 154.329089][ T1658] CPU: 0 UID: 536870912 PID: 1658 Comm:
>> trinity-c3 Tainted: G T 6.14.0-rc5-00228-gde4b59d65264 #1
>> [ 154.330915][ T1658] Tainted: [T]=RANDSTRUCT
>> [ 154.331547][ T1658] Call Trace:
>> [ 154.332090][ T1658] <TASK>
>> [ 154.332553][ T1658] dump_stack_lvl (lib/dump_stack.c:123)
>> [ 154.333291][ T1658] print_address_description+0x8a/0x34b
>> [ 154.334384][ T1658] print_report (mm/kasan/report.c:522)
>> [ 154.335159][ T1658] ? __virt_addr_valid (arch/x86/mm/physaddr.c:66)
>> [ 154.335979][ T1658] ? _raw_spin_lock_irq
>> (include/linux/spinlock_api_smp.h:120 kernel/locking/spinlock.c:170)
>> [ 154.336775][ T1658] kasan_report (mm/kasan/report.c:636)
>> [ 154.337475][ T1658] ? _raw_spin_lock_irq
>> (include/linux/spinlock_api_smp.h:120 kernel/locking/spinlock.c:170)
>> [ 154.338283][ T1658] ? _raw_spin_lock_irq
>> (include/linux/spinlock_api_smp.h:120 kernel/locking/spinlock.c:170)
>> [ 154.339112][ T1658] ? __wait_for_common
>> (kernel/sched/completion.c:84 kernel/sched/completion.c:116)
>> [ 154.339920][ T1658] __kasan_check_byte (mm/kasan/common.c:561)
>> [ 154.340707][ T1658] lock_acquire (include/trace/events/lock.h:24
>> include/trace/events/lock.h:24 kernel/locking/lockdep.c:5829)
>> [ 154.341554][ T1658] ? pci_mmcfg_reserved (kernel/sched/core.c:6646)
>> [ 154.342337][ T1658] ? __sanitizer_cov_trace_pc (kernel/kcov.c:217)
>> [ 154.343252][ T1658] ? irq_trace (kernel/trace/trace_irqsoff.c:59
>> (discriminator 6))
>> [ 154.343968][ T1658] ? write_comp_data (kernel/kcov.c:246)
>> [ 154.344741][ T1658] ? usleep_range_state
>> (kernel/time/sleep_timeout.c:62)
>> [ 154.345597][ T1658] _raw_spin_lock_irq
>> (include/linux/spinlock_api_smp.h:120 kernel/lockinspinlock.c:170)
>> [ 154.346429][ T1658] ? __wait_for_common
>> (kernel/sched/completion.c:84 kernel/sched/completion.c:116)
>> [ 154.347266][ T1658] __wait_for_common (kernel/sched/completion.c:84
>> kernel/sched/completion.c:116)
Taking a deeper look in __wait_for_common():
94 raw_spin_unlock_irq(&x->wait.lock);
95 timeout = action(timeout);
96 raw_spin_lock_irq(&x->wait.lock);
The raw_spin_lock_irq() call before calling __wait_for_common() is OK.
So the memory free likely happens after the unlock in the action() call
here. After that, the raw_spin_lock_irq() call hits the KASAN bug.
Cheers,
Longman
>> [ 154.348111][ T1658] ? _printk (kernel/printk/printk.c:2452)
>> [ 154.348825][ T1658] ? out_of_line_wait_on_bit_lock
>> (kernel/sched/completion.c:110)
>> [ 154.349775][ T1658] wait_for_completion_state
>> (kernel/sched/completion.c:268)
>> [ 154.350731][ T1658] kmod_dup_request_exists_wait
>> (kernel/module/dups.c:210)
>> [ 154.351725][ T1658] ? inet_create (net/ipv4/af_inet.c:1382)
>> [ 154.352749][ T1658] __request_module (kernel/module/kmod.c:167)
>> [ 154.353587][ T1658] ? free_modprobe_argv (kernel/module/kmod.c:132)
>> [ 154.354406][ T1658] ? mark_lock (kernel/locking/lockdep.c:4726
>> (discriminator 3))
>> [ 154.355134][ T1658] ? __lock_acquire (kernel/locking/lockdep.c:5235)
>> [ 154.355920][ T1658] ? rcu_read_unlock (include/linux/rcupdate.h:347
>> include/linux/rcupdate.h:880)
>> [ 154.356711][ T1658] ? kvm_sched_clock_read
>> (arch/x86/kernel/kvmclock.c:91)
>> [ 154.357535][ T1658] ? local_clock_noinstr (kernel/sched/clock.c:301)
>> [ 154.358370][ T1658] ? __lock_release+0xc0/0x16f
>> [ 154.358993][ T1658] ? inet_create (net/ipv4/af_inet.c:1382)
>> [ 154.359749][ T1658] inet_create (net/ipv4/af_inet.c:1382)
>> [ 154.360375][ T1658] ? kvm_sched_clock_read
>> (arch/x86/kernel/kvmclock.c:91)
>> [ 154.360824][ T1658] inet_create (net/ipv4/af_inet.c:266)
>> [ 154.361197][ T1658] ? rcu_read_unlock (include/linux/rcupdate.h:878)
>> [ 154.361659][ T1658] __sock_create (net/socket.c:1549)
>> [ 154.362058][ T1658] __sys_socket_create (net/socket.c:1644)
>> [ 154.362599][ T1658] ? sock_create (net/socket.c:1629)
>> [ 154.363222][ T1658] ? rcu_read_unlock (include/linux/rcupdate.h:347
>> include/linux/rcupdate.h:880)
>> [ 154.363796][ T1658] __sys_socket (net/socket.c:1692)
>> [ 154.364376][ T1658] __x64_sys_socket (net/socket.c:1702)
>> [ 154.364848][ T1658] do_syscall_64 (arch/x86/entry/common.c:52
>> arch/x86/entry/common.c:83)
>> [ 154.365258][ T1658] ? lockdep_hardirqs_on_prepare
>> (kernel/locking/lockdep.c:4663)
>> [ 154.366074][ T1658] ? syscall_exit_to_user_mode
>> (include/linux/entry-common.h:362 kernel/entry/common.c:220)
>> [ 154.366845][ T1658] ? do_syscall_64 (arch/x86/entry/common.c:102)
>> [ 154.367412][ T1658] ? rcu_read_unlock (include/linux/rcupdate.h:347
>> include/linux/rcupdate.h:880)
>> [ 154.367834][ T1658] ? kvm_sched_clock_read
>> (arch/x86/kernel/kvmclock.c:91)
>> [ 154.368274][ T1658] ? local_clock_noinstr (kernel/sched/clock.c:301)
>> [ 154.368702][ T1658] ? local_clock
>> (arch/x86/include/asm/preempt.h:84 kernel/sched/clock.c:316)
>> [ 154.369074][ T1658] ? __lock_release+0xc0/0x16f
>> [ 154.369792][ T1658] ? __sanitizer_cov_trace_pc (kernel/kcov.c:217)
>> [ 154.370652][ T1658] ? __sanitizer_cov_trace_pc (kernel/kcov.c:217)
>> [ 154.371504][ T1658] ? irq_trace (kernel/trace/trace_irqsoff.c:59
>> (discriminator 6))
>> [ 154.372218][ T1658] ? write_comp_data (kernel/kcov.c:246)
>> [ 154.372976][ T1658] ? tracer_hardirqs_on
>> (kernel/trace/trace_irqsoff.c:630)
>> [ 154.373837][ T1658] ? lockdep_hardirqs_on_prepare
>> (kernel/locking/lockdep.c:4663)
>> [ 154.374908][ T1658] ? syscall_exit_to_user_mode
>> (include/linux/entry-common.h:362 kernel/entry/common.c:220)
>> [ 154.375824][ T1658] ? do_syscall_64 (arch/x86/entry/common.c:102)
>> [ 154.376619][ T1658] ? __sanitizer_cov_trace_pc (kernel/kcov.c:217)
>> [ 154.377531][ T1658] ? __sanitizer_cov_trace_pc (kernel/kcov.c:217)
>> [ 154.378445][ T1658] ? irq_trace (kernel/trace/trace_irqsoff.c:59
>> (discriminator 6))
>> [ 154.379157][ T1658] ? write_comp_data (kernel/kcov.c:246)
>> [ 154.379923][ T1658] ? tracer_hardirqs_on
>> (kernel/trace/trace_irqsoff.c:630)
>> [ 154.380723][ T1658] ? lockdep_hardirqs_on_prepare
>> (kernel/locking/lockdep.c:4663)
>> [ 154.381723][ T1658] ? syscall_exit_to_user_mode
>> (include/linux/entry-common.h:362 kernel/entry/common.c:220)
>> [ 154.382608][ T1658] ? do_syscall_64 (arch/x86/entry/common.c:102)
>> [ 154.383220][ T1658] ? rcu_read_unlock (include/linux/rcupdate.h:347
>> include/linux/rcupdate.h:880)
>> [ 154.383811][ T1658] ? kvm_sched_clock_read
>> (arch/x86/kernel/kvmclock.c:91)
>> [ 154.384524][ T1658] ? local_clock_noinstr (kernel/sched/clock.c:301)
>> [ 154.385261][ T1658] ? local_clock
>> (arch/x86/include/asm/preempt.h:84 kernel/sched/clock.c:316)
>> [ 154.385979][ T1658] ? __lock_release+0xc0/0x16f
>> [ 154.386876][ T1658] ? __sanitizer_cov_trace_pc (kernel/kcov.c:217)
>> [ 154.387784][ T1658] ? __sanitizer_cov_trace_pc (kernel/kcov.c:217)
>> [ 154.388666][ T1658] ? irq_trace (kernel/trace/trace_irqsoff.c:59
>> (discriminator 6))
>> [ 154.389383][ T1658] ? write_comp_data (kernel/kcov.c:246)
>> [ 154.390168][ T1658] ? tracer_hardirqs_on
>> (kernel/trace/trace_irqsoff.c:630)
>> [ 154.390997][ T1658] ? lockdep_hardirqs_on_prepare
>> (kernel/locking/lockdep.c:4663)
>> [ 154.392108][ T1658] ? syscall_exit_to_user_mode
>> (include/linux/entry-common.h:362 kernel/entry/common.c:220)
>> [ 154.393047][ T1658] ? clear_bhb_loop (arch/x86/entry/entry_64.S:1538)
>> [ 154.393829][ T1658] ? clear_bhb_loop (arch/x86/entry/entry_64.S:1538)
>> [ 154.394600][ T1658] ? clear_bhb_loop (arch/x86/entry/entry_64.S:1538)
>> [ 154.395191][ T1658] ? clear_bhb_loop (arch/x86/entry/entry_64.S:1538)
>> [ 154.395845][ T1658] entry_SYSCALL_64_after_hwframe
>> (arch/x86/entry/entry_64.S:130)
>> [ 154.396678][ T1658] RIP: 0033:0x463519
>> [ 154.397279][ T1658] Code: 00 f3 c3 66 2e 0f 1f 84 00 00 00 00 00 0f
>> 1f 40 00 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b
>> 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 0f 83 db 59 00 00 c3 66 2e 0f 1f
>> 84 00 00 00 00
>> All code
>> ========
>> 0: 00 f3 add %dh,%bl
>> 2: c3 ret
>> 3: 66 2e 0f 1f 84 00 00 cs nopw 0x0(%rax,%rax,1)
>> a: 00 00 00
>> d: 0f 1f 40 00 nopl 0x0(%rax)
>> 11: 48 89 f8 mov %rdi,%rax
>> 14: 48 89 f7 mov %rsi,%rdi
>> 17: 48 89 d6 mov %rdx,%rsi
>> 1a: 48 89 ca mov %rcx,%rdx
>> 1d: 4d 89 c2 mov %r8,%r10
>> 20: 4d 89 c8 mov %r9,%r8
>> 23: 4c 8b 4c 24 08 mov 0x8(%rsp),%r9
>> 28: 0f 05 syscall
>> 2a:* 48 3d 01 f0 ff ff cmp
>> $0xfffffffffffff001,%rax <-- trapping instruction
>> 30: 0f 83 db 59 00 00 jae 0x5a11
>> 36: c3 ret
>> 37: 66 data16
>> 38: 2e cs
>> 39: 0f .byte 0xf
>> 3a: 1f (bad)
>> 3b: 84 00 test %al,(%rax)
>> 3d: 00 00 add %al,(%rax)
>> ...
>>
>> Code starting with the faulting instruction
>> ===========================================
>> 0: 48 3d 01 f0 ff ff cmp $0xfffffffffffff001,%rax
>> 6: 0f 83 db 59 00 00 jae 0x59e7
>> c: c3 ret
>> d: 66 data16
>> e: 2e cs
>> f: 0f .byte 0xf
>> 10: 1f (bad)
>> 11: 84 00 test %al,(%rax)
>> 13: 00 00 add %al,(%rax)
>>
>>
>> The kernel config and materials to reproduce are available at:
>> https://download.01.org/0day-ci/archive/20250630/202506300447.102c9e45-lkp@intel.com
>>
>>
>>
>>
^ permalink raw reply [flat|nested] 3+ messages in thread
end of thread, other threads:[~2025-06-30 5:33 UTC | newest]
Thread overview: 3+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2025-06-30 2:34 [linus:master] [locking/lockdep] de4b59d652: BUG:KASAN:slab-use-after-free_in_raw_spin_lock_irq kernel test robot
2025-06-30 4:13 ` Waiman Long
2025-06-30 5:32 ` Waiman Long
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.