From nobody Sat Apr 18 04:20:57 2026 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 vger.kernel.org (vger.kernel.org [23.128.96.18]) by smtp.lore.kernel.org (Postfix) with ESMTP id A196EC433EF for ; Mon, 18 Jul 2022 15:12:52 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S235211AbiGRPMu (ORCPT ); Mon, 18 Jul 2022 11:12:50 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:59472 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S234141AbiGRPMr (ORCPT ); Mon, 18 Jul 2022 11:12:47 -0400 Received: from smtp-out2.suse.de (smtp-out2.suse.de [IPv6:2001:67c:2178:6::1d]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id D6B421CFEE for ; Mon, 18 Jul 2022 08:12:45 -0700 (PDT) Received: from relay2.suse.de (relay2.suse.de [149.44.160.134]) by smtp-out2.suse.de (Postfix) with ESMTP id 1769E20113; Mon, 18 Jul 2022 15:12:44 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=suse.com; s=susede1; t=1658157164; h=from:from:reply-to:date:date:message-id:message-id:to:to:cc:cc: mime-version:mime-version: content-transfer-encoding:content-transfer-encoding; bh=n6LVjaU4a6ZqK4u6O9u+Kak/7hh30ZC7LW8h15/5TNQ=; b=YW1yP+oScnnss1fEGR8gDuv7b/Y0UQhHpO9M1aypLFmJteAsU02Yaev3O3bkvutzPSIDOa 6TWKbXERfig1vk7n+zUikahEuBHMa/ah/EL9hCGXdl0JsVqsZCoQPWNUSi/L68psqd0Ngt PoDzF0jotSdp8omAlTUSebeiNqbLPvE= Received: from alley.suse.cz (unknown [10.100.201.202]) by relay2.suse.de (Postfix) with ESMTP id B962E2C141; Mon, 18 Jul 2022 15:12:42 +0000 (UTC) From: Petr Mladek To: Steven Rostedt , "Paul E . McKenney" , John Ogness Cc: Sergey Senozhatsky , Marco Elver , kasan-dev@googlegroups.com, Thomas Gleixner , Johannes Berg , Alexander Potapenko , Dmitry Vyukov , Naresh Kamboju , Peter Zijlstra , Linux Kernel Functional Testing , linux-kernel@vger.kernel.org, Petr Mladek Subject: [PATCH v2] printk: Make console tracepoint safe in NMI() context Date: Mon, 18 Jul 2022 17:11:43 +0200 Message-Id: <20220718151143.32112-1-pmladek@suse.com> X-Mailer: git-send-email 2.35.3 MIME-Version: 1.0 Content-Transfer-Encoding: quoted-printable Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Type: text/plain; charset="utf-8" The commit 701850dc0c31bfadf75a0 ("printk, tracing: fix console tracepoint") moved the tracepoint from console_unlock() to vprintk_store(). As a result, it might be called in any context and triggered the following warning: WARNING: CPU: 1 PID: 16462 at include/trace/events/printk.h:10 printk_spr= int+0x81/0xda Modules linked in: ppdev parport_pc parport CPU: 1 PID: 16462 Comm: event_benchmark Not tainted 5.19.0-rc5-test+ #5 Hardware name: MSI MS-7823/CSM-H87M-G43 (MS-7823), BIOS V1.6 02/22/2014 EIP: printk_sprint+0x81/0xda Code: 89 d8 e8 88 fc 33 00 e9 02 00 00 00 eb 6b 64 a1 a4 b8 91 c1 e8 fd d= 6 ff ff 84 c0 74 5c 64 a1 14 08 92 c1 a9 00 00 f0 00 74 02 <0f> 0b 64 ff 05= 14 08 92 c1 b8 e0 c4 6b c1 e8 a5 dc 00 00 89 c7 e8 EAX: 80110001 EBX: c20a52f8 ECX: 0000000c EDX: 6d203036 ESI: 3df6004c EDI: 00000000 EBP: c61fbd7c ESP: c61fbd70 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068 EFLAGS: 00010006 CR0: 80050033 CR2: b7efc000 CR3: 05b80000 CR4: 001506f0 Call Trace: vprintk_store+0x24b/0x2ff vprintk+0x37/0x4d _printk+0x14/0x16 nmi_handle+0x1ef/0x24e ? find_next_bit.part.0+0x13/0x13 ? find_next_bit.part.0+0x13/0x13 ? function_trace_call+0xd8/0xd9 default_do_nmi+0x57/0x1af ? trace_hardirqs_off_finish+0x2a/0xd9 ? to_kthread+0xf/0xf exc_nmi+0x9b/0xf4 asm_exc_nmi+0xae/0x29c It comes from: #define __DO_TRACE(name, args, cond, rcuidle) \ [...] /* srcu can't be used from NMI */ \ WARN_ON_ONCE(rcuidle && in_nmi()); \ It might be possible to make srcu working in NMI. But it would be slower on some architectures. It is not worth doing it just because of this tracepoint. It would be possible to disable this tracepoint in NMI or in rcuidle context. Where the rcuidle context looks more rare and thus more acceptable to be ignored. Alternative solution would be to move the tracepoint back to console code. But the location is less reliable by definition. Also the synchronization against other tracing messages is much worse. Let's ignore the tracepoint in rcuidle context as the least evil solution. Link: https://lore.kernel.org/r/20220712151655.GU1790663@paulmck-ThinkPad-P= 17-Gen-1 Suggested-by: Steven Rostedt Signed-off-by: Petr Mladek Acked-by: Paul E. McKenney --- Changes against v1: + use rcu_is_watching() instead of rcu_is_idle_cpu() include/trace/events/printk.h | 9 ++++++++- kernel/printk/printk.c | 2 +- 2 files changed, 9 insertions(+), 2 deletions(-) diff --git a/include/trace/events/printk.h b/include/trace/events/printk.h index 13d405b2fd8b..5485513d8838 100644 --- a/include/trace/events/printk.h +++ b/include/trace/events/printk.h @@ -7,11 +7,18 @@ =20 #include =20 -TRACE_EVENT(console, +TRACE_EVENT_CONDITION(console, TP_PROTO(const char *text, size_t len), =20 TP_ARGS(text, len), =20 + /* + * trace_console_rcuidle() is not working in NMI. printk() + * is used more often in NMI than in rcuidle context. + * Choose the less evil solution here. + */ + TP_CONDITION(rcu_is_watching()), + TP_STRUCT__entry( __dynamic_array(char, msg, len + 1) ), diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c index b49c6ff6dca0..bd76a45ecc7f 100644 --- a/kernel/printk/printk.c +++ b/kernel/printk/printk.c @@ -2108,7 +2108,7 @@ static u16 printk_sprint(char *text, u16 size, int fa= cility, } } =20 - trace_console_rcuidle(text, text_len); + trace_console(text, text_len); =20 return text_len; } --=20 2.35.3