Message-Id: <20231116123016.140576-1-naresh.kamboju@linaro.org>
Date:   Thu, 16 Nov 2023 18:00:16 +0530
From:   Naresh Kamboju <naresh.kamboju@...aro.org>
To:     linux-trace-kernel@...r.kernel.org, linux-kernel@...r.kernel.org
Cc:     mhiramat@...nel.org, mark.rutland@....com, rostedt@...dmis.org,
        lkft@...aro.org
Subject: selftests: ftrace: WARNING: __list_del_entry_valid_or_report (lib/list_debug.c:62 (discriminator 1))

Following kernel crash noticed while running selftests: ftrace on arm64 Juno-r2
device running stable-rc linux-6.6.y kernel.

This kernel crash is hard to reproduce.

Reported-by: Linux Kernel Functional Testing <lkft@...aro.org>

kselftest: Running tests in ftrace
TAP version 13
1..1
# timeout set to 0
# selftests: ftrace: ftracetest-ktap
# unlink: cannot unlink '/opt/kselftests/default-in-kernel/ftrace/logs/latest': No such file or directory
# TAP version 13
# 1..130
# ok 1 Basic trace file check
...
# ok 44 ftrace - test for function traceon/off triggers
# ok 45 ftrace - test tracing error log support
[  617.613901] ------------[ cut here ]------------
[  617.618870] list_del corruption. prev->next should be ffff000837184758, but was ffff000837184638. (prev=ffff0008359f82e8)
[  617.629894] WARNING: CPU: 1 PID: 13512 at lib/list_debug.c:62 __list_del_entry_valid_or_report (lib/list_debug.c:62 (discriminator 1)) 
[  617.639496] Modules linked in: onboard_usb_hub hdlcd tda998x crct10dif_ce drm_dma_helper cec drm_kms_helper fuse drm backlight dm_mod ip_tables x_tables [last unloaded: trace_printk]
[  617.655832] CPU: 1 PID: 13512 Comm: ls Not tainted 6.6.2-rc1 #1
[  617.661765] Hardware name: ARM Juno development board (r2) (DT)
[  617.667692] pstate: 60000005 (nZCv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--)
[  617.674668] pc : __list_del_entry_valid_or_report (lib/list_debug.c:62 (discriminator 1)) 
[  617.680339] lr : __list_del_entry_valid_or_report (lib/list_debug.c:62 (discriminator 1)) 
[  617.686009] sp : ffff80008507b910
[  617.689325] x29: ffff80008507b910 x28: 0000000000000003 x27: 0000000000000001
[  617.696482] x26: ffff000834694788 x25: ffff000835a39c88 x24: 0000000000000000
[  617.703637] x23: 0000000000000000 x22: ffff0008359f8248 x21: ffff000837184720
[  617.710792] x20: ffff0008359f8248 x19: ffff000837184758 x18: 0000000000000010
[  617.717948] x17: 20747562202c3835 x16: 3734383137333830 x15: 3030666666662065
[  617.725102] x14: 6220646c756f6873 x13: 2938653238663935 x12: 3338303030666666
[  617.732257] x11: 663d766572702820 x10: 2e38333634383137 x9 : ffff800080145634
[  617.739411] x8 : ffff80008507b638 x7 : 0000000000017fe8 x6 : 0000000000057fa8
[  617.746566] x5 : 0000000000000fff x4 : ffff00097ed27d50 x3 : ffff8008fc5d3000
[  617.753720] x2 : 0000000000000000 x1 : 0000000000000000 x0 : ffff0008010722c0
[  617.760874] Call trace:
[  617.763320] __list_del_entry_valid_or_report (lib/list_debug.c:62 (discriminator 1)) 
[  617.768643] __dentry_kill (include/linux/list.h:215 (discriminator 1) fs/dcache.c:550 (discriminator 1) fs/dcache.c:603 (discriminator 1)) 
[  617.772311] dput (fs/dcache.c:896) 
[  617.775281] create_dentry (fs/tracefs/event_inode.c:404) 
[  617.779040] dcache_dir_open_wrapper (fs/tracefs/event_inode.c:536) 
[  617.783580] do_dentry_open (fs/open.c:929) 
[  617.787424] vfs_open (fs/open.c:1064) 
[  617.790572] path_openat (fs/namei.c:3640 fs/namei.c:3797) 
[  617.794153] do_filp_open (fs/namei.c:3824) 
[  617.797733] do_sys_openat2 (fs/open.c:1422) 
[  617.801490] __arm64_sys_openat (fs/open.c:1448) 
[  617.805508] invoke_syscall (arch/arm64/include/asm/current.h:19 arch/arm64/kernel/syscall.c:56) 
[  617.809267] el0_svc_common.constprop.0 (include/linux/thread_info.h:127 (discriminator 2) arch/arm64/kernel/syscall.c:144 (discriminator 2)) 
[  617.814069] do_el0_svc (arch/arm64/kernel/syscall.c:156) 
[  617.817391] el0_svc (arch/arm64/include/asm/daifflags.h:28 arch/arm64/kernel/entry-common.c:133 arch/arm64/kernel/entry-common.c:144 arch/arm64/kernel/entry-common.c:679) 
[  617.820454] el0t_64_sync_handler (arch/arm64/kernel/entry-common.c:697) 
[  617.824820] el0t_64_sync (arch/arm64/kernel/entry.S:595) 
[  617.828488] ---[ end trace 0000000000000000 ]---
[  617.833214] ------------[ cut here ]------------
[  617.837840] WARNING: CPU: 2 PID: 13523 at fs/dcache.c:365 dentry_free (fs/dcache.c:365 (discriminator 1)) 
[  617.845173] Modules linked in: onboard_usb_hub hdlcd tda998x crct10dif_ce drm_dma_helper cec drm_kms_helper fuse drm backlight dm_mod ip_tables x_tables [last unloaded: trace_printk]
[  617.861503] CPU: 2 PID: 13523 Comm: rmdir Tainted: G        W          6.6.2-rc1 #1
[  617.869175] Hardware name: ARM Juno development board (r2) (DT)
[  617.875102] pstate: 40000005 (nZcv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--)
[  617.882077] pc : dentry_free (fs/dcache.c:365 (discriminator 1)) 
[  617.885835] lr : __dentry_kill (fs/dcache.c:623) 
[  617.889937] sp : ffff800085123a30
[  617.893252] x29: ffff800085123a30 x28: ffff0008371845a8 x27: ffff0008371845a8
[  617.900409] x26: ffff000837184600 x25: ffff000837184638 x24: ffff0008359f82a0
[  617.907565] x23: ffff000835a39d28 x22: ffff0008359f8248 x21: ffff000837184720
[  617.914719] x20: ffff0008359f8248 x19: ffff0008371846c8 x18: 0000000000000000
[  617.921874] x17: 000000040044ffff x16: 00500074b5503510 x15: 0000000000000000
[  617.929029] x14: 0000000000000000 x13: 0000000000000030 x12: 0101010101010101
[  617.936184] x11: 7f7f7f7f7f7f7f7f x10: 0000000000000c00 x9 : ffff80008042bce0
[  617.943339] x8 : ffff800085123968 x7 : 0000000000000000 x6 : 00000000000001fb
[  617.950493] x5 : 0000000000000001 x4 : ffff80008328f000 x3 : ffff80008328f2e8
[  617.957647] x2 : 0000000000000002 x1 : ffff80008042bcd8 x0 : ffff800080428e90
[  617.964801] Call trace:
[  617.967246] dentry_free (fs/dcache.c:365 (discriminator 1)) 
[  617.970656] __dentry_kill (fs/dcache.c:623) 
[  617.974409] dput (fs/dcache.c:896) 
[  617.977380] simple_recursive_removal (include/linux/fs.h:807 fs/libfs.c:552) 
[  617.982008] eventfs_remove (fs/tracefs/event_inode.c:946) 
[  617.985679] remove_event_file_dir (include/linux/list.h:124 include/linux/list.h:215 include/linux/list.h:229 kernel/trace/trace_events.c:1017) 
[  617.989958] event_trace_del_tracer (kernel/trace/trace_events.c:3620 (discriminator 3) kernel/trace/trace_events.c:3772 (discriminator 3)) 
[  617.994324] __remove_instance (kernel/trace/trace.c:9682 kernel/trace/trace.c:9663) 
[  617.998344] instance_rmdir (kernel/trace/trace.c:9741) 
[  618.002010] tracefs_syscall_rmdir (fs/tracefs/inode.c:134) 
[  618.006289] vfs_rmdir (fs/namei.c:4204 fs/namei.c:4181) 
[  618.009608] do_rmdir (fs/namei.c:4263 (discriminator 1)) 
[  618.012928] __arm64_sys_unlinkat (fs/namei.c:4441 (discriminator 2) fs/namei.c:4435 (discriminator 2) fs/namei.c:4435 (discriminator 2)) 
[  618.017118] invoke_syscall (arch/arm64/include/asm/current.h:19 arch/arm64/kernel/syscall.c:56) 
[  618.020876] el0_svc_common.constprop.0 (include/linux/thread_info.h:127 (discriminator 2) arch/arm64/kernel/syscall.c:144 (discriminator 2)) 
[  618.025678] do_el0_svc (arch/arm64/kernel/syscall.c:156) 
[  618.029000] el0_svc (arch/arm64/include/asm/daifflags.h:28 arch/arm64/kernel/entry-common.c:133 arch/arm64/kernel/entry-common.c:144 arch/arm64/kernel/entry-common.c:679) 
[  618.032060] el0t_64_sync_handler (arch/arm64/kernel/entry-common.c:697) 
[  618.036427] el0t_64_sync (arch/arm64/kernel/entry.S:595) 
[  618.040094] ---[ end trace 0000000000000000 ]---
[  618.071010] Unable to handle kernel execute from non-executable memory at virtual address ffff000835b0b758
[  618.080715] Mem abort info:
[  618.083536]   ESR = 0x000000008600000f
[  618.087306]   EC = 0x21: IABT (current EL), IL = 32 bits
[  618.092646]   SET = 0, FnV = 0
[  618.095717]   EA = 0, S1PTW = 0
[  618.098869]   FSC = 0x0f: level 3 permission fault
[  618.103680] swapper pgtable: 4k pages, 48-bit VAs, pgdp=00000000826a6000
[  618.110405] [ffff000835b0b758] pgd=18000009ffdf8003, p4d=18000009ffdf8003, pud=18000009ffa0e003, pmd=18000009ff860003, pte=00680008b5b0b707
[  618.123000] Internal error: Oops: 000000008600000f [#1] PREEMPT SMP
[  618.129287] Modules linked in: onboard_usb_hub hdlcd tda998x crct10dif_ce drm_dma_helper cec drm_kms_helper fuse drm backlight dm_mod ip_tables x_tables [last unloaded: trace_printk]
[  618.145624] CPU: 2 PID: 13523 Comm: rmdir Tainted: G        W          6.6.2-rc1 #1
[  618.153298] Hardware name: ARM Juno development board (r2) (DT)
[  618.159225] pstate: 80000005 (Nzcv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--)
[  618.166203] pc : 0xffff000835b0b758
[  618.169703] lr : rcu_core (arch/arm64/include/asm/preempt.h:13 (discriminator 1) kernel/rcu/tree.c:2146 (discriminator 1) kernel/rcu/tree.c:2403 (discriminator 1)) 
[  618.173377] sp : ffff80008394be60
[  618.176692] x29: ffff80008394be60 x28: ffff0008278e3400 x27: 000000000000000a
[  618.183848] x26: 0000000000000000 x25: 0000000000000000 x24: ffff80008394bf10
[  618.191003] x23: ffff800082752008 x22: ffff80008328ea80 x21: ffff80008332f700
[  618.198157] x20: ffff00097ed59440 x19: 0000000000000001 x18: 0000000000000000
[  618.205311] x17: ffff8008fc5f2000 x16: ffff800083948000 x15: 0000000000000000
[  618.212468] x14: 0000000000000000 x13: 0000000000000030 x12: 00000000000163f1
[  618.219627] x11: 0000000000000001 x10: 000000010001369b x9 : ffff800080174e34
[  618.226782] x8 : ffff80008394bd98 x7 : 0000000000000000 x6 : 0000000000000100
[  618.233939] x5 : 0000000000000100 x4 : ffff80008328f000 x3 : ffff80008328f2e8
[  618.241100] x2 : 0000000000000000 x1 : ffff000835b0b758 x0 : ffff000837184778
[  618.248257] Call trace:
[  618.250707]  0xffff000835b0b758
[  618.253851] rcu_core_si (kernel/rcu/tree.c:2421) 
[  618.257261] __do_softirq (arch/arm64/include/asm/jump_label.h:21 include/linux/jump_label.h:207 include/trace/events/irq.h:142 kernel/softirq.c:554) 
[  618.260929] ____do_softirq (arch/arm64/kernel/irq.c:81) 
[  618.264597] call_on_irq_stack (arch/arm64/kernel/entry.S:892) 
[  618.268527] do_softirq_own_stack (arch/arm64/kernel/irq.c:86) 
[  618.272717] irq_exit_rcu (arch/arm64/include/asm/percpu.h:44 kernel/softirq.c:612 kernel/softirq.c:634 kernel/softirq.c:644) 
[  618.276299] el1_interrupt (arch/arm64/include/asm/current.h:19 arch/arm64/kernel/entry-common.c:246 arch/arm64/kernel/entry-common.c:505 arch/arm64/kernel/entry-common.c:517) 
[  618.279883] el1h_64_irq_handler (arch/arm64/kernel/entry-common.c:523) 
[  618.283989] el1h_64_irq (arch/arm64/kernel/entry.S:591) 
[  618.287394] __srcu_read_unlock (kernel/rcu/srcutree.c:730) 
[  618.291409] srcu_gp_start_if_needed (kernel/rcu/srcutree.c:1298) 
[  618.296034] call_srcu (kernel/rcu/srcutree.c:1362) 
[  618.299266] eventfs_remove_rec (fs/tracefs/event_inode.c:921) 
[  618.303286] eventfs_remove_rec (fs/tracefs/event_inode.c:909 (discriminator 5)) 
[  618.307303] eventfs_remove (fs/tracefs/event_inode.c:939) 
[  618.310973] remove_event_file_dir (include/linux/list.h:124 include/linux/list.h:215 include/linux/list.h:229 kernel/trace/trace_events.c:1017) 
[  618.315252] event_trace_del_tracer (kernel/trace/trace_events.c:3620 (discriminator 3) kernel/trace/trace_events.c:3772 (discriminator 3)) 
[  618.319618] __remove_instance (kernel/trace/trace.c:9682 kernel/trace/trace.c:9663) 
[  618.323637] instance_rmdir (kernel/trace/trace.c:9741) 
[  618.327304] tracefs_syscall_rmdir (fs/tracefs/inode.c:134) 
[  618.331582] vfs_rmdir (fs/namei.c:4204 fs/namei.c:4181) 
[  618.334903] do_rmdir (fs/namei.c:4263 (discriminator 1)) 
[  618.338223] __arm64_sys_unlinkat (fs/namei.c:4441 (discriminator 2) fs/namei.c:4435 (discriminator 2) fs/namei.c:4435 (discriminator 2)) 
[  618.342413] invoke_syscall (arch/arm64/include/asm/current.h:19 arch/arm64/kernel/syscall.c:56) 
[  618.346171] el0_svc_common.constprop.0 (include/linux/thread_info.h:127 (discriminator 2) arch/arm64/kernel/syscall.c:144 (discriminator 2)) 
[  618.350973] do_el0_svc (arch/arm64/kernel/syscall.c:156) 
[  618.354294] el0_svc (arch/arm64/include/asm/daifflags.h:28 arch/arm64/kernel/entry-common.c:133 arch/arm64/kernel/entry-common.c:144 arch/arm64/kernel/entry-common.c:679) 
[  618.357355] el0t_64_sync_handler (arch/arm64/kernel/entry-common.c:697) 
[  618.361721] el0t_64_sync (arch/arm64/kernel/entry.S:595) 
[ 618.365391] Code: 35b0b748 ffff0008 35b0b748 ffff0008 (37184778)
All code
========
   0:	35b0b748 	cbnz	w8, 0xfffffffffff616e8
   4:	ffff0008 	.inst	0xffff0008 ; undefined
   8:	35b0b748 	cbnz	w8, 0xfffffffffff616f0
   c:	ffff0008 	.inst	0xffff0008 ; undefined
  10:*	37184778 	tbnz	w24, #3, 0x8fc		<-- trapping instruction

Code starting with the faulting instruction
===========================================
   0:	37184778 	tbnz	w24, #3, 0x8ec
[  618.371494] ---[ end trace 0000000000000000 ]---
[  618.376117] Kernel panic - not syncing: Oops: Fatal exception in interrupt
[  618.383001] SMP: stopping secondary CPUs
[  618.387117] Kernel Offset: disabled
[  618.390607] CPU features: 0x1,0000020c,3c020000,0000421b
[  618.395927] Memory Limit: none
[  618.398986] ---[ end Kernel panic - not syncing: Oops: Fatal exception in interrupt ]---


Links:
- https://lkft.validation.linaro.org/scheduler/job/7030448#L4546

metadata:
git_ref: linux-6.6.y
git_repo: https://gitlab.com/Linaro/lkft/mirrors/stable/linux-stable-rc
git_sha: df34d612fd4ef266814366c8101094b7f83b6a92
git_describe: v6.6.1-604-gdf34d612fd4e
kernel_version: 6.6.2-rc1
kernel-config:
https://storage.tuxsuite.com/public/linaro/lkft/builds/2YE2AiHE0lU8S30LM8h9i7wempi/config
artifact-location:
https://storage.tuxsuite.com/public/linaro/lkft/builds/2YE2AiHE0lU8S30LM8h9i7wempi/
toolchain: gcc-13


--
Linaro LKFT
https://lkft.linaro.org

Powered by blists - more mailing lists