Re: [PATCH v2] eventfs: Test for ei->is_freed when accessing ei->dentry

From: Naresh Kamboju
Date: Mon Oct 30 2023 - 03:07:29 EST


Hi Steven,

> Are you sure it was applied correctly?

Please ignore the build warnings / errors it was due to apply patch was
not successful.

> Perhaps check out the branch I
> have and let me know if you get the same errors.
>
> git://git.kernel.org/pub/scm/linux/kernel/git/trace/linux-trace.git trace/core

I have tested the linux-trace.git trace/core and run selftests ftrace
the reported kernel panic [1] & [2] has been fixed but found
"general protection fault" at kernel/trace/trace_events.c:2439.

[1] https://lore.kernel.org/all/CA+G9fYt6pY+tMZEOg=SoEywQOe19fGP3uR15SGowkdK+_X85Cg@xxxxxxxxxxxxxx/
[2] https://lore.kernel.org/linux-trace-kernel/20231028164650.4f5ea18a@xxxxxxxxxxxxxxxxxxxx/

Reported-by: Linux Kernel Functional Testing <lkft@xxxxxxxxxx>

Test log:
==========
kselftest: Running tests in ftrace
TAP version 13
1..1
# timeout set to 0
# selftests: ftrace: ftracetest-ktap

...

