diff mbox series

[v2,3/3] power: process: use explicit levels for printk continuations

Message ID 20221125190948.2062-4-linux@weissschuh.net
State New
Headers
Series printk: introduce new macros pr_<level>_cont() |

Commit Message

Thomas Weißschuh Nov. 25, 2022, 7:09 p.m. UTC 
  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 <linux@weissschuh.net>
---
 kernel/power/process.c | 18 +++++++++---------
 1 file changed, 9 insertions(+), 9 deletions(-)

Comments

Joe Perches Nov. 25, 2022, 7:53 p.m. UTC | #1 
On Fri, 2022-11-25 at 20:09 +0100, Thomas Weißschuh wrote:
> 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 <linux@weissschuh.net>
> ---
>  kernel/power/process.c | 18 +++++++++---------
>  1 file changed, 9 insertions(+), 9 deletions(-)
> 
> diff --git 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");

I think this isn't needed because of the immediately following pr_err.

>  		pr_err("Freezing of tasks %s after %d.%03d seconds "
>  		       "(%d tasks refusing to freeze, wq_busy=%d):\n",
>  		       wakeup ? "aborted" : "failed",
Thomas Weißschuh Nov. 25, 2022, 8:41 p.m. UTC | #2 
On 2022-11-25 11:53-0800, Joe Perches wrote:
> On Fri, 2022-11-25 at 20:09 +0100, Thomas Weißschuh wrote:
>> 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 <linux@weissschuh.net>
>> ---
>>  kernel/power/process.c | 18 +++++++++---------
>>  1 file changed, 9 insertions(+), 9 deletions(-)
>> 
>> diff --git 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");
> 
> I think this isn't needed because of the immediately following pr_err.

The pr_cont() itself or the conversion to pr_info_cont() is not needed?

Personally I would prefer to keep the patch as is.

If only the conversion is not needed for consistency with the rest of the file.
If the pr_cont() in general is not needed it should be changed in a dedicated
patch (by somebody who knows this code better).

>>  		pr_err("Freezing of tasks %s after %d.%03d seconds "
>>  		       "(%d tasks refusing to freeze, wq_busy=%d):\n",
>>  		       wakeup ? "aborted" : "failed",
>
Petr Mladek Nov. 30, 2022, 3:06 p.m. UTC | #3 
On Fri 2022-11-25 21:41:55, Thomas Weißschuh wrote:
> On 2022-11-25 11:53-0800, Joe Perches wrote:
> > On Fri, 2022-11-25 at 20:09 +0100, Thomas Weißschuh wrote:
> >> 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 <linux@weissschuh.net>
> >> ---
> >>  kernel/power/process.c | 18 +++++++++---------
> >>  1 file changed, 9 insertions(+), 9 deletions(-)
> >> 
> >> diff --git 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");
> > 
> > I think this isn't needed because of the immediately following pr_err.

Great catch.


> The pr_cont() itself or the conversion to pr_info_cont() is not needed?

The pr_cont() was needed before the commit 4bcc595ccd80decb42450
("printk: reinstate KERN_CONT for printing continuation lines").

Before this commit, lines were appended even without KERN_CONT
when the previous line did not end with "\n".

The above commit caused that only lines with KERN_CONT will be
appended.

We have the code:

		pr_cont("\n");
		pr_err("Freezing of tasks %s after %d.%03d seconds "

The pr_cont() is not needed here because pr_err() does not have
KERN_CONT. It will always start on a new line.

> Personally I would prefer to keep the patch as is.
> 
> If only the conversion is not needed for consistency with the rest of the file.
> If the pr_cont() in general is not needed it should be changed in a dedicated
> patch (by somebody who knows this code better).

I agree that it should be removed in a separate patch. The commit
message should mention the commit that modified the KERN_CONT
handling.

Best Regards,
Petr
diff mbox series

Patch

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");
 }