On Tue, 29 Nov 2022 02:36:22 +0000
Nadav Amit <na...@vmware.com> wrote:

> On Nov 22, 2022, at 12:51 PM, Nadav Amit <na...@vmware.com> 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).

How did this happen. It should be able to handle recursion:

static void
function_stack_trace_call(unsigned long ip, unsigned long parent_ip,
                          struct ftrace_ops *op, struct ftrace_regs *fregs)
{
        struct trace_array *tr = op->private;
        struct trace_array_cpu *data;
        unsigned long flags;
        long disabled;
        int cpu;
        unsigned int trace_ctx;

        if (unlikely(!tr->function_enabled))
                return;

        /*
         * Need to use raw, since this must be called before the
         * recursive protection is performed.
         */
        local_irq_save(flags);
        cpu = raw_smp_processor_id();
        data = per_cpu_ptr(tr->array_buffer.data, cpu);
        disabled = atomic_inc_return(&data->disabled);

        if (likely(disabled == 1)) { <<<---- This stops recursion

                trace_ctx = tracing_gen_ctx_flags(flags);
                trace_function(tr, ip, parent_ip, trace_ctx);
                __trace_stack(tr, trace_ctx, STACK_SKIP);
        }

        atomic_dec(&data->disabled);
        local_irq_restore(flags);
}

Each of the stack trace functions may recurse back into this function, but
it will not recurse further. How did it crash?

-- Steve


> 
> 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 <na...@vmware.com>
> 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 <na...@vmware.com>
> 
> 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)
> 
> 
> 
> 
> 


_______________________________________________
linux-um mailing list
linux-um@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-um

Reply via email to