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 9F8DDC433FE for ; Tue, 29 Nov 2022 15:06:56 +0000 (UTC) Received: by kanga.kvack.org (Postfix) id BD0706B0071; Tue, 29 Nov 2022 10:06:55 -0500 (EST) Received: by kanga.kvack.org (Postfix, from userid 40) id B801C6B0072; Tue, 29 Nov 2022 10:06:55 -0500 (EST) X-Delivered-To: int-list-linux-mm@kvack.org Received: by kanga.kvack.org (Postfix, from userid 63042) id A481D6B0074; Tue, 29 Nov 2022 10:06:55 -0500 (EST) X-Delivered-To: linux-mm@kvack.org Received: from relay.hostedemail.com (smtprelay0014.hostedemail.com [216.40.44.14]) by kanga.kvack.org (Postfix) with ESMTP id 987306B0071 for ; Tue, 29 Nov 2022 10:06:55 -0500 (EST) Received: from smtpin22.hostedemail.com (a10.router.float.18 [10.200.18.1]) by unirelay04.hostedemail.com (Postfix) with ESMTP id 4FDB81A0DB3 for ; Tue, 29 Nov 2022 15:06:55 +0000 (UTC) X-FDA: 80186807190.22.FBE6C2C Received: from dfw.source.kernel.org (dfw.source.kernel.org [139.178.84.217]) by imf08.hostedemail.com (Postfix) with ESMTP id 17204160014 for ; Tue, 29 Nov 2022 15:06:52 +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 dfw.source.kernel.org (Postfix) with ESMTPS id 0A25461783; Tue, 29 Nov 2022 15:06:52 +0000 (UTC) Received: by smtp.kernel.org (Postfix) with ESMTPSA id 7237EC433D6; Tue, 29 Nov 2022 15:06:49 +0000 (UTC) Date: Tue, 29 Nov 2022 10:06:47 -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 Subject: Re: [PATCH 3/3] compiler: inline does not imply notrace Message-ID: <20221129100647.4957579e@gandalf.local.home> In-Reply-To: <2CFF9131-48E9-44D3-93CA-976C47106092@vmware.com> References: <20221122195329.252654-1-namit@vmware.com> <20221122195329.252654-4-namit@vmware.com> <4BDE3655-CCC3-412B-9DDB-226485113706@vmware.com> <20221128231532.40210855@gandalf.local.home> <2CFF9131-48E9-44D3-93CA-976C47106092@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-Seal: i=1; s=arc-20220608; d=hostedemail.com; t=1669734413; a=rsa-sha256; cv=none; b=hVPMxNNUg8BUTnb9SYobfy7/2ACKRILGg1nm97r1n3aO67cKf4cX+X0qv/U4I+0NeT3JMz LuZ7HGmIbnmwsBj0t2Z1FdSMkuxJ6WWLD7JN8ajujCSKWRHtkX2xaY1mBI7KNjMksBpTBM UmaCRlZxXB8Fkvxfjj5zqqtovyaEKoc= ARC-Authentication-Results: i=1; imf08.hostedemail.com; dkim=none; dmarc=none; spf=pass (imf08.hostedemail.com: domain of "SRS0=ndWz=35=goodmis.org=rostedt@kernel.org" designates 139.178.84.217 as permitted sender) smtp.mailfrom="SRS0=ndWz=35=goodmis.org=rostedt@kernel.org" ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=hostedemail.com; s=arc-20220608; t=1669734413; 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=q8SD7tYak7U6SUc+NsEamPGOTScZ+24YV98UkMvkP7U=; b=VvGzmz5Aia7DWUovW5MVo+RvVBz6lYENmlsGMNb8vCJ7xp7SyPXPBmYFAJv8ngcPyNanMY wSOxcIb5T8zxwzR4nRJell5mRmyRfif4dxHvVlLOYLIFgWRFVsdwA0LecK16dInBXf34jn uqIpLuzDpevir3chwAWb7cL7edtsAT4= X-Rspamd-Queue-Id: 17204160014 Authentication-Results: imf08.hostedemail.com; dkim=none; dmarc=none; spf=pass (imf08.hostedemail.com: domain of "SRS0=ndWz=35=goodmis.org=rostedt@kernel.org" designates 139.178.84.217 as permitted sender) smtp.mailfrom="SRS0=ndWz=35=goodmis.org=rostedt@kernel.org" X-Rspamd-Server: rspam12 X-Rspam-User: X-Stat-Signature: ooeudd414pg41wjy9f16ymey4z8pmix8 X-HE-Tag: 1669734412-621291 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 04:25:38 +0000 Nadav Amit wrote: > I will need to further debug it, but this issue does not occur every time. >=20 > The kernel didn=E2=80=99t crash exactly - it=E2=80=99s more of a deadlock= . I have lockdep > enabled, so it is not a deadlock that lockdep knows. Could it be that > somehow things just slowed down due to IPIs and mostly-disabled IRQs? I h= ave > no idea. I would need to recreate the scenario.=20 You have lockdep enabled and you are running function tracing with stack trace on? So you are doing a stack trace on *every* function that is traced? I don't think you hit a deadlock, I think you hit a live lock. You could possibly slow the system down so much that when an interrupt finishes it's time for it to be triggered again, and you never make forward progress. >=20 > For the record, I tried to saved some details in the previous email. It w= as > kind of hard to understand what=E2=80=99s going on on the other cores, si= nce the > trace of other cores was interleaved. I extract the parts from that I thi= nk > the refer to the another CPU (yes, the output is really slow, as seen in = the > timestamps): >=20 > [531413.923628] Code: 00 00 31 c0 eb f1 0f 1f 80 00 00 00 00 e8 1b 2e 16 = 3e 55 48 89 e5 c6 07 00 0f 1f 00 f7 c6 00 02 00 00 74 06 fb 0f 1f 44 00 00 = 01 00 00 00 e8 99 da f1 fe 65 8b 05 f2 99 d7 7d 85 c0 74 02 5d >=20 > All code > =3D=3D=3D=3D=3D=3D=3D=3D > 0: 00 00 add %al,(%rax) > 2: 31 c0 xor %eax,%eax > 4: eb f1 jmp 0xfffffffffffffff7 > 6: 0f 1f 80 00 00 00 00 nopl 0x0(%rax) > d: e8 1b 2e 16 3e call 0x3e162e2d > 12: 55 push %rbp > 13: 48 89 e5 mov %rsp,%rbp > 16: c6 07 00 movb $0x0,(%rdi) > 19: 0f 1f 00 nopl (%rax) > 1c: f7 c6 00 02 00 00 test $0x200,%esi > 22: 74 06 je 0x2a > 24: fb sti=20 > 25: 0f 1f 44 00 00 nopl 0x0(%rax,%rax,1) > 2a:* bf 01 00 00 00 mov $0x1,%edi <-- trapping instruction > 2f: e8 99 da f1 fe call 0xfffffffffef1dacd > 34: 65 8b 05 f2 99 d7 7d mov %gs:0x7dd799f2(%rip),%eax # 0x7dd79a2d > 3b: 85 c0 test %eax,%eax > 3d: 74 02 je 0x41 > 3f: 5d pop %rbp >=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: bf 01 00 00 00 mov $0x1,%edi > 5: e8 99 da f1 fe call 0xfffffffffef1daa3 > a: 65 8b 05 f2 99 d7 7d mov %gs:0x7dd799f2(%rip),%eax # 0x7dd79a03 > 11: 85 c0 test %eax,%eax > 13: 74 02 je 0x17 > 15: 5d pop %rbp >=20 > [531414.066765] RSP: 0018:ffffc9000c9a77d8 EFLAGS: 00000206 > [531414.077943] RIP: 0010:smp_call_function_many_cond (kernel/smp.c:443 k= ernel/smp.c:988)=20 > [531416.987351] on_each_cpu_cond_mask (kernel/smp.c:1155)=20 > [531416.205862] ? text_poke_memset (arch/x86/kernel/alternative.c:1296)=20 > [531416.681294] ? text_poke_memset (arch/x86/kernel/alternative.c:1296)=20 > [531417.468443] text_poke_bp_batch (arch/x86/kernel/alternative.c:1553)=20 > [531418.939923] arch_ftrace_update_trampoline (arch/x86/kernel/ftrace.c:5= 00) > [531419.882055] ? ftrace_no_pid_write (kernel/trace/ftrace.c:7864)=20 > [531420.510376] ftrace_update_pid_func (kernel/trace/ftrace.c:374 (discri= minator 1)) > [531420.784703] ftrace_pid_open (kernel/trace/ftrace.c:2918 kernel/trace/= ftrace.c:2932 kernel/trace/ftrace.c:7725 kernel/trace/ftrace.c:7835 kernel/= trace/ftrace.c:7865)=20 > [531421.851294] vfs_open (fs/open.c:1017) >=20 >=20 >=20 Do you have an issue with normal function tracing, and not tracing every function. I should also add this, because it detects recursion faster than the atomic_inc_return() does. -- Steve diff --git a/kernel/trace/trace_functions.c b/kernel/trace/trace_functions.c index 9f1bfbe105e8..93ec756dc24b 100644 --- a/kernel/trace/trace_functions.c +++ b/kernel/trace/trace_functions.c @@ -221,12 +221,18 @@ function_stack_trace_call(unsigned long ip, unsigned = long parent_ip, struct trace_array_cpu *data; unsigned long flags; long disabled; + int bit; int cpu; unsigned int trace_ctx; =20 if (unlikely(!tr->function_enabled)) return; =20 + /* Faster than atomic_inc_return() */ + bit =3D ftrace_test_recursion_trylock(ip, parent_ip); + if (bit < 0) + return; + /* * Need to use raw, since this must be called before the * recursive protection is performed. @@ -244,6 +250,7 @@ function_stack_trace_call(unsigned long ip, unsigned lo= ng parent_ip, =20 atomic_dec(&data->disabled); local_irq_restore(flags); + ftrace_test_recursion_unlock(bit); } =20 static inline bool is_repeat_check(struct trace_array *tr,