Re: [PATCH 3/3] compiler: inline does not imply notrace

From: Nadav Amit
Date: Mon Nov 28 2022 - 21:36:39 EST


On Nov 22, 2022, at 12:51 PM, Nadav Amit <namit@xxxxxxxxxx> wrote:

> But more importantly, the current “inline”->”notrace” solution just papers
> over missing “notrace” annotations. Anyone can remove the “inline” at any
> given moment since there is no direct (or indirect) relationship between
> “inline” and “notrace”. It seems to me all random and bound to fail at some
> point.

Peter, Steven, (and others),

Beyond the issues that are addressed in this patch-set, I encountered one
more, which reiterates the fact that the heuristics of marking “inline”
functions as “notrace” is not good enough.

Before I send a patch, I would like to get your feedback. I include a splat
below. It appeaers the execution might get stuck since some functions that
can be used for function tracing can be traced themselves.

For example, __kernel_text_address() and unwind_get_return_address() are
traceable. I think that we need to disallow the tracing of all functions
that are called directly and indirectly from function_stack_trace_call()
(i.e., they are in the dynamic extent of function_stack_trace_call).

In the lack of a proper automated static analysis tool for the matter, I
suggest the following solution, but I would like to check that you are ok
with the granularity of the “notrace” as I propose. Again, note that this is
not caused by this “inline” patch, but an issue that existed before.

-- >8 --

Author: Nadav Amit <namit@xxxxxxxxxx>
Date: Tue Nov 29 02:25:12 2022 +0000

trace: Disable tracing of code called from function_stack_trace_call()

Signed-off-by: Nadav Amit <namit@xxxxxxxxxx>

diff --git a/arch/x86/kernel/Makefile b/arch/x86/kernel/Makefile
index a20a5ebfacd7..185933222d08 100644
--- a/arch/x86/kernel/Makefile
+++ b/arch/x86/kernel/Makefile
@@ -21,6 +21,10 @@ CFLAGS_REMOVE_ftrace.o = -pg
CFLAGS_REMOVE_early_printk.o = -pg
CFLAGS_REMOVE_head64.o = -pg
CFLAGS_REMOVE_sev.o = -pg
+CFLAGS_REMOVE_unwind_frame.o = -pg
+CFLAGS_REMOVE_unwind_guess.o = -pg
+CFLAGS_REMOVE_unwind_orc.o = -pg
+CFLAGS_REMOVE_stacktrace.o = -pg
endif

KASAN_SANITIZE_head$(BITS).o := n
diff --git a/kernel/Makefile b/kernel/Makefile
index 318789c728d3..d688eab1e1f8 100644
--- a/kernel/Makefile
+++ b/kernel/Makefile
@@ -19,6 +19,8 @@ obj-$(CONFIG_MULTIUSER) += groups.o
ifdef CONFIG_FUNCTION_TRACER
# Do not trace internal ftrace files
CFLAGS_REMOVE_irq_work.o = $(CC_FLAGS_FTRACE)
+CFLAGS_REMOVE_stacktrace.o = $(CC_FLAGS_FTRACE)
+CFLAGS_REMOVE_extable.o = $(CC_FLAGS_FTRACE)
endif

# Prevents flicker of uninteresting __do_softirq()/__local_bh_disable_ip()


---


[531394.447185] sched: RT throttling activated
[531394.874541] NMI watchdog: Watchdog detected hard LOCKUP on cpu 26
[531394.874745] Modules linked in: zram
[531394.875224] CPU: 26 PID: 0 Comm: swapper/26 Not tainted 6.0.0-rc6umem+ #29
[531394.875426] Hardware name: Cisco Systems Inc UCSC-C220-M5SX/UCSC-C220-M5SX, BIOS C220M5.4.0.1i.0.0522190226 05/22/2019
[531394.875623] RIP: 0010:poke_int3_handler (arch/x86/kernel/alternative.c:1435)
[531394.875903] Code: 45 01 48 8b 0d c8 0a 45 01 49 8d 70 ff 83 f8 01 7f 1c 48 63 39 31 c0 48 81 c7 00 00 00 81 48 39 fe 74 3c f0 ff 0d b3 0a 45 01 <c3> 31 c0 c3 49 89 ca 49 89 c1 49 d1 e9 4c 89 c9 48 c1 e1 04 4c 01
All code
========
0: 45 01 48 8b add %r9d,-0x75(%r8)
4: 0d c8 0a 45 01 or $0x1450ac8,%eax
9: 49 8d 70 ff lea -0x1(%r8),%rsi
d: 83 f8 01 cmp $0x1,%eax
10: 7f 1c jg 0x2e
12: 48 63 39 movslq (%rcx),%rdi
15: 31 c0 xor %eax,%eax
17: 48 81 c7 00 00 00 81 add $0xffffffff81000000,%rdi
1e: 48 39 fe cmp %rdi,%rsi
21: 74 3c je 0x5f
23: f0 ff 0d b3 0a 45 01 lock decl 0x1450ab3(%rip) # 0x1450add
2a:* c3 ret <-- trapping instruction
2b: 31 c0 xor %eax,%eax
2d: c3 ret
2e: 49 89 ca mov %rcx,%r10
31: 49 89 c1 mov %rax,%r9
34: 49 d1 e9 shr %r9
37: 4c 89 c9 mov %r9,%rcx
3a: 48 c1 e1 04 shl $0x4,%rcx
3e: 4c rex.WR
3f: 01 .byte 0x1

