lkml.org 
[lkml]   [2022]   [Feb]   [23]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
From
Date
Subject5.15 ftrace bug when enabling function_graph
Hi all

We had some panic when trying to profile some function using ftrace's
function_graph.
The panic is attached here:

------------[ cut here ]------------
WARNING: CPU: 30 PID: 812411 at arch/x86/kernel/ftrace.c:96
ftrace_verify_code+0x37/0x70
Modules linked in: xt_hashlimit macvlan ip_set_hash_netport
xt_length esp4 xfrm_interface xfrm6_tunnel dummy ipip nft_numgen
nft_ct ip_gre gre xfrm_user xfrm_algo udp_diag inet_diag fou6
ip6_tunnel tunnel6 cls_bpf xt_NFLOG xt_statistic lz4 lz4_compress sit
tunnel4 fou ip_tunnel ip6_udp_tunnel udp_tunnel nft_compat veth tun
overlay sch_ingress raid0 md_mod essiv dm_crypt trusted asn1_encoder
tee dm_mod dax nfnetlink_log nft_log nft_limit nft_counter nf_tables
ip6table_filter ip6table_mangle ip6table_raw ip6table_security
ip6table_nat ip6_tables xt_state xt_multiport xt_tcpmss iptable_filter
xt_TCPMSS xt_bpf xt_u32 xt_mark xt_connmark xt_conntrack
iptable_mangle xt_nat iptable_nat nf_nat xt_owner xt_set xt_comment
xt_tcpudp xt_CT iptable_raw ip_set_hash_net ip_set_hash_ip ip_set
nfnetlink sch_fq tcp_bbr nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4
8021q garp stp mrp llc skx_edac x86_pkg_temp_thermal kvm_intel kvm
irqbypass crc32_pclmul crc32c_intel aesni_intel
rapl intel_cstate ipmi_ssif mlx5_core i2c_i801 mlxfw i2c_smbus
xhci_pci acpi_ipmi tpm_crb tls intel_uncore ioatdma i2c_core xhci_hcd
ipmi_si dca tpm_tis ipmi_devintf tpm_tis_core tiny_power_button
ipmi_msghandler tpm button fuse efivarfs ip_tables x_tables
bcmcrypt(O) crypto_simd cryptd [last unloaded: zsmalloc]
CPU: 30 PID: 812411 Comm: bash Tainted: G O
5.15.19-cloudflare-2022.2.1 #1
Hardware name: Quanta Cloud Technology Inc. QuantaPlex
T42S-2U/T42S-2U MB (Lewisburg-1G) CLX, BIOS 3B16.Q102 02/19/2020
RIP: 0010:ftrace_verify_code+0x37/0x70
Code: 83 ec 10 65 48 8b 04 25 28 00 00 00 48 89 44 24 08 31 c0 48 8d
7c 24 03 e8 26 1f 1a 00 48 85 c0 75 33 8b 03 39 44 24 03 74 1d <0f> 0b
b8 ea ff ff ff 48 8b 4c 24 08 65 48 2b 0c 25 28 00 00 00 75
RSP: 0018:ffffa86ce19e3d28 EFLAGS: 00010212
RAX: 0000000000441f0f RBX: ffffffffa9001e8a RCX: 0000000000000010
RDX: 000000000db62b18 RSI: 0000000000000005 RDI: ffffffffa89ea1d0
RBP: ffffffffaa764350 R08: 0000000000000001 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000001 R12: 0000000000000001
R13: ffff8fb8c00f95f0 R14: 0000000000000000 R15: 000000000000000f
FS: 00007f3715044740(0000) GS:ffff8ff7bf380000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 000055c306a30298 CR3: 0000002e01756002 CR4: 00000000007706e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
PKRU: 55555554
Call Trace:
<TASK>
ftrace_replace_code+0x9a/0x160
? arch_unoptimize_kprobes+0xb0/0xb0
ftrace_modify_all_code+0xbd/0x150
ftrace_run_update_code+0x13/0x70
ftrace_startup.part.0+0xe1/0x140
register_ftrace_graph+0x292/0x2d0
graph_trace_init+0x27/0x50
tracing_set_tracer+0xdb/0x170
tracing_set_trace_write+0x95/0xe0
vfs_write+0xbd/0x270
ksys_write+0x5f/0xe0
do_syscall_64+0x38/0x90
entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f3715135f33
Code: 8b 15 61 ef 0c 00 f7 d8 64 89 02 48 c7 c0 ff ff ff ff eb b7 0f
1f 00 64 8b 04 25 18 00 00 00 85 c0 75 14 b8 01 00 00 00 0f 05 <48> 3d
00 f0 ff ff 77 55 c3 0f 1f 40 00 48 83 ec 28 48 89 54 24 18
RSP: 002b:00007ffc4232a038 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
RAX: ffffffffffffffda RBX: 000000000000000f RCX: 00007f3715135f33
RDX: 000000000000000f RSI: 000055c2f4c63480 RDI: 0000000000000001
RBP: 000055c2f4c63480 R08: 000000000000000a R09: 000000000000000e
R10: 000055c2f4c66cd0 R11: 0000000000000246 R12: 000000000000000f
R13: 00007f37152066a0 R14: 000000000000000f R15: 00007f37152068a0
</TASK>
---[ end trace 3c0096669fc25320 ]---
------------[ ftrace bug ]------------
ftrace failed to modify
[<ffffffffa89ea1d0>] bpf_dispatcher_xdp_func+0x0/0x10
actual: ffffffe9:2b:ffffffb6:0d:18
Setting ftrace call site to call ftrace function
ftrace record flags: 10000001
(1)
expected tramp: ffffffffa824bd90
------------[ cut here ]------------

