[PATCH 1/3] PM: hibernate: Print speed statistics of copy_data_pages()

[Nícolas F. R. A. Prado]

copy_data_pages() can take a long (multi-second) time to finish, and
currently the only indication of that is the timestamp difference
between print messages right before and right after. The timestamp is
also immediately reset afterwards to the time before image creation,
making it even harder to spot this delay. And this function runs in a
critical section with a single CPU online and syscore suspended, so it
should be kept as quick as possible to keep the system responsive.

Call into swsusp_show_speed() to report the amount of data, time taken,
and copy speed of copy_data_pages() to make it easier to spot delays and
verify performance improvements. The current time is obtained through
sched_clock() instead of ktime_get() since timekeeping is suspended in
this region.

Signed-off-by: Nícolas F. R. A. Prado <nfraprado@xxxxxxxxxxxxx>
---
 kernel/power/snapshot.c | 5 +++++
 1 file changed, 5 insertions(+)

diff --git a/kernel/power/snapshot.c b/kernel/power/snapshot.c
index e249e5786fbc..4f452baf31dc 100644
--- a/kernel/power/snapshot.c
+++ b/kernel/power/snapshot.c
@@ -13,6 +13,7 @@
 #include <linux/version.h>
 #include <linux/module.h>
 #include <linux/mm.h>
+#include <linux/sched/clock.h>
 #include <linux/suspend.h>
 #include <linux/delay.h>
 #include <linux/bitops.h>
@@ -2109,6 +2110,7 @@ static int swsusp_alloc(struct memory_bitmap *copy_bm,
 asmlinkage __visible int swsusp_save(void)
 {
 	unsigned int nr_pages, nr_highmem;
+	ktime_t start, stop;
 
 	pr_info("Creating image:\n");
 
@@ -2132,7 +2134,10 @@ asmlinkage __visible int swsusp_save(void)
 	 * Kill them.
 	 */
 	drain_local_pages(NULL);
+	start = ns_to_ktime(sched_clock());
 	nr_copy_pages = copy_data_pages(&copy_bm, &orig_bm, &zero_bm);
+	stop = ns_to_ktime(sched_clock());
+	swsusp_show_speed(start, stop, nr_copy_pages, "Copied");
 
 	/*
 	 * End of critical section. From now on, we can write to memory,

-- 
2.53.0