# ok 46 Test creation and deletion of trace instances while setting an event
[ 332.783872] general protection fault, probably for non-canonical
address 0x6b6b6b6b6b6b6bcb: 0000 [#1] PREEMPT SMP PTI
[ 332.794585] CPU: 1 PID: 5165 Comm: ls Not tainted 6.6.0-rc4 #1
[ 332.800429] Hardware name: Supermicro SYS-5019S-ML/X11SSH-F, BIOS
2.7 12/07/2021
[ 332.807820] RIP: 0010:event_callback (kernel/trace/trace_events.c:2439)
[ 332.812353] Code: f6 48 c7 c6 09 78 6b a0 41 55 49 89 cd 41 54 49 89
d4 53 48 8b 02 48 89 fb 4c 8b 78 10 e8 10 8b 19 01 85 c0 0f 84 d2 00
00 00 <41> 8b 47 60 a8 08 0f 85 9c 00 00 00 49 8b 47 10 48 83 78 18 00
74
All code
========
0: f6 48 c7 c6 testb $0xc6,-0x39(%rax)
4: 09 78 6b or %edi,0x6b(%rax)
7: a0 41 55 49 89 cd 41 movabs 0x495441cd89495541,%al
e: 54 49
10: 89 d4 mov %edx,%esp
12: 53 push %rbx
13: 48 8b 02 mov (%rdx),%rax
16: 48 89 fb mov %rdi,%rbx
19: 4c 8b 78 10 mov 0x10(%rax),%r15
1d: e8 10 8b 19 01 callq 0x1198b32
22: 85 c0 test %eax,%eax
24: 0f 84 d2 00 00 00 je 0xfc
2a:* 41 8b 47 60 mov 0x60(%r15),%eax <-- trapping instruction
2e: a8 08 test $0x8,%al
30: 0f 85 9c 00 00 00 jne 0xd2
36: 49 8b 47 10 mov 0x10(%r15),%rax
3a: 48 83 78 18 00 cmpq $0x0,0x18(%rax)
3f: 74 .byte 0x74

Code starting with the faulting instruction
===========================================
0: 41 8b 47 60 mov 0x60(%r15),%eax
4: a8 08 test $0x8,%al
6: 0f 85 9c 00 00 00 jne 0xa8
c: 49 8b 47 10 mov 0x10(%r15),%rax
10: 48 83 78 18 00 cmpq $0x0,0x18(%rax)
15: 74 .byte 0x74
[ 332.831089] RSP: 0018:ffffba5700967b50 EFLAGS: 00010202
[ 332.836315] RAX: 0000000000000001 RBX: ffffffffa06fb5d7 RCX: ffffba5700967bc8
[ 332.843439] RDX: 0000000000000069 RSI: ffffffffa06b7809 RDI: ffffffffa06fb5d7
[ 332.850563] RBP: ffffba5700967b78 R08: ffff8dbe12250134 R09: 0000000000000000
[ 332.857722] R10: ffff8dbe122500e0 R11: ffff8dbe0d8f8fc8 R12: ffffba5700967bd0
[ 332.864846] R13: ffffba5700967bc8 R14: ffffba5700967bc6 R15: 6b6b6b6b6b6b6b6b
[ 332.871971] FS: 00007fc5a5062d00(0000) GS:ffff8dc167a80000(0000)
knlGS:0000000000000000
[ 332.880057] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 332.885801] CR2: 00007f7f8dc50a1c CR3: 0000000113c84003 CR4: 00000000003706e0
[ 332.892928] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 332.900058] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 332.907183] Call Trace:
[ 332.909658] <TASK>
[ 332.911760] ? show_regs (arch/x86/kernel/dumpstack.c:479)
[ 332.915166] ? die_addr (arch/x86/kernel/dumpstack.c:421
arch/x86/kernel/dumpstack.c:460)
[ 332.918486] ? exc_general_protection (arch/x86/kernel/traps.c:697
arch/x86/kernel/traps.c:642)
[ 332.923191] ? asm_exc_general_protection
(arch/x86/include/asm/idtentry.h:564)
[ 332.928073] ? event_callback (kernel/trace/trace_events.c:2439)
[ 332.931996] dcache_dir_open_wrapper (fs/tracefs/event_inode.c:745)
[ 332.936636] ? __pfx_dcache_dir_open_wrapper (fs/tracefs/event_inode.c:683)
[ 332.941772] do_dentry_open (fs/open.c:929)
[ 332.945646] vfs_open (fs/open.c:1064)
[ 332.948800] path_openat (fs/namei.c:3639 fs/namei.c:3796)
[ 332.952465] ? ___slab_alloc (mm/slub.c:810 mm/slub.c:3265)
[ 332.956384] ? nfs_ctx_key_to_expire (fs/nfs/write.c:1281)
[ 332.960917] ? trace_preempt_on (kernel/trace/trace_preemptirq.c:105)
[ 332.964929] do_filp_open (fs/namei.c:3823)
[ 332.968511] do_sys_openat2 (fs/open.c:1422)
[ 332.972173] __x64_sys_openat (fs/open.c:1448)
[ 332.976014] do_syscall_64 (arch/x86/entry/common.c:50
arch/x86/entry/common.c:80)
[ 332.979601] ? trace_hardirqs_on_prepare
(kernel/trace/trace_preemptirq.c:47 (discriminator 16)
kernel/trace/trace_preemptirq.c:42 (discriminator 16))
[ 332.984436] ? syscall_exit_to_user_mode (kernel/entry/common.c:299)
[ 332.989219] ? do_syscall_64 (arch/x86/entry/common.c:87)
[ 332.992964] ? do_syscall_64 (arch/x86/entry/common.c:87)
[ 332.996709] ? do_syscall_64 (arch/x86/entry/common.c:87)
[ 333.000460] ? do_syscall_64 (arch/x86/entry/common.c:87)
[ 333.004204] ? do_syscall_64 (arch/x86/entry/common.c:87)
[ 333.007948] entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:120)
[ 333.012994] RIP: 0033:0x7fc5a51fadf1
[ 333.016600] Code: 44 24 18 31 c0 41 83 e2 40 75 3e 89 f0 25 00 00 41
00 3d 00 00 41 00 74 30 89 f2 b8 01 01 00 00 48 89 fe bf 9c ff ff ff
0f 05 <48> 3d 00 f0 ff ff 77 3f 48 8b 54 24 18 64 48 2b 14 25 28 00 00
00
All code
========
0: 44 24 18 rex.R and $0x18,%al
3: 31 c0 xor %eax,%eax
5: 41 83 e2 40 and $0x40,%r10d
9: 75 3e jne 0x49
b: 89 f0 mov %esi,%eax
d: 25 00 00 41 00 and $0x410000,%eax
12: 3d 00 00 41 00 cmp $0x410000,%eax
17: 74 30 je 0x49
19: 89 f2 mov %esi,%edx
1b: b8 01 01 00 00 mov $0x101,%eax
20: 48 89 fe mov %rdi,%rsi
23: bf 9c ff ff ff mov $0xffffff9c,%edi
28: 0f 05 syscall
2a:* 48 3d 00 f0 ff ff cmp $0xfffffffffffff000,%rax <--
trapping instruction
30: 77 3f ja 0x71
32: 48 8b 54 24 18 mov 0x18(%rsp),%rdx
37: 64 48 2b 14 25 28 00 sub %fs:0x28,%rdx
3e: 00 00

