[RFC] mm, page_alloc: reintroduce page allocation stall warning

[David Rientjes <rientjes@google.com>]

Previously, we had warnings when a single page allocation took longer
than reasonably expected.  This was introduced in commit 63f53dea0c98
("mm: warn about allocations which stall for too long").

The warning was subsequently reverted in commit 400e22499dd9 ("mm: don't
warn about allocations which stall for too long") but for reasons
unrelated to the warning itself.

Page allocation stalls in excess of 10 seconds are always useful to debug
because they can result in severe userspace unresponsiveness.  Adding
this artifact can be used to correlate with userspace going out to lunch
and to understand the state of memory at the time.

There should be a reasonable expectation that this warning will never
trigger given it is very passive, it starts with a 10 second floor to
begin with.  If it does trigger, this reveals an issue that should be
fixed: a single page allocation should never loop for more than 10
seconds without oom killing to make memory available.

Unlike the original implementation, this implementation only reports
stalls that are at least a second longer than the longest stall reported
thus far.

Signed-off-by: David Rientjes <rientjes@google.com>
---
 mm/page_alloc.c | 32 ++++++++++++++++++++++++++++++++
 1 file changed, 32 insertions(+)

diff --git a/mm/page_alloc.c b/mm/page_alloc.c
--- a/mm/page_alloc.c
+++ b/mm/page_alloc.c
@@ -4706,6 +4706,36 @@ check_retry_cpuset(int cpuset_mems_cookie, struct alloc_context *ac)
 	return false;
 }
 
+static unsigned long max_alloc_stall_warn_msecs = 10 * 1000L;
+
+static void check_alloc_stall_warn(gfp_t gfp_mask, nodemask_t *nodemask,
+				   unsigned int order, unsigned long alloc_start_time)
+{
+	static DEFINE_SPINLOCK(max_alloc_stall_lock);
+	unsigned long stall_msecs = jiffies_to_msecs(jiffies - alloc_start_time);
+	unsigned long flags;
+
+	if (likely(stall_msecs <= READ_ONCE(max_alloc_stall_warn_msecs)))
+		return;
+	if (gfp_mask & __GFP_NOWARN)
+		return;
+
+	spin_lock_irqsave(&max_alloc_stall_lock, flags);
+	if (stall_msecs > max_alloc_stall_warn_msecs) {
+		pr_warn("%s: page allocation stall for %lu secs: order:%d, mode:%#x(%pGg) nodemask=%*pbl",
+			current->comm, stall_msecs / MSEC_PER_SEC, order, gfp_mask, &gfp_mask,
+			nodemask_pr_args(nodemask));
+		cpuset_print_current_mems_allowed();
+		pr_cont("\n");
+		dump_stack();
+		warn_alloc_show_mem(gfp_mask, nodemask);
+
+		/* Only print future stalls that are more than a second longer */
+		WRITE_ONCE(max_alloc_stall_warn_msecs, stall_msecs + MSEC_PER_SEC);
+	}
+	spin_unlock_irqrestore(&max_alloc_stall_lock, flags);
+}
+
 static inline struct page *
 __alloc_pages_slowpath(gfp_t gfp_mask, unsigned int order,
 						struct alloc_context *ac)
@@ -4726,6 +4756,7 @@ __alloc_pages_slowpath(gfp_t gfp_mask, unsigned int order,
 	int reserve_flags;
 	bool compact_first = false;
 	bool can_retry_reserves = true;
+	unsigned long alloc_start_time = jiffies;
 
 	if (unlikely(nofail)) {
 		/*
@@ -4990,6 +5021,7 @@ __alloc_pages_slowpath(gfp_t gfp_mask, unsigned int order,
 	warn_alloc(gfp_mask, ac->nodemask,
 			"page allocation failure: order:%u", order);
 got_pg:
+	check_alloc_stall_warn(gfp_mask, ac->nodemask, order, alloc_start_time);
 	return page;
 }