After this, any attempt to use trace will fail. For example, here we execute
https://github.com/iovisor/bcc/blob/master/tools/funcslower.py shortly after.

WARNING: CPU: 30 PID: 812411 at kernel/trace/ftrace.c:2073
ftrace_bug+0x22c/0x252
Modules linked in: xt_hashlimit macvlan ip_set_hash_netport
xt_length esp4 xfrm_interface xfrm6_tunnel dummy ipip nft_numgen
nft_ct ip_gre gre xfrm_user xfrm_algo udp_diag inet_diag fou6
ip6_tunnel tunnel6 cls_bpf xt_NFLOG xt_statistic lz4 lz4_compress sit
tunnel4 fou ip_tunnel ip6_udp_tunnel udp_tunnel nft_compat veth tun
overlay sch_ingress raid0 md_mod essiv dm_crypt trusted asn1_encoder
tee dm_mod dax nfnetlink_log nft_log nft_limit nft_counter nf_tables
ip6table_filter ip6table_mangle ip6table_raw ip6table_security
ip6table_nat ip6_tables xt_state xt_multiport xt_tcpmss iptable_filter
xt_TCPMSS xt_bpf xt_u32 xt_mark xt_connmark xt_conntrack
iptable_mangle xt_nat iptable_nat nf_nat xt_owner xt_set xt_comment
xt_tcpudp xt_CT iptable_raw ip_set_hash_net ip_set_hash_ip ip_set
nfnetlink sch_fq tcp_bbr nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4
8021q garp stp mrp llc skx_edac x86_pkg_temp_thermal kvm_intel kvm
irqbypass crc32_pclmul crc32c_intel aesni_intel
rapl intel_cstate ipmi_ssif mlx5_core i2c_i801 mlxfw i2c_smbus
xhci_pci acpi_ipmi tpm_crb tls intel_uncore ioatdma i2c_core xhci_hcd
ipmi_si dca tpm_tis ipmi_devintf tpm_tis_core tiny_power_button
ipmi_msghandler tpm button fuse efivarfs ip_tables x_tables
bcmcrypt(O) crypto_simd cryptd [last unloaded: zsmalloc]
CPU: 30 PID: 812411 Comm: bash Tainted: G W O
5.15.19-cloudflare-2022.2.1 #1
Hardware name: Quanta Cloud Technology Inc. QuantaPlex
T42S-2U/T42S-2U MB (Lewisburg-1G) CLX, BIOS 3B16.Q102 02/19/2020
RIP: 0010:ftrace_bug+0x22c/0x252
Code: ff 84 c0 74 d0 eb b4 48 c7 c7 d8 72 75 a9 e8 53 c9 ff ff 48 89
ef e8 5b 74 7b ff 48 c7 c7 e9 72 75 a9 48 89 c6 e8 3c c9 ff ff <0f> 0b
c7 05 18 98 4d 01 01 00 00 00 5b c7 05 1d 98 4d 01 00 00 00
RSP: 0018:ffffa86ce19e3d50 EFLAGS: 00010246
RAX: 0000000000000022 RBX: 00000000ffffffea RCX: ffff8ff7bf39f7b8
RDX: 0000000000000000 RSI: 0000000000000027 RDI: ffff8ff7bf39f7b0
RBP: ffff8fb8c00f95f0 R08: ffffffffaa719120 R09: 000000000000000f
R10: 000000000000000f R11: ffff8ff83ff3291a R12: ffffffffa89ea1d0
R13: ffffffffa8250030 R14: 0000000000000000 R15: 000000000000000f
FS: 00007f3715044740(0000) GS:ffff8ff7bf380000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 000055c306a30298 CR3: 0000002e01756002 CR4: 00000000007706e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
PKRU: 55555554
Call Trace:
<TASK>
ftrace_modify_all_code+0xbd/0x150
ftrace_run_update_code+0x13/0x70
ftrace_startup.part.0+0xe1/0x140
register_ftrace_graph+0x292/0x2d0
graph_trace_init+0x27/0x50
tracing_set_tracer+0xdb/0x170
tracing_set_trace_write+0x95/0xe0
vfs_write+0xbd/0x270
ksys_write+0x5f/0xe0
do_syscall_64+0x38/0x90
entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f3715135f33
Code: 8b 15 61 ef 0c 00 f7 d8 64 89 02 48 c7 c0 ff ff ff ff eb b7 0f
1f 00 64 8b 04 25 18 00 00 00 85 c0 75 14 b8 01 00 00 00 0f 05 <48> 3d
00 f0 ff ff 77 55 c3 0f 1f 40 00 48 83 ec 28 48 89 54 24 18
RSP: 002b:00007ffc4232a038 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
RAX: ffffffffffffffda RBX: 000000000000000f RCX: 00007f3715135f33
RDX: 000000000000000f RSI: 000055c2f4c63480 RDI: 0000000000000001
RBP: 000055c2f4c63480 R08: 000000000000000a R09: 000000000000000e
R10: 000055c2f4c66cd0 R11: 0000000000000246 R12: 000000000000000f
R13: 00007f37152066a0 R14: 000000000000000f R15: 00007f37152068a0
</TASK>
---[ end trace 3c0096669fc25321 ]---
BUG: kernel NULL pointer dereference, address: 0000000000000000
#PF: supervisor read access in kernel mode
#PF: error_code(0x0000) - not-present page
PGD f607b5067 P4D f607b5067 PUD ef47e0067 PMD 0
Oops: 0000 [#1] SMP NOPTI
CPU: 4 PID: 852378 Comm: funcslower Tainted: G W O
5.15.19-cloudflare-2022.2.1 #1
Hardware name: Quanta Cloud Technology Inc. QuantaPlex
T42S-2U/T42S-2U MB (Lewisburg-1G) CLX, BIOS 3B16.Q102 02/19/2020
RIP: 0010:register_kprobe+0xb8/0x630
Code: aa 48 85 c0 75 0a eb 4a 48 8b 00 48 85 c0 74 42 48 3b 50 28 75
f2 48 39 c5 74 21 48 8b 70 10 48 8d 56 f0 48 39 d0 75 0f eb 28 <48> 8b
52 10 48 83 ea 10 48 39 d0 74 1b 48 39 d5 75 ee 0f 0b 48 c7
RSP: 0000:ffffa86cf5313d58 EFLAGS: 00010287
RAX: ffff8fc570aa3a40 RBX: 0000000000000000 RCX: 0000000000000000
RDX: fffffffffffffff0 RSI: ffff8fcf34e45a28 RDI: ffff8fca4f652700
RBP: ffff8fb9f851f918 R08: 0000000000000006 R09: ffff8fb8c7e680e8
R10: 0000000000000000 R11: 000000000000005d R12: 0000000000000000
R13: ffff8fc5d1c5c860 R14: ffff8fb9f851f9d8 R15: 0000000000000000
FS: 00007fa26c8a0740(0000) GS:ffff8fd7bf700000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000000000000000 CR3: 0000001be733e003 CR4: 00000000007706e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
PKRU: 55555554
Call Trace:
<TASK>
__trace_kprobe_create+0x810/0xb10
? __kmalloc+0x17e/0x320
? print_kprobe_event+0x190/0x190
? probes_write+0x10/0x10
trace_probe_create+0x73/0x90
create_or_delete_trace_kprobe+0x11/0x30
trace_parse_run_command+0xba/0x140
vfs_write+0xbd/0x270
ksys_write+0x5f/0xe0
do_syscall_64+0x38/0x90
entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7fa26cc17fb3
Code: 75 05 48 83 c4 58 c3 e8 cb 41 ff ff 66 2e 0f 1f 84 00 00 00 00
00 90 64 8b 04 25 18 00 00 00 85 c0 75 14 b8 01 00 00 00 0f 05 <48> 3d
00 f0 ff ff 77 55 c3 0f 1f 40 00 48 83 ec 28 48 89 54 24 18
RSP: 002b:00007ffdf1336128 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007fa26cc17fb3
RDX: 0000000000000044 RSI: 00007ffdf1336470 RDI: 0000000000000007
RBP: 00007ffdf1336470 R08: 00000000ffffffff R09: 00007ffdf1335fb0
R10: 00007fa263400090 R11: 0000000000000246 R12: 00007fa26bd150b9
R13: 0000000000000007 R14: 00007fa263400490 R15: 00007ffdf1336150
</TASK>
Modules linked in: xt_hashlimit macvlan ip_set_hash_netport
xt_length esp4 xfrm_interface xfrm6_tunnel dummy ipip nft_numgen
nft_ct ip_gre gre xfrm_user xfrm_algo udp_diag inet_diag fou6
ip6_tunnel tunnel6 cls_bpf xt_NFLOG xt_statistic lz4 lz4_compress sit
tunnel4 fou ip_tunnel ip6_udp_tunnel udp_tunnel nft_compat veth tun
overlay sch_ingress raid0 md_mod essiv dm_crypt trusted asn1_encoder
tee dm_mod dax nfnetlink_log nft_log nft_limit nft_counter nf_tables
ip6table_filter ip6table_mangle ip6table_raw ip6table_security
ip6table_nat ip6_tables xt_state xt_multiport xt_tcpmss iptable_filter
xt_TCPMSS xt_bpf xt_u32 xt_mark xt_connmark xt_conntrack
iptable_mangle xt_nat iptable_nat nf_nat xt_owner xt_set xt_comment
xt_tcpudp xt_CT iptable_raw ip_set_hash_net ip_set_hash_ip ip_set
nfnetlink sch_fq tcp_bbr nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4
8021q garp stp mrp llc skx_edac x86_pkg_temp_thermal kvm_intel kvm
irqbypass crc32_pclmul crc32c_intel aesni_intel
rapl intel_cstate ipmi_ssif mlx5_core i2c_i801 mlxfw i2c_smbus
xhci_pci acpi_ipmi tpm_crb tls intel_uncore ioatdma i2c_core xhci_hcd
ipmi_si dca tpm_tis ipmi_devintf tpm_tis_core tiny_power_button
ipmi_msghandler tpm button fuse efivarfs ip_tables x_tables
bcmcrypt(O) crypto_simd cryptd [last unloaded: zsmalloc]
CR2: 0000000000000000
---[ end trace 3c0096669fc25323 ]---
RIP: 0010:register_kprobe+0xb8/0x630
Code: aa 48 85 c0 75 0a eb 4a 48 8b 00 48 85 c0 74 42 48 3b 50 28 75
f2 48 39 c5 74 21 48 8b 70 10 48 8d 56 f0 48 39 d0 75 0f eb 28 <48> 8b
52 10 48 83 ea 10 48 39 d0 74 1b 48 39 d5 75 ee 0f 0b 48 c7
RSP: 0000:ffffa86cf5313d58 EFLAGS: 00010287
RAX: ffff8fc570aa3a40 RBX: 0000000000000000 RCX: 0000000000000000
RDX: fffffffffffffff0 RSI: ffff8fcf34e45a28 RDI: ffff8fca4f652700
RBP: ffff8fb9f851f918 R08: 0000000000000006 R09: ffff8fb8c7e680e8
R10: 0000000000000000 R11: 000000000000005d R12: 0000000000000000
R13: ffff8fc5d1c5c860 R14: ffff8fb9f851f9d8 R15: 0000000000000000
FS: 00007fa26c8a0740(0000) GS:ffff8fd7bf700000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000000000000000 CR3: 0000001be733e003 CR4: 00000000007706e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
PKRU: 55555554

\
 
 \ /
  Last update: 2022-02-23 16:48    [W:0.192 / U:0.628 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site