From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from kanga.kvack.org (kanga.kvack.org [205.233.56.17]) by smtp.lore.kernel.org (Postfix) with ESMTP id 0E8FAC4332F for ; Tue, 29 Nov 2022 04:15:42 +0000 (UTC) Received: by kanga.kvack.org (Postfix) id 9FF0D6B0074; Mon, 28 Nov 2022 23:15:41 -0500 (EST) Received: by kanga.kvack.org (Postfix, from userid 40) id 988296B0075; Mon, 28 Nov 2022 23:15:41 -0500 (EST) X-Delivered-To: int-list-linux-mm@kvack.org Received: by kanga.kvack.org (Postfix, from userid 63042) id 8008A6B0078; Mon, 28 Nov 2022 23:15:41 -0500 (EST) X-Delivered-To: linux-mm@kvack.org Received: from relay.hostedemail.com (smtprelay0010.hostedemail.com [216.40.44.10]) by kanga.kvack.org (Postfix) with ESMTP id 699B36B0074 for ; Mon, 28 Nov 2022 23:15:41 -0500 (EST) Received: from smtpin30.hostedemail.com (a10.router.float.18 [10.200.18.1]) by unirelay10.hostedemail.com (Postfix) with ESMTP id 3F4ACC0EDE for ; Tue, 29 Nov 2022 04:15:41 +0000 (UTC) X-FDA: 80185166082.30.C1EA74D Received: from ams.source.kernel.org (ams.source.kernel.org [145.40.68.75]) by imf11.hostedemail.com (Postfix) with ESMTP id 930D44000A for ; Tue, 29 Nov 2022 04:15:40 +0000 (UTC) Received: from smtp.kernel.org (relay.kernel.org [52.25.139.140]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by ams.source.kernel.org (Postfix) with ESMTPS id 4A73EB8117A; Tue, 29 Nov 2022 04:15:38 +0000 (UTC) Received: by smtp.kernel.org (Postfix) with ESMTPSA id AC4F6C433C1; Tue, 29 Nov 2022 04:15:34 +0000 (UTC) Date: Mon, 28 Nov 2022 23:15:32 -0500 From: Steven Rostedt To: Nadav Amit Cc: Peter Zijlstra , Arnd Bergmann , Thomas Gleixner , "linux-arm-kernel@lists.infradead.org" , kernel list , "linux-ia64@vger.kernel.org" , "linux-um@lists.infradead.org" , Linux-Arch , Linux-MM , Andy Lutomirski , Ingo Molnar , Borislav Petkov , Dave Hansen , X86 ML , Richard Weinberger , Anton Ivanov , Johannes Berg , Andrew Morton , Nadav Amit Subject: Re: [PATCH 3/3] compiler: inline does not imply notrace Message-ID: <20221128231532.40210855@gandalf.local.home> In-Reply-To: <4BDE3655-CCC3-412B-9DDB-226485113706@vmware.com> References: <20221122195329.252654-1-namit@vmware.com> <20221122195329.252654-4-namit@vmware.com> <4BDE3655-CCC3-412B-9DDB-226485113706@vmware.com> X-Mailer: Claws Mail 3.17.8 (GTK+ 2.24.33; x86_64-pc-linux-gnu) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=hostedemail.com; s=arc-20220608; t=1669695340; h=from:from:sender:reply-to:subject:subject:date:date: message-id:message-id:to:to:cc:cc:mime-version:mime-version: content-type:content-type: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references; bh=/npJqdDP+l1jBOPDxNr0yHmdwfYGkxgbXIaMCCayvV4=; b=sb9CFG4xvXTIHAYTOQSGC1YUb8oAo2mCjzEw2Ll++jJ2bZMDsxGdYA5zOX1JY05Emjrdf+ xoQAqVrzk/khnpNDKlxudkbKiVNGkak/6RKvJvMJRvxVfxXklav6fhlmIzf69JqyVA6PZg JcHqNfrFLCogqGQEIIzKto1GghEonf8= ARC-Authentication-Results: i=1; imf11.hostedemail.com; dkim=none; dmarc=none; spf=pass (imf11.hostedemail.com: domain of "SRS0=ndWz=35=goodmis.org=rostedt@kernel.org" designates 145.40.68.75 as permitted sender) smtp.mailfrom="SRS0=ndWz=35=goodmis.org=rostedt@kernel.org" ARC-Seal: i=1; s=arc-20220608; d=hostedemail.com; t=1669695340; a=rsa-sha256; cv=none; b=IiDqMewj/IDksNUnFi9t+fY6o4zpj4sH4orGOnP/SSrclMBwkpIFZ2uk9DNnJHZuN5oaVA AxMVi2VzcNsZdM8zKmlUB0/5XoJgk83fb2/gjfsROt/NL+cdXb/CQwb5F+EGy/91KAyaOJ jN+tzdykIrpdsQ/ZVsywzSpS3sEgv/s= X-Stat-Signature: pimn77o65j4e7m75gd5efp7jg7bqn6fm X-Rspamd-Queue-Id: 930D44000A Authentication-Results: imf11.hostedemail.com; dkim=none; dmarc=none; spf=pass (imf11.hostedemail.com: domain of "SRS0=ndWz=35=goodmis.org=rostedt@kernel.org" designates 145.40.68.75 as permitted sender) smtp.mailfrom="SRS0=ndWz=35=goodmis.org=rostedt@kernel.org" X-Rspamd-Server: rspam06 X-Rspam-User: X-HE-Tag: 1669695340-237730 X-Bogosity: Ham, tests=bogofilter, spamicity=0.000000, version=1.2.4 Sender: owner-linux-mm@kvack.org Precedence: bulk X-Loop: owner-majordomo@kvack.org List-ID: On Tue, 29 Nov 2022 02:36:22 +0000 Nadav Amit wrote: > On Nov 22, 2022, at 12:51 PM, Nadav Amit wrote: >=20 > > But more importantly, the current =E2=80=9Cinline=E2=80=9D->=E2=80=9Dno= trace=E2=80=9D solution just papers > > over missing =E2=80=9Cnotrace=E2=80=9D annotations. Anyone can remove t= he =E2=80=9Cinline=E2=80=9D at any > > given moment since there is no direct (or indirect) relationship between > > =E2=80=9Cinline=E2=80=9D and =E2=80=9Cnotrace=E2=80=9D. It seems to me = all random and bound to fail at some > > point. =20 >=20 > Peter, Steven, (and others), >=20 > Beyond the issues that are addressed in this patch-set, I encountered one > more, which reiterates the fact that the heuristics of marking =E2=80=9Ci= nline=E2=80=9D > functions as =E2=80=9Cnotrace=E2=80=9D is not good enough. >=20 > Before I send a patch, I would like to get your feedback. I include a spl= at > below. It appeaers the execution might get stuck since some functions that > can be used for function tracing can be traced themselves. >=20 > 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 =3D 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 =3D raw_smp_processor_id(); data =3D per_cpu_ptr(tr->array_buffer.data, cpu); disabled =3D atomic_inc_return(&data->disabled); if (likely(disabled =3D=3D 1)) { <<<---- This stops recursion trace_ctx =3D 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 >=20 > 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 =E2=80=9Cnotrace=E2=80=9D as I propose. Again= , note that this is > not caused by this =E2=80=9Cinline=E2=80=9D patch, but an issue that exis= ted before. >=20 > -- >8 -- =20 >=20 > Author: Nadav Amit > Date: Tue Nov 29 02:25:12 2022 +0000 >=20 > trace: Disable tracing of code called from function_stack_trace_call() > =20 > Signed-off-by: Nadav Amit >=20 > 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 =3D -pg > CFLAGS_REMOVE_early_printk.o =3D -pg > CFLAGS_REMOVE_head64.o =3D -pg > CFLAGS_REMOVE_sev.o =3D -pg > +CFLAGS_REMOVE_unwind_frame.o =3D -pg > +CFLAGS_REMOVE_unwind_guess.o =3D -pg > +CFLAGS_REMOVE_unwind_orc.o =3D -pg > +CFLAGS_REMOVE_stacktrace.o =3D -pg > endif > =20 > KASAN_SANITIZE_head$(BITS).o :=3D 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) +=3D groups.o > ifdef CONFIG_FUNCTION_TRACER > # Do not trace internal ftrace files > CFLAGS_REMOVE_irq_work.o =3D $(CC_FLAGS_FTRACE) > +CFLAGS_REMOVE_stacktrace.o =3D $(CC_FLAGS_FTRACE) > +CFLAGS_REMOVE_extable.o =3D $(CC_FLAGS_FTRACE) > endif > =20 > # Prevents flicker of uninteresting __do_softirq()/__local_bh_disable_ip= () >=20 >=20 > --- >=20 >=20 > [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)=20 > [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 = 31 c0 c3 49 89 ca 49 89 c1 49 d1 e9 4c 89 c9 48 c1 e1 04 4c 01 > All code > =3D=3D=3D=3D=3D=3D=3D=3D > 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 =20 > 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 >=20 > Code starting with the faulting instruction > =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D > 0: c3 ret =20 > 1: 31 c0 xor %eax,%eax > 3: c3 ret =20 > 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: ffffc900= 0cd388a8 > [531394.876482] RDX: ffffc9000cd387d8 RSI: ffffffff812ba310 RDI: ffffffff= c0409094 > [531394.876652] RBP: ffffc9000cd387c8 R08: ffffffffc0409099 R09: 00000000= 00000000 > [531394.876782] R10: 0000000000000000 R11: 0000000000000000 R12: ffffc900= 0cd387d8 > [531394.876927] R13: 0000000000000000 R14: 0000000000000000 R15: 00000000= 00000000 > [531394.877180] FS: 0000000000000000(0000) GS:ffff88afdf900000(0000) knl= GS:0000000000000000 > [531394.877371] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 > [531394.877503] CR2: 00007efd1e47b01c CR3: 0000000006a0a001 CR4: 00000000= 007706e0 > [531394.877641] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 00000000= 00000000 > [531394.877822] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 00000000= 00000400 > [531394.877993] PKRU: 55555554 > [531394.878164] Call Trace: > [531394.878356] > [531394.878573] ? exc_int3 (arch/x86/kernel/traps.c:817)=20 > [531394.879306] asm_exc_int3 (./arch/x86/include/asm/idtentry.h:569)=20 > [531394.879725] RIP: 0010:function_stack_trace_call (kernel/trace/trace_f= unctions.c:219)=20 > [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 > =3D=3D=3D=3D=3D=3D=3D=3D > 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 =20 > c: fd std =20 > d: ff 48 c7 decl -0x39(%rax) > 10: c7 80 e6 1c 83 e8 40 movl $0xfe6140,-0x177ce31a(%rax) > 17: 61 fe 00=20 > 1a: 5d pop %rbp > 1b: c3 ret =20 > 1c: cc int3 =20 > 1d: cc int3 =20 > 1e: cc int3 =20 > 1f: cc int3 =20 > 20: cc int3 =20 > 21: cc int3 =20 > 22: cc int3 =20 > 23: cc int3 =20 > 24: cc int3 =20 > 25: cc int3 =20 > 26: cc int3 =20 > 27: cc int3 =20 > 28: cc int3 =20 > 29: cc int3 =20 > 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 >=20 > Code starting with the faulting instruction > =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D > 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: ffffc900= 0cd388b0 > [531394.880702] RDX: ffffffff831cbec0 RSI: ffffffff8111893f RDI: ffffffff= 811b2c80 > [531394.880884] RBP: ffffc9000cd38958 R08: ffffc900082f7f48 R09: 00000000= 00000001 > [531394.881055] R10: 0000000000000e00 R11: 0000000000000001 R12: ffffc900= 0cd38a50 > [531394.881225] R13: 0000000000000000 R14: ffff889846ecc080 R15: 00000000= 00000004 > [531394.883694] ? unwind_get_return_address (arch/x86/kernel/unwind_frame= .c:19 arch/x86/kernel/unwind_frame.c:14)=20 > [531394.883984] ? kernel_text_address (kernel/extable.c:78)=20 > [531394.885410] ? 0xffffffffc0409095 > [531394.886432] ? 0xffffffffc0409099 > [531394.887278] ? 0xffffffffc0409099 > [531394.889561] ? __trace_stack (kernel/trace/trace.c:3119)=20 > [531394.890036] ? __kernel_text_address (kernel/extable.c:78)=20 > [531394.891196] __kernel_text_address (kernel/extable.c:78)=20 > [531394.891658] unwind_get_return_address (arch/x86/kernel/unwind_frame.c= :19 arch/x86/kernel/unwind_frame.c:14)=20 > [531394.892112] ? __kernel_text_address (kernel/extable.c:78)=20 > [531394.892382] ? unwind_get_return_address (arch/x86/kernel/unwind_frame= .c:19 arch/x86/kernel/unwind_frame.c:14)=20 > [531394.892789] ? write_profile (kernel/stacktrace.c:83)=20 > [531394.893260] arch_stack_walk (arch/x86/kernel/stacktrace.c:26)=20 > [531394.895650] ? __trace_stack (kernel/trace/trace.c:3119)=20 > [531394.897209] stack_trace_save (kernel/stacktrace.c:123)=20 > [531394.898344] __ftrace_trace_stack (kernel/trace/trace.c:3061)=20 > [531394.899500] ? rt_mutex_postunlock (kernel/printk/printk.c:2894)=20 > [531394.899975] __trace_stack (kernel/trace/trace.c:3119)=20 > [531394.901025] function_stack_trace_call (./arch/x86/include/asm/atomic.= h:108 ./include/linux/atomic/atomic-instrumented.h:258 kernel/trace/trace_f= unctions.c:245)=20 > [531394.901356] ? fbcon_redraw.constprop.0 (drivers/video/fbdev/core/fbco= n.c:1661)=20 > [531394.902748] 0xffffffffc0409099 > [531394.904289] ? fb_get_color_depth (drivers/video/fbdev/core/fbmem.c:92= )=20 > [531394.906173] ? console_conditional_schedule (kernel/printk/printk.c:28= 95)=20 > [531394.907244] console_conditional_schedule (kernel/printk/printk.c:2895= )=20 > [531394.907727] fbcon_redraw.constprop.0 (drivers/video/fbdev/core/fbcon.= c:1661)=20 > [531394.908200] ? console_conditional_schedule (kernel/printk/printk.c:28= 95)=20 > [531394.908506] ? fbcon_redraw.constprop.0 (drivers/video/fbdev/core/fbco= n.c:1661)=20 > [531394.911230] fbcon_scroll (drivers/video/fbdev/core/fbcon.c:1838)=20 > [531394.912743] con_scroll (drivers/tty/vt/vt.c:630 (discriminator 1))=20 > [531394.914360] lf (drivers/tty/vt/vt.c:1507)=20 > [531394.914680] ? lf (drivers/tty/vt/vt.c:1502)=20 > [531394.915779] vt_console_print (drivers/tty/vt/vt.c:3126)=20 > [531394.918248] console_emit_next_record.constprop.0 (kernel/printk/print= k.c:1945 kernel/printk/printk.c:2732)=20 > [531394.922365] console_unlock (kernel/printk/printk.c:2794 kernel/printk= /printk.c:2861)=20 > [531394.924129] vprintk_emit (kernel/printk/printk.c:2272)=20 > [531394.925782] vprintk_default (kernel/printk/printk.c:2283)=20 > [531394.926306] vprintk (kernel/printk/printk_safe.c:50)=20 > [531394.926943] _printk (kernel/printk/printk.c:2296)=20 > [531394.929016] perf_duration_warn.cold (kernel/events/core.c:510 kernel/= events/core.c:508)=20 > [531394.929518] irq_work_single (kernel/irq_work.c:211)=20 > [531394.930449] irq_work_run_list (kernel/irq_work.c:241 (discriminator 3= ))=20 > [531394.931169] irq_work_run (kernel/irq_work.c:253)=20 > [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)=20 > [531394.932259] sysvec_irq_work (arch/x86/kernel/irq_work.c:17 (discrimin= ator 14))=20 > [531394.932660] > [531394.932854] > [531394.933607] asm_sysvec_irq_work (./arch/x86/include/asm/idtentry.h:67= 5) >=20 >=20 >=20 >=20 >=20