[mhiramat:topic/fprobe-on-fgraph] [function_graph] 367c724761: BUG:KASAN:slab-out-of-bounds_in_ftrace_push_return_trace

From: kernel test robot
Date: Wed Jan 17 2024 - 09:28:52 EST




Hello,

kernel test robot noticed "BUG:KASAN:slab-out-of-bounds_in_ftrace_push_return_trace" on:

commit: 367c724761b0a49e115dd3bb27e93b3905cfe05a ("function_graph: Improve push operation for several interrupts")
https://git.kernel.org/cgit/linux/kernel/git/mhiramat/linux.git topic/fprobe-on-fgraph

in testcase: ftrace-onoff
version:
with following parameters:

runtime: 5m



compiler: gcc-12
test machine: 8 threads 1 sockets Intel(R) Core(TM) i7-7700 CPU @ 3.60GHz (Kaby Lake) with 32G 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/202401172217.36e37075-oliver.sang@xxxxxxxxx


[ 43.381281][ T644] BUG: KASAN: slab-out-of-bounds in ftrace_push_return_trace+0x7e0/0x820
[ 43.390620][ T644] Write of size 8 at addr ffff888116ea1ff8 by task cat/644
[ 43.397694][ T644]
[ 43.399903][ T644] CPU: 1 PID: 644 Comm: cat Not tainted 6.7.0-rc8-00020-g367c724761b0 #1
[ 43.408197][ T644] Hardware name: Dell Inc. OptiPlex 7050/062KRH, BIOS 1.2.0 12/22/2016
[ 43.416323][ T644] Call Trace:
[ 43.419491][ T644] <TASK>
[ 43.422316][ T644] dump_stack_lvl (lib/dump_stack.c:107 (discriminator 1))
[ 43.426715][ T644] print_address_description+0x2c/0x3a0
[ 43.433196][ T644] ? ftrace_push_return_trace+0x7e0/0x820
[ 43.439857][ T644] print_report (mm/kasan/report.c:476)
[ 43.444161][ T644] ? fixup_red_left (mm/slub.c:224)
[ 43.448650][ T644] ? kasan_addr_to_slab (mm/kasan/common.c:35)
[ 43.453485][ T644] ? ftrace_push_return_trace+0x7e0/0x820
[ 43.460143][ T644] kasan_report (mm/kasan/report.c:590)
[ 43.464461][ T644] ? ftrace_push_return_trace+0x7e0/0x820
[ 43.471130][ T644] ? unwind_next_frame (arch/x86/kernel/unwind_orc.c:469)
[ 43.476040][ T644] ? arch_stack_walk (arch/x86/kernel/stacktrace.c:24)
[ 43.480689][ T644] ftrace_push_return_trace+0x7e0/0x820
[ 43.487161][ T644] ? trace_graph_entry (arch/x86/include/asm/atomic.h:60 include/linux/atomic/atomic-arch-fallback.h:1210 include/linux/atomic/atomic-instrumented.h:593 kernel/trace/trace_functions_graph.c:188)
[ 43.492173][ T644] ? unwind_next_frame (arch/x86/kernel/unwind_orc.c:469)
[ 43.497079][ T644] ? arch_stack_walk (arch/x86/kernel/stacktrace.c:24)
[ 43.501724][ T644] function_graph_enter_ops (kernel/trace/fgraph.c:702)
[ 43.507071][ T644] ? kernel_text_address (kernel/extable.c:95)
[ 43.512071][ T644] ? function_graph_enter (kernel/trace/fgraph.c:690)
[ 43.517338][ T644] ? ftrace_graph_func (arch/x86/kernel/ftrace.c:674)
[ 43.522352][ T644] ? kernel_text_address (kernel/extable.c:95)
[ 43.527372][ T644] ? unwind_next_frame (arch/x86/kernel/unwind_orc.c:469)
[ 43.532287][ T644] ftrace_graph_func (arch/x86/kernel/ftrace.c:674)
[ 43.537116][ T644] ? write_profile (kernel/stacktrace.c:83)
[ 43.541769][ T644] 0xffffffffc0478087
[ 43.545670][ T644] ? do_exit (kernel/exit.c:859)
[ 43.549799][ T644] ? unwind_next_frame (arch/x86/kernel/unwind_orc.c:471)
[ 43.554715][ T644] unwind_next_frame (arch/x86/kernel/unwind_orc.c:471)
[ 43.559444][ T644] arch_stack_walk (arch/x86/kernel/stacktrace.c:24)
[ 43.563944][ T644] ? do_exit (kernel/exit.c:859)
[ 43.568090][ T644] stack_trace_save (kernel/stacktrace.c:123)
[ 43.572653][ T644] ? filter_irq_stacks (kernel/stacktrace.c:114)
[ 43.577492][ T644] ? stack_trace_save (kernel/stacktrace.c:114)
[ 43.582148][ T644] kasan_save_stack (mm/kasan/common.c:46)
[ 43.586707][ T644] ? kasan_save_stack (mm/kasan/common.c:46)
[ 43.591436][ T644] ? kasan_set_track (mm/kasan/common.c:52)
[ 43.596081][ T644] ? kasan_save_free_info (mm/kasan/generic.c:524)
[ 43.601159][ T644] ? __kasan_slab_free (mm/kasan/common.c:238 mm/kasan/common.c:200 mm/kasan/common.c:244)
[ 43.606150][ T644] ? kmem_cache_free_bulk (mm/slub.c:4037)
[ 43.612010][ T644] ? mt_destroy_walk+0x56f/0xfd0
[ 43.617435][ T644] ? __mt_destroy (lib/maple_tree.c:5338)
[ 43.621906][ T644] ? exit_mmap (arch/x86/include/asm/jump_label.h:27 include/linux/jump_label.h:207 include/linux/mmap_lock.h:41 include/linux/mmap_lock.h:131 mm/mmap.c:3341)
[ 43.626203][ T644] ? __mmput (kernel/fork.c:1350)
[ 43.630241][ T644] ? exit_mm (kernel/exit.c:568)
[ 43.634374][ T644] ? do_exit (kernel/exit.c:859)
[ 43.638643][ T644] ? mt_destroy_walk+0x56f/0xfd0
[ 43.644071][ T644] kasan_set_track (mm/kasan/common.c:52)
[ 43.648544][ T644] kasan_save_free_info (mm/kasan/generic.c:524)
[ 43.653452][ T644] __kasan_slab_free (mm/kasan/common.c:238 mm/kasan/common.c:200 mm/kasan/common.c:244)
[ 43.658280][ T644] kmem_cache_free_bulk (mm/slub.c:4037)
[ 43.663969][ T644] ? mt_destroy_walk+0x56f/0xfd0
[ 43.669445][ T644] mt_destroy_walk+0x56f/0xfd0
[ 43.674747][ T644] __mt_destroy (lib/maple_tree.c:5338)
[ 43.679062][ T644] exit_mmap (arch/x86/include/asm/jump_label.h:27 include/linux/jump_label.h:207 include/linux/mmap_lock.h:41 include/linux/mmap_lock.h:131 mm/mmap.c:3341)
[ 43.683205][ T644] ? do_vma_munmap (mm/mmap.c:3283)
[ 43.687684][ T644] ? mutex_unlock (kernel/locking/mutex.c:538)
[ 43.692014][ T644] ? ftrace_graph_func (arch/x86/kernel/ftrace.c:674)
[ 43.697069][ T644] ? __mmput (arch/x86/include/asm/bitops.h:206 arch/x86/include/asm/bitops.h:238 include/asm-generic/bitops/instrumented-non-atomic.h:142 include/linux/khugepaged.h:38 kernel/fork.c:1348)
[ 43.701136][ T644] __mmput (kernel/fork.c:1350)
[ 43.705015][ T644] exit_mm (kernel/exit.c:568)
[ 43.708973][ T644] do_exit (kernel/exit.c:859)
[ 43.712936][ T644] ? exit_mm (kernel/exit.c:810)
[ 43.717057][ T644] ? _raw_spin_lock_irq (arch/x86/include/asm/atomic.h:115 include/linux/atomic/atomic-arch-fallback.h:2164 include/linux/atomic/atomic-instrumented.h:1296 include/asm-generic/qspinlock.h:111 include/linux/spinlock.h:187 include/linux/spinlock_api_smp.h:120 kernel/locking/spinlock.c:170)
[ 43.721969][ T644] ? _raw_spin_lock_irq (arch/x86/include/asm/atomic.h:115 include/linux/atomic/atomic-arch-fallback.h:2164 include/linux/atomic/atomic-instrumented.h:1296 include/asm-generic/qspinlock.h:111 include/linux/spinlock.h:187 include/linux/spinlock_api_smp.h:120 kernel/locking/spinlock.c:170)
[ 43.726901][ T644] do_group_exit (kernel/exit.c:999)
[ 43.731301][ T644] __x64_sys_exit_group (kernel/exit.c:1027)
[ 43.736215][ T644] do_syscall_64 (arch/x86/entry/common.c:52 arch/x86/entry/common.c:83)
[ 43.740518][ T644] entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:129)
[ 43.746293][ T644] RIP: 0033:0x7fddfe515699
[ 43.750594][ T644] Code: Unable to access opcode bytes at 0x7fddfe51566f.

