From patchwork Fri Nov 25 19:09:46 2022 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 8bit X-Patchwork-Submitter: =?utf-8?q?Thomas_Wei=C3=9Fschuh?= X-Patchwork-Id: 13056231 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 991ADC4321E for ; Fri, 25 Nov 2022 19:10:20 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S229926AbiKYTKS (ORCPT ); Fri, 25 Nov 2022 14:10:18 -0500 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:40702 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S229816AbiKYTKQ (ORCPT ); Fri, 25 Nov 2022 14:10:16 -0500 Received: from todd.t-8ch.de (todd.t-8ch.de [159.69.126.157]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 13F965474F for ; Fri, 25 Nov 2022 11:10:16 -0800 (PST) From: =?utf-8?q?Thomas_Wei=C3=9Fschuh?= DKIM-Signature: v=1; a=rsa-sha256; c=simple/simple; d=weissschuh.net; s=mail; t=1669403409; bh=Cfs+sOQDL6GBgQ3fenqAT1FujV3he1f3Lpmpy6WNGIY=; h=From:To:Cc:Subject:Date:In-Reply-To:References:From; b=CdjwjO5hHtwgwX90USoA3/oYV6gNtrbEg2T9br83TK4zdDJz6VEWprrsMkCEyvepp PUB2jhZPZu/9ERMHp8awa/NpE4O55WPPfRNpkBArX3qyjoKkMYY6qFKJ6AYFFZNbTp LoHFvTGLPJslEBlrSWMXLfJZLDQva+Kk9Vuypl2s= To: "Rafael J. Wysocki" , Pavel Machek , Len Brown , linux-pm@vger.kernel.org, Petr Mladek , Sergey Senozhatsky , Andy Whitcroft , Joe Perches Cc: =?utf-8?q?Thomas_Wei=C3=9Fschuh?= , linux-kernel@vger.kernel.org, Steven Rostedt , Dwaipayan Ray , Lukas Bulwahn Subject: [PATCH v2 1/3] printk: introduce new macros pr__cont() Date: Fri, 25 Nov 2022 20:09:46 +0100 Message-Id: <20221125190948.2062-2-linux@weissschuh.net> X-Mailer: git-send-email 2.38.1 In-Reply-To: <20221125190948.2062-1-linux@weissschuh.net> References: <20221125190948.2062-1-linux@weissschuh.net> MIME-Version: 1.0 X-Developer-Signature: v=1; a=ed25519-sha256; t=1669403373; l=2153; i=linux@weissschuh.net; s=20211113; h=from:subject; bh=Cfs+sOQDL6GBgQ3fenqAT1FujV3he1f3Lpmpy6WNGIY=; b=HrAjdosSOqn753OZecTREHBNiVZHFXNRlI3g1j+9iLw4cn/f064kUy61f5eptIvvv5OiNU3b0iWm VqdxqwJmBCtf2AP3qCG9Gek6WHudS6izrr6XXVq30kQbg1PoiGz4 X-Developer-Key: i=linux@weissschuh.net; a=ed25519; pk=9LP6KM4vD/8CwHW7nouRBhWLyQLcK1MkP6aTZbzUlj4= Precedence: bulk List-ID: X-Mailing-List: linux-pm@vger.kernel.org These macros emit continuation messages with explicit levels. In case the continuation is logged separately from the original message it will retain its level instead of falling back to KERN_DEFAULT. This remedies the issue that logs filtered by level contain stray continuation messages without context. Suggested-by: Petr Mladek Signed-off-by: Thomas Weißschuh --- include/linux/printk.h | 23 +++++++++++++++++++++++ 1 file changed, 23 insertions(+) diff --git a/include/linux/printk.h b/include/linux/printk.h index 8c81806c2e99..8f564c38f121 100644 --- a/include/linux/printk.h +++ b/include/linux/printk.h @@ -537,6 +537,8 @@ struct pi_entry { * This macro expands to a printk with KERN_CONT loglevel. It should only be * used when continuing a log message with no newline ('\n') enclosed. Otherwise * it defaults back to KERN_DEFAULT loglevel. + * + * Use the dedicated pr__cont() macros instead. */ #define pr_cont(fmt, ...) \ printk(KERN_CONT fmt, ##__VA_ARGS__) @@ -701,6 +703,27 @@ do { \ no_printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__) #endif +/* + * Print a continuation message with level. In case the continuation is split + * from the main message it preserves the level. + */ + +#define pr_emerg_cont(fmt, ...) \ + printk(KERN_EMERG KERN_CONT pr_fmt(fmt), ##__VA_ARGS__) +#define pr_alert_cont(fmt, ...) \ + printk(KERN_ALERT KERN_CONT pr_fmt(fmt), ##__VA_ARGS__) +#define pr_crit_cont(fmt, ...) \ + printk(KERN_CRIT KERN_CONT pr_fmt(fmt), ##__VA_ARGS__) +#define pr_err_cont(fmt, ...) \ + printk(KERN_ERR KERN_CONT pr_fmt(fmt), ##__VA_ARGS__) +#define pr_warn_cont(fmt, ...) \ + printk(KERN_WARN KERN_CONT pr_fmt(fmt), ##__VA_ARGS__) +#define pr_notice_cont(fmt, ...) \ + printk(KERN_NOTICE KERN_CONT pr_fmt(fmt), ##__VA_ARGS__) +#define pr_info_cont(fmt, ...) \ + printk(KERN_INFO KERN_CONT pr_fmt(fmt), ##__VA_ARGS__) +/* no pr_debug_ratelimited, it doesn't make sense with CONFIG_DYNAMIC_DEBUG. */ + extern const struct file_operations kmsg_fops; enum { From patchwork Fri Nov 25 19:09:47 2022 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 8bit X-Patchwork-Submitter: =?utf-8?q?Thomas_Wei=C3=9Fschuh?= X-Patchwork-Id: 13056230 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 E6133C4332F for ; Fri, 25 Nov 2022 19:10:17 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S229812AbiKYTKQ (ORCPT ); Fri, 25 Nov 2022 14:10:16 -0500 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:40692 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S229475AbiKYTKP (ORCPT ); Fri, 25 Nov 2022 14:10:15 -0500 Received: from todd.t-8ch.de (todd.t-8ch.de [159.69.126.157]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id E21AA5474F; Fri, 25 Nov 2022 11:10:12 -0800 (PST) From: =?utf-8?q?Thomas_Wei=C3=9Fschuh?= DKIM-Signature: v=1; a=rsa-sha256; c=simple/simple; d=weissschuh.net; s=mail; t=1669403409; bh=Cc2ClTVm2l8saukQMqFH86xff8jJ/Zkmp6yCVTzmAQI=; h=From:To:Cc:Subject:Date:In-Reply-To:References:From; b=CNXSiJN+v/zXwLWrJgqlJGajJyPZ+7jU7x3u9+ts6auIIMHQWL5v/ZFxECTf3QJxf zUzvLrNg/oI6Y8MFxCFjNNUIA0f2vVUe3HV1ZF3wsuC5TbBcJfacROfdIgv6thy+rX tjIWAjg8dDcQm8M7EkhL7B9Fh3bFhr83UEe3LuDY= To: "Rafael J. Wysocki" , Pavel Machek , Len Brown , linux-pm@vger.kernel.org, Petr Mladek , Sergey Senozhatsky , Andy Whitcroft , Joe Perches Cc: =?utf-8?q?Thomas_Wei=C3=9Fschuh?= , linux-kernel@vger.kernel.org, Steven Rostedt , Dwaipayan Ray , Lukas Bulwahn Subject: [PATCH v2 2/3] checkpatch: handle new pr__cont macros Date: Fri, 25 Nov 2022 20:09:47 +0100 Message-Id: <20221125190948.2062-3-linux@weissschuh.net> X-Mailer: git-send-email 2.38.1 In-Reply-To: <20221125190948.2062-1-linux@weissschuh.net> References: <20221125190948.2062-1-linux@weissschuh.net> MIME-Version: 1.0 X-Developer-Signature: v=1; a=ed25519-sha256; t=1669403373; l=1632; i=linux@weissschuh.net; s=20211113; h=from:subject; bh=Cc2ClTVm2l8saukQMqFH86xff8jJ/Zkmp6yCVTzmAQI=; b=Uv1SmRxhkAlXNeJpl8GBYcYw6GTCbSPRtF1w2m1VcrJcH7C7QOYyiOMZrST2deFGQxKEXv9JWLkg m0rSB25MBJRBtXF+hi+Jg+AwA7gpFO20zxvfQkexKukujd4f9lHt X-Developer-Key: i=linux@weissschuh.net; a=ed25519; pk=9LP6KM4vD/8CwHW7nouRBhWLyQLcK1MkP6aTZbzUlj4= Precedence: bulk List-ID: X-Mailing-List: linux-pm@vger.kernel.org These new macros from include/linux/printk.h replace the usage of plain pr_cont(). Signed-off-by: Thomas Weißschuh --- scripts/checkpatch.pl | 10 ++++++++-- 1 file changed, 8 insertions(+), 2 deletions(-) diff --git a/scripts/checkpatch.pl b/scripts/checkpatch.pl index 1e5e66ae5a52..fb1747639c9c 100755 --- a/scripts/checkpatch.pl +++ b/scripts/checkpatch.pl @@ -590,7 +590,7 @@ our $zero_initializer = qr{(?:(?:0[xX])?0+$Int_type?|NULL|false)\b}; our $logFunctions = qr{(?x: printk(?:_ratelimited|_once|_deferred_once|_deferred|)| - (?:[a-z0-9]+_){1,2}(?:printk|emerg|alert|crit|err|warning|warn|notice|info|debug|dbg|vdbg|devel|cont|WARN)(?:_ratelimited|_once|)| + (?:[a-z0-9]+_){1,2}(?:printk|emerg|alert|crit|err|warning|warn|notice|info|debug|dbg|vdbg|devel|cont|WARN)(?:_ratelimited|_once|_cont|)| TP_printk| WARN(?:_RATELIMIT|_ONCE|)| panic| @@ -6374,11 +6374,17 @@ sub process { } # check for logging continuations - if ($line =~ /\bprintk\s*\(\s*KERN_CONT\b|\bpr_cont\s*\(/) { + if ($line =~ /\bprintk\s*\(\s*KERN_CONT\b|\bpr_([a-z]+_)?cont\s*\(/) { WARN("LOGGING_CONTINUATION", "Avoid logging continuation uses where feasible\n" . $herecurr); } +# check for logging continuations without explicit level + if ($line =~ /\bpr_cont\s*\(/) { + WARN("LOGGING_CONTINUATION_WITHOUT_LEVEL", + "Avoid logging continuation without level\n" . $herecurr); + } + # check for unnecessary use of %h[xudi] and %hh[xudi] in logging functions if (defined $stat && $line =~ /\b$logFunctions\s*\(/ && From patchwork Fri Nov 25 19:09:48 2022 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 8bit X-Patchwork-Submitter: =?utf-8?q?Thomas_Wei=C3=9Fschuh?= X-Patchwork-Id: 13056232 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 A79A7C47088 for ; Fri, 25 Nov 2022 19:10:20 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S229816AbiKYTKS (ORCPT ); Fri, 25 Nov 2022 14:10:18 -0500 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:40708 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S229870AbiKYTKR (ORCPT ); Fri, 25 Nov 2022 14:10:17 -0500 Received: from todd.t-8ch.de (todd.t-8ch.de [159.69.126.157]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 94F6A554E9 for ; Fri, 25 Nov 2022 11:10:16 -0800 (PST) From: =?utf-8?q?Thomas_Wei=C3=9Fschuh?= DKIM-Signature: v=1; a=rsa-sha256; c=simple/simple; d=weissschuh.net; s=mail; t=1669403409; bh=s6KcxTNSDlbspLXYkAwhQ7ixHOFLXXeH4opgjulE3Dk=; h=From:To:Cc:Subject:Date:In-Reply-To:References:From; b=NpSyhfLLpJafJPxciAM1hvxxl3WMxPo3EpdLtlKqczTp/ZZ0/Ekc9ZqON3/B86Gbe aIsyj0Z9IOpA940sugiPplWBhAHkXPkTGuHAQHt51PmcxiKrGBH21aHRQRpH7jrnXH L8p0AJFOS8GOTMPD/yB2WECXSNAdqbQ4bgSinlKk= To: "Rafael J. Wysocki" , Pavel Machek , Len Brown , linux-pm@vger.kernel.org, Petr Mladek , Sergey Senozhatsky , Andy Whitcroft , Joe Perches Cc: =?utf-8?q?Thomas_Wei=C3=9Fschuh?= , linux-kernel@vger.kernel.org, Steven Rostedt , Dwaipayan Ray , Lukas Bulwahn Subject: [PATCH v2 3/3] power: process: use explicit levels for printk continuations Date: Fri, 25 Nov 2022 20:09:48 +0100 Message-Id: <20221125190948.2062-4-linux@weissschuh.net> X-Mailer: git-send-email 2.38.1 In-Reply-To: <20221125190948.2062-1-linux@weissschuh.net> References: <20221125190948.2062-1-linux@weissschuh.net> MIME-Version: 1.0 X-Developer-Signature: v=1; a=ed25519-sha256; t=1669403373; l=2640; i=linux@weissschuh.net; s=20211113; h=from:subject; bh=s6KcxTNSDlbspLXYkAwhQ7ixHOFLXXeH4opgjulE3Dk=; b=GkGBljbJ6DHMkREQP115g4j9iS5KQRe8ZSb8HRM6GJfL3NuL56f01HHVCLvxCka9QRIwmeEyQw7O fnNTXMAsBF9mGgmkSiAuSl04zDZTLsQxO5eLurZ64NmjKYbyBHjg X-Developer-Key: i=linux@weissschuh.net; a=ed25519; pk=9LP6KM4vD/8CwHW7nouRBhWLyQLcK1MkP6aTZbzUlj4= Precedence: bulk List-ID: X-Mailing-List: linux-pm@vger.kernel.org Many of the printk messages emitted during suspend and resume are emitted in fragments using pr_cont()/KERN_CONT. As during suspend and resume a lot of operations are happing in the kernel the chances are high that the fragments are interspersed with unrelated messages. In this case if no explicit level is specified for the fragments the standard level is applied, which by default is KERN_WARNING. If the user is only observing KERN_WARNING and *not* KERN_INFO messages they will see incomplete message fragments. By specifing the correct printk level also with the continuations this mismatch can be avoided. Also it reduces the amount of false-positive KERN_WARNING messages. Signed-off-by: Thomas Weißschuh --- kernel/power/process.c | 18 +++++++++--------- 1 file changed, 9 insertions(+), 9 deletions(-) diff --git a/kernel/power/process.c b/kernel/power/process.c index ddd9988327fe..698a823033e4 100644 --- a/kernel/power/process.c +++ b/kernel/power/process.c @@ -82,7 +82,7 @@ static int try_to_freeze_tasks(bool user_only) elapsed_msecs = ktime_to_ms(elapsed); if (todo) { - pr_cont("\n"); + pr_info_cont("\n"); pr_err("Freezing of tasks %s after %d.%03d seconds " "(%d tasks refusing to freeze, wq_busy=%d):\n", wakeup ? "aborted" : "failed", @@ -101,8 +101,8 @@ static int try_to_freeze_tasks(bool user_only) read_unlock(&tasklist_lock); } } else { - pr_cont("(elapsed %d.%03d seconds) ", elapsed_msecs / 1000, - elapsed_msecs % 1000); + pr_info_cont("(elapsed %d.%03d seconds) ", elapsed_msecs / 1000, + elapsed_msecs % 1000); } return todo ? -EBUSY : 0; @@ -135,9 +135,9 @@ int freeze_processes(void) error = try_to_freeze_tasks(true); if (!error) { __usermodehelper_set_disable_depth(UMH_DISABLED); - pr_cont("done."); + pr_info_cont("done."); } - pr_cont("\n"); + pr_info_cont("\n"); BUG_ON(in_atomic()); /* @@ -171,9 +171,9 @@ int freeze_kernel_threads(void) pm_nosig_freezing = true; error = try_to_freeze_tasks(false); if (!error) - pr_cont("done."); + pr_info_cont("done."); - pr_cont("\n"); + pr_info_cont("\n"); BUG_ON(in_atomic()); if (error) @@ -215,7 +215,7 @@ void thaw_processes(void) usermodehelper_enable(); schedule(); - pr_cont("done.\n"); + pr_info_cont("done.\n"); trace_suspend_resume(TPS("thaw_processes"), 0, false); } @@ -236,5 +236,5 @@ void thaw_kernel_threads(void) read_unlock(&tasklist_lock); schedule(); - pr_cont("done.\n"); + pr_info_cont("done.\n"); }