Code starting with the faulting instruction
===========================================
0: 48 3d 00 f0 ff ff cmp $0xfffffffffffff000,%rax
6: 77 3f ja 0x47
8: 48 8b 54 24 18 mov 0x18(%rsp),%rdx
d: 64 48 2b 14 25 28 00 sub %fs:0x28,%rdx
14: 00 00
[ 333.035361] RSP: 002b:00007ffebef93680 EFLAGS: 00000287 ORIG_RAX:
0000000000000101
[ 333.042919] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007fc5a51fadf1
[ 333.050042] RDX: 0000000000090800 RSI: 0000562c92f2cc20 RDI: 00000000ffffff9c
[ 333.057166] RBP: 0000000000000000 R08: 0000000000000007 R09: 0000562c92f2cc90
[ 333.064290] R10: 0000000000000000 R11: 0000000000000287 R12: 00007fc5a5062b98
[ 333.071415] R13: 00007ffebef93ad0 R14: 0000562c92f2cc20 R15: 0000562c9122ffc8
[ 333.078541] </TASK>
[ 333.080733] Modules linked in: x86_pkg_temp_thermal fuse configfs
ip_tables x_tables [last unloaded: trace_printk]
[ 333.091109] ---[ end trace 0000000000000000 ]---
[ 333.095757] RIP: 0010:event_callback (kernel/trace/trace_events.c:2439)
[ 333.100295] Code: f6 48 c7 c6 09 78 6b a0 41 55 49 89 cd 41 54 49 89
d4 53 48 8b 02 48 89 fb 4c 8b 78 10 e8 10 8b 19 01 85 c0 0f 84 d2 00
00 00 <41> 8b 47 60 a8 08 0f 85 9c 00 00 00 49 8b 47 10 48 83 78 18 00
74
All code
========
0: f6 48 c7 c6 testb $0xc6,-0x39(%rax)
4: 09 78 6b or %edi,0x6b(%rax)
7: a0 41 55 49 89 cd 41 movabs 0x495441cd89495541,%al
e: 54 49
10: 89 d4 mov %edx,%esp
12: 53 push %rbx
13: 48 8b 02 mov (%rdx),%rax
16: 48 89 fb mov %rdi,%rbx
19: 4c 8b 78 10 mov 0x10(%rax),%r15
1d: e8 10 8b 19 01 callq 0x1198b32
22: 85 c0 test %eax,%eax
24: 0f 84 d2 00 00 00 je 0xfc
2a:* 41 8b 47 60 mov 0x60(%r15),%eax <-- trapping instruction
2e: a8 08 test $0x8,%al
30: 0f 85 9c 00 00 00 jne 0xd2
36: 49 8b 47 10 mov 0x10(%r15),%rax
3a: 48 83 78 18 00 cmpq $0x0,0x18(%rax)
3f: 74 .byte 0x74

Code starting with the faulting instruction
===========================================
0: 41 8b 47 60 mov 0x60(%r15),%eax
4: a8 08 test $0x8,%al
6: 0f 85 9c 00 00 00 jne 0xa8
c: 49 8b 47 10 mov 0x10(%r15),%rax
10: 48 83 78 18 00 cmpq $0x0,0x18(%rax)
15: 74 .byte 0x74
[ 333.119040] RSP: 0018:ffffba5700967b50 EFLAGS: 00010202
[ 333.124290] RAX: 0000000000000001 RBX: ffffffffa06fb5d7 RCX: ffffba5700967bc8
[ 333.131451] RDX: 0000000000000069 RSI: ffffffffa06b7809 RDI: ffffffffa06fb5d7
[ 333.138623] RBP: ffffba5700967b78 R08: ffff8dbe12250134 R09: 0000000000000000
[ 333.145811] R10: ffff8dbe122500e0 R11: ffff8dbe0d8f8fc8 R12: ffffba5700967bd0
[ 333.152969] R13: ffffba5700967bc8 R14: ffffba5700967bc6 R15: 6b6b6b6b6b6b6b6b
[ 333.160127] FS: 00007fc5a5062d00(0000) GS:ffff8dc167a80000(0000)
knlGS:0000000000000000
[ 333.168215] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 333.173961] CR2: 00007f7f8dc50a1c CR3: 0000000113c84003 CR4: 00000000003706e0
[ 333.181092] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 333.188251] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
# ok 47 Test creation and deletion of trace instances

Log link:
- https://lkft.validation.linaro.org/scheduler/job/6983932#L1655
- https://storage.tuxsuite.com/public/linaro/naresh/builds/2XT84xYJIMmKApmqOOtKhnLdCyz/tuxmake_reproducer.sh

metadata:
git_ref: master
git_repo: https://git.kernel.org/pub/scm/linux/kernel/git/trace/linux-trace.git
git_ref: trace/core
kernel-config:
https://storage.tuxsuite.com/public/linaro/naresh/builds/2XT84xYJIMmKApmqOOtKhnLdCyz/config
artifact-location:
https://storage.tuxsuite.com/public/linaro/naresh/builds/2XT84xYJIMmKApmqOOtKhnLdCyz/
toolchain: gcc-13

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


> -- Steve