Code starting with the faulting instruction
===========================================
[ 43.757492][ T644] RSP: 002b:00007fff2924edf8 EFLAGS: 00000246 ORIG_RAX: 00000000000000e7
[ 43.765794][ T644] RAX: ffffffffffffffda RBX: 00007fddfe60a610 RCX: 00007fddfe515699
[ 43.773649][ T644] RDX: 000000000000003c RSI: 00000000000000e7 RDI: 0000000000000000
[ 43.781505][ T644] RBP: 0000000000000000 R08: ffffffffffffff80 R09: 0000000000000001
[ 43.789373][ T644] R10: 00007fddfe63a1c0 R11: 0000000000000246 R12: 00007fddfe60a610
[ 43.797228][ T644] R13: 0000000000000002 R14: 00007fddfe60aae8 R15: 0000000000000000
[ 43.805145][ T644] </TASK>
[ 43.808050][ T644]
[ 43.810258][ T644] Allocated by task 478:
[ 43.814377][ T644] kasan_save_stack (mm/kasan/common.c:46)
[ 43.818934][ T644] kasan_set_track (mm/kasan/common.c:52)
[ 43.823405][ T644] __kasan_kmalloc (mm/kasan/common.c:374 mm/kasan/common.c:383)
[ 43.827877][ T644] ftrace_graph_init_task (include/linux/slab.h:600 kernel/trace/fgraph.c:1168)
[ 43.833130][ T644] copy_process (kernel/fork.c:1947 (discriminator 4) kernel/fork.c:2360 (discriminator 4))
[ 43.837599][ T644] kernel_clone (include/linux/random.h:26 kernel/fork.c:2908)
[ 43.841896][ T644] __do_sys_clone (kernel/fork.c:3039)
[ 43.846277][ T644] do_syscall_64 (arch/x86/entry/common.c:52 arch/x86/entry/common.c:83)
[ 43.850574][ T644] entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:129)
[ 43.856360][ T644]
[ 43.858566][ T644] Freed by task 0:
[ 43.862167][ T644] kasan_save_stack (mm/kasan/common.c:46)
[ 43.866723][ T644] kasan_set_track (mm/kasan/common.c:52)
[ 43.871193][ T644] kasan_save_free_info (mm/kasan/generic.c:524)
[ 43.876094][ T644] __kasan_slab_free (mm/kasan/common.c:238 mm/kasan/common.c:200 mm/kasan/common.c:244)
[ 43.880910][ T644] __kmem_cache_free (mm/slub.c:1826 mm/slub.c:3809 mm/slub.c:3822)
[ 43.885729][ T644] free_task (kernel/fork.c:623 (discriminator 3))
[ 43.889764][ T644] rcu_do_batch (arch/x86/include/asm/preempt.h:27 kernel/rcu/tree.c:2165)
[ 43.894148][ T644] rcu_core (kernel/rcu/tree.c:2433)
[ 43.898183][ T644] __do_softirq (arch/x86/include/asm/jump_label.h:27 include/linux/jump_label.h:207 include/trace/events/irq.h:142 kernel/softirq.c:554)
[ 43.902567][ T644]
[ 43.904776][ T644] The buggy address belongs to the object at ffff888116ea0000
[ 43.904776][ T644] which belongs to the cache kmalloc-4k of size 4096
[ 43.918727][ T644] The buggy address is located 4088 bytes to the right of
[ 43.918727][ T644] allocated 4096-byte region [ffff888116ea0000, ffff888116ea1000)
[ 43.933471][ T644]
[ 43.935684][ T644] The buggy address belongs to the physical page:
[ 43.941980][ T644] page:00000000206533fa refcount:1 mapcount:0 mapping:0000000000000000 index:0x0 pfn:0x116ea0
[ 43.952099][ T644] head:00000000206533fa order:3 entire_mapcount:0 nr_pages_mapped:0 pincount:0
[ 43.960911][ T644] flags: 0x17ffffc0000840(slab|head|node=0|zone=2|lastcpupid=0x1fffff)
[ 43.969032][ T644] page_type: 0xffffffff()
[ 43.973238][ T644] raw: 0017ffffc0000840 ffff88810c843040 ffffea00045ba600 0000000000000002
[ 43.981703][ T644] raw: 0000000000000000 0000000080040004 00000001ffffffff 0000000000000000
[ 43.990167][ T644] page dumped because: kasan: bad access detected
[ 43.996456][ T644]
[ 43.998663][ T644] Memory state around the buggy address:
[ 44.004172][ T644] ffff888116ea1e80: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc
[ 44.012114][ T644] ffff888116ea1f00: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc
[ 44.020056][ T644] >ffff888116ea1f80: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc
[ 44.027999][ T644] ^
[ 44.035856][ T644] ffff888116ea2000: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 44.043803][ T644] ffff888116ea2080: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 44.051747][ T644] ==================================================================
[ 44.059762][ T644] Disabling lock debugging due to kernel taint
[ 44.423837][ T312] 2024-01-15 00:33:41 echo 1 > tracing_on
[ 44.425933][ T312]
[ 45.159545][ T312] 2024-01-15 00:33:41 echo 0 > tracing_on
[ 45.159845][ T312]
[ 45.289241][ T312] 2024-01-15 00:33:41 echo wakeup_dl > current_tracer
[ 45.289643][ T312]
[ 45.735915][ T312] 2024-01-15 00:33:42 echo 1 > tracing_on
[ 45.735956][ T312]
[ 45.780233][ T312] 2024-01-15 00:33:42 echo 0 > tracing_on
[ 45.780288][ T312]
[ 45.802820][ T312] 2024-01-15 00:33:42 echo wakeup_rt > current_tracer
[ 45.802877][ T312]
[ 46.191536][ T312] 2024-01-15 00:33:42 echo 1 > tracing_on
[ 46.191576][ T312]
[ 46.227375][ T312] 2024-01-15 00:33:42 echo 0 > tracing_on
[ 46.227420][ T312]
[ 46.248058][ T312] 2024-01-15 00:33:42 echo wakeup > current_tracer
[ 46.248099][ T312]
[ 46.637161][ T312] 2024-01-15 00:33:43 echo 1 > tracing_on


The kernel config and materials to reproduce are available at:
https://download.01.org/0day-ci/archive/20240117/202401172217.36e37075-oliver.sang@xxxxxxxxx



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