Code starting with the faulting instruction
===========================================
0: c3 ret
1: 31 c0 xor %eax,%eax
3: c3 ret
4: 49 89 ca mov %rcx,%r10
7: 49 89 c1 mov %rax,%r9
a: 49 d1 e9 shr %r9
d: 4c 89 c9 mov %r9,%rcx
10: 48 c1 e1 04 shl $0x4,%rcx
14: 4c rex.WR
15: 01 .byte 0x1
[531394.876031] RSP: 0018:ffffc9000cd387b0 EFLAGS: 00000003
[531394.876320] RAX: 0000000000000001 RBX: 0000000000000000 RCX: ffffc9000cd388a8
[531394.876482] RDX: ffffc9000cd387d8 RSI: ffffffff812ba310 RDI: ffffffffc0409094
[531394.876652] RBP: ffffc9000cd387c8 R08: ffffffffc0409099 R09: 0000000000000000
[531394.876782] R10: 0000000000000000 R11: 0000000000000000 R12: ffffc9000cd387d8
[531394.876927] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
[531394.877180] FS: 0000000000000000(0000) GS:ffff88afdf900000(0000) knlGS:0000000000000000
[531394.877371] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[531394.877503] CR2: 00007efd1e47b01c CR3: 0000000006a0a001 CR4: 00000000007706e0
[531394.877641] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[531394.877822] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[531394.877993] PKRU: 55555554
[531394.878164] Call Trace:
[531394.878356] <IRQ>
[531394.878573] ? exc_int3 (arch/x86/kernel/traps.c:817)
[531394.879306] asm_exc_int3 (./arch/x86/include/asm/idtentry.h:569)
[531394.879725] RIP: 0010:function_stack_trace_call (kernel/trace/trace_functions.c:219)
[531394.880058] Code: 2b 81 48 c7 c7 e0 e2 33 83 e8 1c fa fd ff 48 c7 c7 80 e6 1c 83 e8 40 61 fe 00 5d c3 cc cc cc cc cc cc cc cc cc cc cc cc cc cc <55> 48 89 e5 41 57 41 56 41 55 41 54 53 48 83 ec 08 4c 8b 62 18 41
All code
========
0: 2b 81 48 c7 c7 e0 sub -0x1f3838b8(%rcx),%eax
6: e2 33 loop 0x3b
8: 83 e8 1c sub $0x1c,%eax
b: fa cli
c: fd std
d: ff 48 c7 decl -0x39(%rax)
10: c7 80 e6 1c 83 e8 40 movl $0xfe6140,-0x177ce31a(%rax)
17: 61 fe 00
1a: 5d pop %rbp
1b: c3 ret
1c: cc int3
1d: cc int3
1e: cc int3
1f: cc int3
20: cc int3
21: cc int3
22: cc int3
23: cc int3
24: cc int3
25: cc int3
26: cc int3
27: cc int3
28: cc int3
29: cc int3
2a:* 55 push %rbp <-- trapping instruction
2b: 48 89 e5 mov %rsp,%rbp
2e: 41 57 push %r15
30: 41 56 push %r14
32: 41 55 push %r13
34: 41 54 push %r12
36: 53 push %rbx
37: 48 83 ec 08 sub $0x8,%rsp
3b: 4c 8b 62 18 mov 0x18(%rdx),%r12
3f: 41 rex.B

