[PATCH v1 0/2] PM: sleep: Avoid using pr_cont() in tasks freezing code

[PATCH v1 0/2] PM: sleep: Avoid using pr_cont() in tasks freezing code

[Rafael J. Wysocki]

Hi All,

The first patch in this series rearranges the tasks freezing code used during
system-wide suspend and hibernation to avoid printing continuation messages
with pr_cont() which is problematic.

The second patch refines one more message in that code on top of the first one.

Thanks!

[PATCH v1 1/2] PM: sleep: Avoid using pr_cont() in the tasks freezing code

[Rafael J. Wysocki]

From: Rafael J. Wysocki <rafael.j.wysocki@intel.com>

Using pr_cont() in the tasks freezing code related to system-wide
suspend and hibernation is problematic, because the continuation
messages printed there are susceptible to interspersing with other
unrelated messages which results in output that is hard to
understand.

Address this issue by modifying try_to_freeze_tasks() to print
messages that don't require continuations and adjusting its
callers accordingly.

Reported-by: Thomas Weißschuh <linux@weissschuh.net>
Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
---
 kernel/power/process.c |   21 ++++++++-------------
 1 file changed, 8 insertions(+), 13 deletions(-)

Index: linux-pm/kernel/power/process.c
===================================================================
--- linux-pm.orig/kernel/power/process.c
+++ linux-pm/kernel/power/process.c
@@ -27,6 +27,8 @@ unsigned int __read_mostly freeze_timeou
 
 static int try_to_freeze_tasks(bool user_only)
 {
+	const char *what = user_only ? "user space processes" :
+					"remaining freezable tasks";
 	struct task_struct *g, *p;
 	unsigned long end_time;
 	unsigned int todo;
@@ -36,6 +38,8 @@ static int try_to_freeze_tasks(bool user
 	bool wakeup = false;
 	int sleep_usecs = USEC_PER_MSEC;
 
+	pr_info("Freezing %s\n", what);
+
 	start = ktime_get_boottime();
 
 	end_time = jiffies + msecs_to_jiffies(freeze_timeout_msecs);
@@ -82,7 +86,6 @@ static int try_to_freeze_tasks(bool user
 	elapsed_msecs = ktime_to_ms(elapsed);
 
 	if (todo) {
-		pr_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 +104,8 @@ static int try_to_freeze_tasks(bool user
 			read_unlock(&tasklist_lock);
 		}
 	} else {
-		pr_cont("(elapsed %d.%03d seconds) ", elapsed_msecs / 1000,
-			elapsed_msecs % 1000);
+		pr_info("Freezing %s completed (elapsed %d.%03d seconds)\n",
+			what, elapsed_msecs / 1000, elapsed_msecs % 1000);
 	}
 
 	return todo ? -EBUSY : 0;
@@ -130,14 +133,11 @@ int freeze_processes(void)
 		static_branch_inc(&freezer_active);
 
 	pm_wakeup_clear(0);
-	pr_info("Freezing user space processes ... ");
 	pm_freezing = true;
 	error = try_to_freeze_tasks(true);
-	if (!error) {
+	if (!error)
 		__usermodehelper_set_disable_depth(UMH_DISABLED);
-		pr_cont("done.");
-	}
-	pr_cont("\n");
+
 	BUG_ON(in_atomic());
 
 	/*
@@ -166,14 +166,9 @@ int freeze_kernel_threads(void)
 {
 	int error;
 
-	pr_info("Freezing remaining freezable tasks ... ");
-
 	pm_nosig_freezing = true;
 	error = try_to_freeze_tasks(false);
-	if (!error)
-		pr_cont("done.");
 
-	pr_cont("\n");
 	BUG_ON(in_atomic());
 
 	if (error)

[PATCH v1 2/2] PM: sleep: Refine error message in try_to_freeze_tasks()

[Rafael J. Wysocki]

From: Rafael J. Wysocki <rafael.j.wysocki@intel.com>

A previous change amended try_to_freeze_tasks() with the "what"
variable pointing to a string describing the group of tasks subject to
the freezing which may be used in the error message in there too, so
make that happen.

Accordingly, update sleepgraph.py to catch the modified error message
as appropriate.

Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
---
 kernel/power/process.c             |    4 ++--
 tools/power/pm-graph/sleepgraph.py |    2 +-
 2 files changed, 3 insertions(+), 3 deletions(-)

Index: linux-pm/kernel/power/process.c
===================================================================
--- linux-pm.orig/kernel/power/process.c
+++ linux-pm/kernel/power/process.c
@@ -86,8 +86,8 @@ static int try_to_freeze_tasks(bool user
 	elapsed_msecs = ktime_to_ms(elapsed);
 
 	if (todo) {
-		pr_err("Freezing of tasks %s after %d.%03d seconds "
-		       "(%d tasks refusing to freeze, wq_busy=%d):\n",
+		pr_err("Freezing %s %s after %d.%03d seconds "
+		       "(%d tasks refusing to freeze, wq_busy=%d):\n", what,
 		       wakeup ? "aborted" : "failed",
 		       elapsed_msecs / 1000, elapsed_msecs % 1000,
 		       todo - wq_busy, wq_busy);
Index: linux-pm/tools/power/pm-graph/sleepgraph.py
===================================================================
--- linux-pm.orig/tools/power/pm-graph/sleepgraph.py
+++ linux-pm/tools/power/pm-graph/sleepgraph.py
@@ -1462,7 +1462,7 @@ class Data:
 		'TIMEOUT' : r'(?i).*\bTIMEOUT\b.*',
 		'ABORT'   : r'(?i).*\bABORT\b.*',
 		'IRQ'     : r'.*\bgenirq: .*',
-		'TASKFAIL': r'.*Freezing of tasks *.*',
+		'TASKFAIL': r'.*Freezing .*after *.*',
 		'ACPI'    : r'.*\bACPI *(?P<b>[A-Za-z]*) *Error[: ].*',
 		'DISKFULL': r'.*\bNo space left on device.*',
 		'USBERR'  : r'.*usb .*device .*, error [0-9-]*',

Re: [PATCH v1 0/2] PM: sleep: Avoid using pr_cont() in tasks freezing code

[Petr Mladek]

On Thu 2022-12-01 19:31:59, Rafael J. Wysocki wrote:
> Hi All,
> 
> The first patch in this series rearranges the tasks freezing code used during
> system-wide suspend and hibernation to avoid printing continuation messages
> with pr_cont() which is problematic.
> 
> The second patch refines one more message in that code on top of the first one.

Both patches seems to do what they are supposed to do. Feel free to use:

Reviewed-by: Petr Mladek <pmladek@suse.com>

That said, I am not familiar with the freezer code. For example, I was
not aware of linux-pm/tools/power/pm-graph/sleepgraph.py. Anyway,
both changes make perfect sense and I do not see any problem.

Best Regards,
Petr