Code starting with the faulting instruction
===========================================
0: 55 push %rbp
1: 48 89 e5 mov %rsp,%rbp
4: 41 57 push %r15
6: 41 56 push %r14
8: 41 55 push %r13
a: 41 54 push %r12
c: 53 push %rbx
d: 48 83 ec 08 sub $0x8,%rsp
11: 4c 8b 62 18 mov 0x18(%rdx),%r12
15: 41 rex.B
[531394.880225] RSP: 0018:ffffc9000cd388a8 EFLAGS: 00000082
[531394.880538] RAX: 0000000000000002 RBX: ffffc9000cd389a8 RCX: ffffc9000cd388b0
[531394.880702] RDX: ffffffff831cbec0 RSI: ffffffff8111893f RDI: ffffffff811b2c80
[531394.880884] RBP: ffffc9000cd38958 R08: ffffc900082f7f48 R09: 0000000000000001
[531394.881055] R10: 0000000000000e00 R11: 0000000000000001 R12: ffffc9000cd38a50
[531394.881225] R13: 0000000000000000 R14: ffff889846ecc080 R15: 0000000000000004
[531394.883694] ? unwind_get_return_address (arch/x86/kernel/unwind_frame.c:19 arch/x86/kernel/unwind_frame.c:14)
[531394.883984] ? kernel_text_address (kernel/extable.c:78)
[531394.885410] ? 0xffffffffc0409095
[531394.886432] ? 0xffffffffc0409099
[531394.887278] ? 0xffffffffc0409099
[531394.889561] ? __trace_stack (kernel/trace/trace.c:3119)
[531394.890036] ? __kernel_text_address (kernel/extable.c:78)
[531394.891196] __kernel_text_address (kernel/extable.c:78)
[531394.891658] unwind_get_return_address (arch/x86/kernel/unwind_frame.c:19 arch/x86/kernel/unwind_frame.c:14)
[531394.892112] ? __kernel_text_address (kernel/extable.c:78)
[531394.892382] ? unwind_get_return_address (arch/x86/kernel/unwind_frame.c:19 arch/x86/kernel/unwind_frame.c:14)
[531394.892789] ? write_profile (kernel/stacktrace.c:83)
[531394.893260] arch_stack_walk (arch/x86/kernel/stacktrace.c:26)
[531394.895650] ? __trace_stack (kernel/trace/trace.c:3119)
[531394.897209] stack_trace_save (kernel/stacktrace.c:123)
[531394.898344] __ftrace_trace_stack (kernel/trace/trace.c:3061)
[531394.899500] ? rt_mutex_postunlock (kernel/printk/printk.c:2894)
[531394.899975] __trace_stack (kernel/trace/trace.c:3119)
[531394.901025] function_stack_trace_call (./arch/x86/include/asm/atomic.h:108 ./include/linux/atomic/atomic-instrumented.h:258 kernel/trace/trace_functions.c:245)
[531394.901356] ? fbcon_redraw.constprop.0 (drivers/video/fbdev/core/fbcon.c:1661)
[531394.902748] 0xffffffffc0409099
[531394.904289] ? fb_get_color_depth (drivers/video/fbdev/core/fbmem.c:92)
[531394.906173] ? console_conditional_schedule (kernel/printk/printk.c:2895)
[531394.907244] console_conditional_schedule (kernel/printk/printk.c:2895)
[531394.907727] fbcon_redraw.constprop.0 (drivers/video/fbdev/core/fbcon.c:1661)
[531394.908200] ? console_conditional_schedule (kernel/printk/printk.c:2895)
[531394.908506] ? fbcon_redraw.constprop.0 (drivers/video/fbdev/core/fbcon.c:1661)
[531394.911230] fbcon_scroll (drivers/video/fbdev/core/fbcon.c:1838)
[531394.912743] con_scroll (drivers/tty/vt/vt.c:630 (discriminator 1))
[531394.914360] lf (drivers/tty/vt/vt.c:1507)
[531394.914680] ? lf (drivers/tty/vt/vt.c:1502)
[531394.915779] vt_console_print (drivers/tty/vt/vt.c:3126)
[531394.918248] console_emit_next_record.constprop.0 (kernel/printk/printk.c:1945 kernel/printk/printk.c:2732)
[531394.922365] console_unlock (kernel/printk/printk.c:2794 kernel/printk/printk.c:2861)
[531394.924129] vprintk_emit (kernel/printk/printk.c:2272)
[531394.925782] vprintk_default (kernel/printk/printk.c:2283)
[531394.926306] vprintk (kernel/printk/printk_safe.c:50)
[531394.926943] _printk (kernel/printk/printk.c:2296)
[531394.929016] perf_duration_warn.cold (kernel/events/core.c:510 kernel/events/core.c:508)
[531394.929518] irq_work_single (kernel/irq_work.c:211)
[531394.930449] irq_work_run_list (kernel/irq_work.c:241 (discriminator 3))
[531394.931169] irq_work_run (kernel/irq_work.c:253)
[531394.931816] __sysvec_irq_work (./arch/x86/include/asm/jump_label.h:27 ./include/linux/jump_label.h:207 ./arch/x86/include/asm/trace/irq_vectors.h:64 arch/x86/kernel/irq_work.c:23)
[531394.932259] sysvec_irq_work (arch/x86/kernel/irq_work.c:17 (discriminator 14))
[531394.932660] </IRQ>
[531394.932854] <TASK>
[531394.933607] asm_sysvec_irq_work (./arch/x86/include/asm/idtentry.h:675)