Skip to contentSkip to conversation

rcu: endless stalls

PATCH Mike Galbraith 4 participants 15 messages Jun 11, 2012 – Jun 15, 2012

lore
Share & tools
lore
#0 lore raw

Greetings,

I received a report of a 48 core UV box hitting a gripe, taking longer than timeout to emit same, so box griped endlessly, forcing reboot.

The below might prevent that.. and bust other stuff for free :)

rcu: one gripe at a time please

Not-compiled-by:
Not-signed-off-by:
Not-etc-by:

kernel/rcutree.c +27 -18
index 0da7b88..6462056d6 100644
@@ -818,10 +818,25 @@ static void print_cpu_stall(struct rcu_state *rsp)
 	set_need_resched();  /* kick ourselves to get things going. */
 }
 
+/**
+ * rcu_cpu_stall_reset - prevent further stall warnings in current grace period
+ *
+ * Set the stall-warning timeout way off into the future, thus preventing
+ * any RCU CPU stall-warning messages from appearing in the current set of
+ * RCU grace periods.
+ *
+ * The caller must disable hard irqs.
+ */
+void rcu_cpu_stall_reset(void)
+{
+	rcu_sched_state.jiffies_stall = jiffies + ULONG_MAX / 2;
+	rcu_bh_state.jiffies_stall = jiffies + ULONG_MAX / 2;
+	rcu_preempt_stall_reset();
+}
+
 static void check_cpu_stall(struct rcu_state *rsp, struct rcu_data *rdp)
 {
-	unsigned long j;
-	unsigned long js;
+	unsigned long j, js, flags;
 	struct rcu_node *rnp;
 
 	if (rcu_cpu_stall_suppress)
@@ -832,13 +847,23 @@ static void check_cpu_stall(struct rcu_state *rsp, struct rcu_data *rdp)
 	if ((ACCESS_ONCE(rnp->qsmask) & rdp->grpmask) && ULONG_CMP_GE(j, js)) {
 
 		/* We haven't checked in, so go dump stack. */
+		rcu_cpu_stall_suppress = 1;
 		print_cpu_stall(rsp);
+		local_irq_save(flags);
+		rcu_cpu_stall_reset();
+		local_irq_restore(flags);
+		rcu_cpu_stall_suppress = 0;
 
 	} else if (rcu_gp_in_progress(rsp) &&
 		   ULONG_CMP_GE(j, js + RCU_STALL_RAT_DELAY)) {
 
 		/* They had a few time units to dump stack, so complain. */
+		rcu_cpu_stall_suppress = 1;
 		print_other_cpu_stall(rsp);
+		local_irq_save(flags);
+		rcu_cpu_stall_reset();
+		local_irq_restore(flags);
+		rcu_cpu_stall_suppress = 0;
 	}
 }
 
@@ -848,22 +873,6 @@ static int rcu_panic(struct notifier_block *this, unsigned long ev, void *ptr)
 	return NOTIFY_DONE;
 }
 
-/**
- * rcu_cpu_stall_reset - prevent further stall warnings in current grace period
- *
- * Set the stall-warning timeout way off into the future, thus preventing
- * any RCU CPU stall-warning messages from appearing in the current set of
- * RCU grace periods.
- *
- * The caller must disable hard irqs.
- */
-void rcu_cpu_stall_reset(void)
-{
-	rcu_sched_state.jiffies_stall = jiffies + ULONG_MAX / 2;
-	rcu_bh_state.jiffies_stall = jiffies + ULONG_MAX / 2;
-	rcu_preempt_stall_reset();
-}
-
 static struct notifier_block rcu_panic_block = {
 	.notifier_call = rcu_panic,
 };
#1 lore raw
Quoted 4 lines · Mike Galbraith

Greetings,

I received a report of a 48 core UV box hitting a gripe, taking longer than timeout to emit same, so box griped endlessly, forcing reboot.

So it took minutes to print an RCU CPU stall warning? On only 48 CPUs?

If so, yow!!!

My guess is that rcu_cpu_stall_suppress must be manipulated atomically for this to work reliably, for example, using xchg().

Thanx, Paul

Quoted 89 lines

The below might prevent that.. and bust other stuff for free :)

rcu: one gripe at a time please

Not-compiled-by:
Not-signed-off-by:
Not-etc-by:

kernel/rcutree.c +27 -18
index 0da7b88..6462056d6 100644
@@ -818,10 +818,25 @@ static void print_cpu_stall(struct rcu_state *rsp)
 	set_need_resched();  /* kick ourselves to get things going. */
 }
 
+/**
+ * rcu_cpu_stall_reset - prevent further stall warnings in current grace period
+ *
+ * Set the stall-warning timeout way off into the future, thus preventing
+ * any RCU CPU stall-warning messages from appearing in the current set of
+ * RCU grace periods.
+ *
+ * The caller must disable hard irqs.
+ */
+void rcu_cpu_stall_reset(void)
+{
+	rcu_sched_state.jiffies_stall = jiffies + ULONG_MAX / 2;
+	rcu_bh_state.jiffies_stall = jiffies + ULONG_MAX / 2;
+	rcu_preempt_stall_reset();
+}
+
 static void check_cpu_stall(struct rcu_state *rsp, struct rcu_data *rdp)
 {
-	unsigned long j;
-	unsigned long js;
+	unsigned long j, js, flags;
 	struct rcu_node *rnp;
 
 	if (rcu_cpu_stall_suppress)
@@ -832,13 +847,23 @@ static void check_cpu_stall(struct rcu_state *rsp, struct rcu_data *rdp)
 	if ((ACCESS_ONCE(rnp->qsmask) & rdp->grpmask) && ULONG_CMP_GE(j, js)) {
 
 		/* We haven't checked in, so go dump stack. */
+		rcu_cpu_stall_suppress = 1;
 		print_cpu_stall(rsp);
+		local_irq_save(flags);
+		rcu_cpu_stall_reset();
+		local_irq_restore(flags);
+		rcu_cpu_stall_suppress = 0;
 
 	} else if (rcu_gp_in_progress(rsp) &&
 		   ULONG_CMP_GE(j, js + RCU_STALL_RAT_DELAY)) {
 
 		/* They had a few time units to dump stack, so complain. */
+		rcu_cpu_stall_suppress = 1;
 		print_other_cpu_stall(rsp);
+		local_irq_save(flags);
+		rcu_cpu_stall_reset();
+		local_irq_restore(flags);
+		rcu_cpu_stall_suppress = 0;
 	}
 }
 
@@ -848,22 +873,6 @@ static int rcu_panic(struct notifier_block *this, unsigned long ev, void *ptr)
 	return NOTIFY_DONE;
 }
 
-/**
- * rcu_cpu_stall_reset - prevent further stall warnings in current grace period
- *
- * Set the stall-warning timeout way off into the future, thus preventing
- * any RCU CPU stall-warning messages from appearing in the current set of
- * RCU grace periods.
- *
- * The caller must disable hard irqs.
- */
-void rcu_cpu_stall_reset(void)
-{
-	rcu_sched_state.jiffies_stall = jiffies + ULONG_MAX / 2;
-	rcu_bh_state.jiffies_stall = jiffies + ULONG_MAX / 2;
-	rcu_preempt_stall_reset();
-}
-
 static struct notifier_block rcu_panic_block = {
 	.notifier_call = rcu_panic,
 };
#2 lore raw
Quoted 9 lines · Paul E. McKenney
Quoted 4 lines · Mike Galbraith

Greetings,

I received a report of a 48 core UV box hitting a gripe, taking longer than timeout to emit same, so box griped endlessly, forcing reboot.

So it took minutes to print an RCU CPU stall warning? On only 48 CPUs?

If so, yow!!!

The report was a tad fuzzy on details, but serial console can take a while at low baud rate, and the box was apparently perma-stalled.

Quoted 2 lines

My guess is that rcu_cpu_stall_suppress must be manipulated atomically for this to work reliably, for example, using xchg().

Ah, thanks.

-Mike

#3 lore raw
Quoted 7 lines · Mike Galbraith
Quoted 6 lines · Paul E. McKenney
Quoted 4 lines · Mike Galbraith

Greetings,

I received a report of a 48 core UV box hitting a gripe, taking longer than timeout to emit same, so box griped endlessly, forcing reboot.

Quoted 6 lines
Quoted 3 lines

So it took minutes to print an RCU CPU stall warning? On only 48 CPUs?

If so, yow!!!

The report was a tad fuzzy on details, but serial console can take a while at low baud rate, and the box was apparently perma-stalled.

Which clearly demands the question "why not increase the serial-console baud rate"... ;-)

Thanx, Paul

Quoted 7 lines
Quoted 2 lines

My guess is that rcu_cpu_stall_suppress must be manipulated atomically for this to work reliably, for example, using xchg().

Ah, thanks.

-Mike

#4 lore raw
In reply to Mike Galbraith
Quoted 7 lines · Mike Galbraith
Quoted 6 lines · Paul E. McKenney
Quoted 4 lines · Mike Galbraith

Greetings,

I received a report of a 48 core UV box hitting a gripe, taking longer than timeout to emit same, so box griped endlessly, forcing reboot.

Quoted 6 lines
Quoted 3 lines

So it took minutes to print an RCU CPU stall warning? On only 48 CPUs?

If so, yow!!!

The report was a tad fuzzy on details, but serial console can take a while at low baud rate, and the box was apparently perma-stalled.

Gee, no wonder it took a while to emit the gripe, there were a few more than 48 CPUs actually.. 4048 more to be precise.

4096 tasks on 4096 CPUs all hammering wait_lock at once r!pretty.

2aa15890 - mm: prevent concurrent unmap_mapping_range() on the same inode

-Mike

#5 lore raw
Quoted 12 lines · Mike Galbraith
Quoted 11 lines · Mike Galbraith
Quoted 9 lines · Paul E. McKenney
Quoted 4 lines · Mike Galbraith

Greetings,

I received a report of a 48 core UV box hitting a gripe, taking longer than timeout to emit same, so box griped endlessly, forcing reboot.

So it took minutes to print an RCU CPU stall warning? On only 48 CPUs?

If so, yow!!!

Quoted 7 lines
Quoted 2 lines

The report was a tad fuzzy on details, but serial console can take a while at low baud rate, and the box was apparently perma-stalled.

Gee, no wonder it took a while to emit the gripe, there were a few more than 48 CPUs actually.. 4048 more to be precise.

4096 tasks on 4096 CPUs all hammering wait_lock at once r!pretty.

That would be bad...

BTW, one other thing on the patch -- it needs to use a separate flag, otherwise there are races with sysfs and panic() updates to the flag.

Quoted 1 line

2aa15890 - mm: prevent concurrent unmap_mapping_range() on the same inode

I confess, you lost me on this one. You believe that this commit is the cause of the RCU CPU stall warnings?

Thanx, Paul

#6 lore raw
Quoted 23 lines · Paul E. McKenney
Quoted 12 lines · Mike Galbraith
Quoted 11 lines · Mike Galbraith
Quoted 9 lines · Paul E. McKenney
Quoted 4 lines · Mike Galbraith

Greetings,

I received a report of a 48 core UV box hitting a gripe, taking longer than timeout to emit same, so box griped endlessly, forcing reboot.

So it took minutes to print an RCU CPU stall warning? On only 48 CPUs?

If so, yow!!!

Quoted 7 lines
Quoted 2 lines

The report was a tad fuzzy on details, but serial console can take a while at low baud rate, and the box was apparently perma-stalled.

Gee, no wonder it took a while to emit the gripe, there were a few more than 48 CPUs actually.. 4048 more to be precise.

4096 tasks on 4096 CPUs all hammering wait_lock at once r!pretty.

That would be bad...

Quoted 7 lines

BTW, one other thing on the patch -- it needs to use a separate flag, otherwise there are races with sysfs and panic() updates to the flag.

Quoted 1 line

2aa15890 - mm: prevent concurrent unmap_mapping_range() on the same inode

I confess, you lost me on this one. You believe that this commit is the cause of the RCU CPU stall warnings?

4096 tasks on 4096 CPUs exit (well, try to) simultaneously.

Call Trace:
                __mutex_lock_slowpath+0x94/0x150
                mutex_lock+0x1a/0x40
                unlink_file_vma+0x3f/0xf0
                free_pgtables+0x40/0x100
                exit_mmap+0xb0/0x120
                mmput+0x49/0x120
                exit_mm+0x122/0x160
                do_exit+0x179/0x8d0
                do_group_exit+0x3d/0xb0
                sys_exit_group+0x12/0x20

Monster box dies screaming.

-Mike

#7 lore raw
Quoted 21 lines · Mike Galbraith
Quoted 4 lines · Paul E. McKenney
Quoted 1 line

2aa15890 - mm: prevent concurrent unmap_mapping_range() on the same inode

I confess, you lost me on this one. You believe that this commit is the cause of the RCU CPU stall warnings?

4096 tasks on 4096 CPUs exit (well, try to) simultaneously.

Call Trace:
                __mutex_lock_slowpath+0x94/0x150
                mutex_lock+0x1a/0x40
                unlink_file_vma+0x3f/0xf0
                free_pgtables+0x40/0x100
                exit_mmap+0xb0/0x120
                mmput+0x49/0x120
                exit_mm+0x122/0x160
                do_exit+0x179/0x8d0
                do_group_exit+0x3d/0xb0
                sys_exit_group+0x12/0x20
Quoted 1 line

Monster box dies screaming.

That commit landed in stable, box with way too many cores (NR_CPUS=0!!) chokes instantly with loads of spinners. Ok, so zillion CPUs grabbing a mutex in lockstep is a bad idea (_having_ zillion?), but is there pilot error involved in a logjam like this?

-Mike

#8 lore raw
Quoted 22 lines · Mike Galbraith
Quoted 21 lines · Mike Galbraith
Quoted 4 lines · Paul E. McKenney
Quoted 1 line

2aa15890 - mm: prevent concurrent unmap_mapping_range() on the same inode

I confess, you lost me on this one. You believe that this commit is the cause of the RCU CPU stall warnings?

4096 tasks on 4096 CPUs exit (well, try to) simultaneously.

Call Trace:
                __mutex_lock_slowpath+0x94/0x150
                mutex_lock+0x1a/0x40
                unlink_file_vma+0x3f/0xf0
                free_pgtables+0x40/0x100
                exit_mmap+0xb0/0x120
                mmput+0x49/0x120
                exit_mm+0x122/0x160
                do_exit+0x179/0x8d0
                do_group_exit+0x3d/0xb0
                sys_exit_group+0x12/0x20
Quoted 6 lines
Quoted 1 line

Monster box dies screaming.

That commit landed in stable, box with way too many cores (NR_CPUS=0!!) chokes instantly with loads of spinners. Ok, so zillion CPUs grabbing a mutex in lockstep is a bad idea (_having_ zillion?), but is there pilot error involved in a logjam like this?

Surely some mistake...

I can't find any mention of which kernel release you're talking about.

But Miklos's 2aa15890 unmap_mutex was introduced in 2.6.38 and removed in 3.0, when PeterZ converted i_mmap_lock to i_mmap_mutex, and removed the need for the additional unmap_mutex.

The unmap_mutex would never have been taken in unlink_file_vma(), shown in your stacktrace above: it was for truncation and invalidation.

The likely mutex in unlink_file_vma() would be the i_mmap_mutex. So I expect you're talking about a 3.0 or later kernel.

But then why would someone "backport" Miklos's patch to stable for it?

You lost me too!

Hugh

#9 lore raw
Quoted 23 lines · Hugh Dickins
Quoted 22 lines · Mike Galbraith
Quoted 21 lines · Mike Galbraith
Quoted 4 lines · Paul E. McKenney
Quoted 1 line

2aa15890 - mm: prevent concurrent unmap_mapping_range() on the same inode

I confess, you lost me on this one. You believe that this commit is the cause of the RCU CPU stall warnings?

4096 tasks on 4096 CPUs exit (well, try to) simultaneously.

Call Trace:
                __mutex_lock_slowpath+0x94/0x150
                mutex_lock+0x1a/0x40
                unlink_file_vma+0x3f/0xf0
                free_pgtables+0x40/0x100
                exit_mmap+0xb0/0x120
                mmput+0x49/0x120
                exit_mm+0x122/0x160
                do_exit+0x179/0x8d0
                do_group_exit+0x3d/0xb0
                sys_exit_group+0x12/0x20
Quoted 8 lines
Quoted 6 lines
Quoted 1 line

Monster box dies screaming.

That commit landed in stable, box with way too many cores (NR_CPUS=0!!) chokes instantly with loads of spinners. Ok, so zillion CPUs grabbing a mutex in lockstep is a bad idea (_having_ zillion?), but is there pilot error involved in a logjam like this?

Surely some mistake...

Yup.

Quoted 11 lines

I can't find any mention of which kernel release you're talking about.

But Miklos's 2aa15890 unmap_mutex was introduced in 2.6.38 and removed in 3.0, when PeterZ converted i_mmap_lock to i_mmap_mutex, and removed the need for the additional unmap_mutex.

The unmap_mutex would never have been taken in unlink_file_vma(), shown in your stacktrace above: it was for truncation and invalidation.

The likely mutex in unlink_file_vma() would be the i_mmap_mutex. So I expect you're talking about a 3.0 or later kernel.

Yeah.

Quoted 3 lines

But then why would someone "backport" Miklos's patch to stable for it?

You lost me too!

Sorry, /me is hopping around vigorously between too many darn trees, it's already there, not a stable addition.

Question remains though. Maybe the box hit some other problem that led to death by RCU gripage, but the info I received indicated the box was in the midst of a major spin-fest.

-Mike

#10 lore raw
Quoted 3 lines · Mike Galbraith

Question remains though. Maybe the box hit some other problem that led to death by RCU gripage, but the info I received indicated the box was in the midst of a major spin-fest.

To (maybe) speak more clearly, since it's a mutex like any other mutex that loads of CPUs can hit if you've got loads of CPUs, did huge box driver do something that we don't expect so many CPUs to be doing, thus instigate simultaneous exit trouble (ie shoot self in foot), or did that mutex addition create the exit trouble which box appeared to be having?

Too bad box RCU griped itself to death, would have been nice to have more than a snippet.

-Mike

#11 lore raw
Quoted 11 lines · Mike Galbraith
Quoted 3 lines · Mike Galbraith

Question remains though. Maybe the box hit some other problem that led to death by RCU gripage, but the info I received indicated the box was in the midst of a major spin-fest.

To (maybe) speak more clearly, since it's a mutex like any other mutex that loads of CPUs can hit if you've got loads of CPUs, did huge box driver do something that we don't expect so many CPUs to be doing, thus instigate simultaneous exit trouble (ie shoot self in foot), or did that mutex addition create the exit trouble which box appeared to be having?

Crickets chirping.. I know what _that_ means: "tsk tsk, you dummy" :)

I suspected that would happen, but asked anyway because I couldn't imagine even 4096 CPUs getting tangled up for an _eternity_ trying to go to sleep, but the lock which landed after 32-stable where these beasts earn their daily fuel rods was splattered all over the event. Oh well.

So, I can forget that and just make the thing not gripe itself to death should a stall for whatever reason be encountered again.

Rather than mucking about with rcu_cpu_stall_suppress, how about adjust timeout as you proceed, and block report functions? That way, there's no fiddling with things used elsewhere, and it shouldn't matter how badly console is being be hammered, you get a full report, and maybe even only one.

Hm, maybe I should forget hoping to keep check_cpu_stall() happy too, and only silently ignore it when busy.

kernel/rcutree.c +37 -9
index 0da7b88..e9dd654 100644
@@ -727,24 +727,29 @@ static void record_gp_stall_check_time(struct rcu_state *rsp)
 	rsp->jiffies_stall = jiffies + jiffies_till_stall_check();
 }
 
+int rcu_stall_report_in_progress;
+
 static void print_other_cpu_stall(struct rcu_state *rsp)
 {
 	int cpu;
 	long delta;
 	unsigned long flags;
 	int ndetected;
-	struct rcu_node *rnp = rcu_get_root(rsp);
+	struct rcu_node *root = rcu_get_root(rsp);
+	struct rcu_node *rnp;
 
 	/* Only let one CPU complain about others per time interval. */
 
-	raw_spin_lock_irqsave(&rnp->lock, flags);
+	raw_spin_lock_irqsave(&root->lock, flags);
 	delta = jiffies - rsp->jiffies_stall;
-	if (delta < RCU_STALL_RAT_DELAY || !rcu_gp_in_progress(rsp)) {
-		raw_spin_unlock_irqrestore(&rnp->lock, flags);
+	if (delta < RCU_STALL_RAT_DELAY || !rcu_gp_in_progress(rsp) ||
+			rcu_stall_report_in_progress) {
+		raw_spin_unlock_irqrestore(&root->lock, flags);
 		return;
 	}
 	rsp->jiffies_stall = jiffies + 3 * jiffies_till_stall_check() + 3;
-	raw_spin_unlock_irqrestore(&rnp->lock, flags);
+	rcu_stall_report_in_progress++;
+	raw_spin_unlock_irqrestore(&root->lock, flags);
 
 	/*
 	 * OK, time to rat on our buddy...
@@ -765,16 +770,23 @@ static void print_other_cpu_stall(struct rcu_state *rsp)
 				print_cpu_stall_info(rsp, rnp->grplo + cpu);
 				ndetected++;
 			}
+
+		/*
+		 * Push the timeout back as we go.  With a slow serial
+		 * console on a large machine, this may take a while.
+		 */ 
+		raw_spin_lock_irqsave(&root->lock, flags);
+		rsp->jiffies_stall = jiffies + 3 * jiffies_till_stall_check() + 3;
+		raw_spin_unlock_irqrestore(&root->lock, flags);
 	}
 
 	/*
 	 * Now rat on any tasks that got kicked up to the root rcu_node
 	 * due to CPU offlining.
 	 */
-	rnp = rcu_get_root(rsp);
-	raw_spin_lock_irqsave(&rnp->lock, flags);
-	ndetected = rcu_print_task_stall(rnp);
-	raw_spin_unlock_irqrestore(&rnp->lock, flags);
+	raw_spin_lock_irqsave(&root->lock, flags);
+	ndetected = rcu_print_task_stall(root);
+	raw_spin_unlock_irqrestore(&root->lock, flags);
 
 	print_cpu_stall_info_end();
 	printk(KERN_CONT "(detected by %d, t=%ld jiffies)\n",
@@ -784,6 +796,10 @@ static void print_other_cpu_stall(struct rcu_state *rsp)
 	else if (!trigger_all_cpu_backtrace())
 		dump_stack();
 
+	raw_spin_lock_irqsave(&root->lock, flags);
+	rcu_stall_report_in_progress--;
+	raw_spin_unlock_irqrestore(&root->lock, flags);
+
 	/* If so configured, complain about tasks blocking the grace period. */
 
 	rcu_print_detail_task_stall(rsp);
@@ -796,6 +812,17 @@ static void print_cpu_stall(struct rcu_state *rsp)
 	unsigned long flags;
 	struct rcu_node *rnp = rcu_get_root(rsp);
 
+	raw_spin_lock_irqsave(&rnp->lock, flags);
+	if (rcu_stall_report_in_progress) {
+		raw_spin_unlock_irqrestore(&rnp->lock, flags);
+		return;
+	}
+
+	/* Reset timeout, dump_stack() may take a while on large machines. */
+	rsp->jiffies_stall = jiffies + 3 * jiffies_till_stall_check() + 3;
+	rcu_stall_report_in_progress++;
+	raw_spin_unlock_irqrestore(&rnp->lock, flags);
+
 	/*
 	 * OK, time to rat on ourselves...
 	 * See Documentation/RCU/stallwarn.txt for info on how to debug
@@ -813,6 +840,7 @@ static void print_cpu_stall(struct rcu_state *rsp)
 	if (ULONG_CMP_GE(jiffies, rsp->jiffies_stall))
 		rsp->jiffies_stall = jiffies +
 				     3 * jiffies_till_stall_check() + 3;
+	rcu_stall_report_in_progress--;
 	raw_spin_unlock_irqrestore(&rnp->lock, flags);
 
 	set_need_resched();  /* kick ourselves to get things going. */

-Mike

#12 lore raw
Quoted 7 lines · Mike Galbraith
Quoted 6 lines · Mike Galbraith
Quoted 3 lines · Mike Galbraith

Question remains though. Maybe the box hit some other problem that led to death by RCU gripage, but the info I received indicated the box was in the midst of a major spin-fest.

Quoted 7 lines
Quoted 5 lines

To (maybe) speak more clearly, since it's a mutex like any other mutex that loads of CPUs can hit if you've got loads of CPUs, did huge box driver do something that we don't expect so many CPUs to be doing, thus instigate simultaneous exit trouble (ie shoot self in foot), or did that mutex addition create the exit trouble which box appeared to be having?

Crickets chirping.. I know what _that_ means: "tsk tsk, you dummy" :)

In my case, it means that I suspect you would rather me continue working on my series of patches to further reduce RCU grace-period-initialization latencies on large systems than worry about this patch.

If I understand correctly, your patch did what you wanted in the situation at hand. I have some quibbles, please see below.

Quoted 5 lines

I suspected that would happen, but asked anyway because I couldn't imagine even 4096 CPUs getting tangled up for an _eternity_ trying to go to sleep, but the lock which landed after 32-stable where these beasts earn their daily fuel rods was splattered all over the event. Oh well.

Quoted 8 lines

So, I can forget that and just make the thing not gripe itself to death should a stall for whatever reason be encountered again.

Rather than mucking about with rcu_cpu_stall_suppress, how about adjust timeout as you proceed, and block report functions? That way, there's no fiddling with things used elsewhere, and it shouldn't matter how badly console is being be hammered, you get a full report, and maybe even only one.

That sounds like a very good interim approach to me!

Quoted 2 lines

Hm, maybe I should forget hoping to keep check_cpu_stall() happy too, and only silently ignore it when busy.

But this is a good way to accumulate a variety of stalls, so not recommended.

Thanx, Paul

Quoted 8 lines
kernel/rcutree.c +0 -0
index 0da7b88..e9dd654 100644
@@ -727,24 +727,29 @@ static void record_gp_stall_check_time(struct rcu_state *rsp)
 	rsp->jiffies_stall = jiffies + jiffies_till_stall_check();
 }
 

kernel/rcutree.c static void record_gp_stall_check_time(struct rcu_state *rsp) · line 738

Quoted 10 lines
kernel/rcutree.c +3 -1
+int rcu_stall_report_in_progress;
+
 static void print_other_cpu_stall(struct rcu_state *rsp)
 {
 	int cpu;
 	long delta;
 	unsigned long flags;
 	int ndetected;
-	struct rcu_node *rnp = rcu_get_root(rsp);
+	struct rcu_node *root = rcu_get_root(rsp);

s/root/rnp_root/, please -- consistency with other places in the code. But see below.

kernel/rcutree.c static void record_gp_stall_check_time(struct rcu_state *rsp) · line 743

Quoted 6 lines
kernel/rcutree.c +2 -1
+	struct rcu_node *rnp;
 
 	/* Only let one CPU complain about others per time interval. */
 
-	raw_spin_lock_irqsave(&rnp->lock, flags);
+	raw_spin_lock_irqsave(&root->lock, flags);

On a 4096-CPU system, I bet that this needs to be trylock, with a bare "return" on failure to acquire the lock.

Of course, that fails if someone is holding this lock for some other reason. So I believe that you need a separate ->stalllock in the rcu_state structure for this purpose. You won't need to disable irqs when acquiring the lock.

kernel/rcutree.c static void record_gp_stall_check_time(struct rcu_state *rsp) · line 746

Quoted 5 lines
kernel/rcutree.c +2 -2
 	delta = jiffies - rsp->jiffies_stall;
-	if (delta < RCU_STALL_RAT_DELAY || !rcu_gp_in_progress(rsp)) {
-		raw_spin_unlock_irqrestore(&rnp->lock, flags);
+	if (delta < RCU_STALL_RAT_DELAY || !rcu_gp_in_progress(rsp) ||
+			rcu_stall_report_in_progress) {

If you conditionally acquire the new ->stalllock, you shouldn't need this added check.

kernel/rcutree.c static void record_gp_stall_check_time(struct rcu_state *rsp) · line 751

Quoted 6 lines
kernel/rcutree.c +2 -1
+		raw_spin_unlock_irqrestore(&root->lock, flags);
 		return;
 	}
 	rsp->jiffies_stall = jiffies + 3 * jiffies_till_stall_check() + 3;
-	raw_spin_unlock_irqrestore(&rnp->lock, flags);
+	rcu_stall_report_in_progress++;

And with the new ->stalllock, rcu_stall_report_in_progress can go away.

Quoted 6 lines
kernel/rcutree.c +1 -0
+	raw_spin_unlock_irqrestore(&root->lock, flags);
 
 	/*
 	 * OK, time to rat on our buddy...
@@ -765,16 +770,23 @@ static void print_other_cpu_stall(struct rcu_state *rsp)
 				print_cpu_stall_info(rsp, rnp->grplo + cpu);

kernel/rcutree.c static void print_other_cpu_stall(struct rcu_state *rsp) · line 780

Quoted 10 lines
kernel/rcutree.c +8 -0
 				ndetected++;
 			}
+
+		/*
+		 * Push the timeout back as we go.  With a slow serial
+		 * console on a large machine, this may take a while.
+		 */ 
+		raw_spin_lock_irqsave(&root->lock, flags);
+		rsp->jiffies_stall = jiffies + 3 * jiffies_till_stall_check() + 3;
+		raw_spin_unlock_irqrestore(&root->lock, flags);

And the separate ->stalllock should make this unnecessary as well. However, updating rsp->jiffies_stall periodically is a good idea in order to decrease cache thrashing on ->stalllock.

kernel/rcutree.c static void print_other_cpu_stall(struct rcu_state *rsp) · line 789

Quoted 13 lines
kernel/rcutree.c +3 -4
 	}
 
 	/*
 	 * Now rat on any tasks that got kicked up to the root rcu_node
 	 * due to CPU offlining.
 	 */
-	rnp = rcu_get_root(rsp);
-	raw_spin_lock_irqsave(&rnp->lock, flags);
-	ndetected = rcu_print_task_stall(rnp);
-	raw_spin_unlock_irqrestore(&rnp->lock, flags);
+	raw_spin_lock_irqsave(&root->lock, flags);
+	ndetected = rcu_print_task_stall(root);
+	raw_spin_unlock_irqrestore(&root->lock, flags);

And the separate lock makes this change unnecessary, also.

kernel/rcutree.c static void print_other_cpu_stall(struct rcu_state *rsp) · line 801

Quoted 9 lines
kernel/rcutree.c +3 -0
 	print_cpu_stall_info_end();
 	printk(KERN_CONT "(detected by %d, t=%ld jiffies)\n",
@@ -784,6 +796,10 @@ static void print_other_cpu_stall(struct rcu_state *rsp)
 	else if (!trigger_all_cpu_backtrace())
 		dump_stack();
 
+	raw_spin_lock_irqsave(&root->lock, flags);
+	rcu_stall_report_in_progress--;
+	raw_spin_unlock_irqrestore(&root->lock, flags);

Ditto here.

Quoted 8 lines
kernel/rcutree.c +1 -0
+
 	/* If so configured, complain about tasks blocking the grace period. */
 
 	rcu_print_detail_task_stall(rsp);
@@ -796,6 +812,17 @@ static void print_cpu_stall(struct rcu_state *rsp)
 	unsigned long flags;
 	struct rcu_node *rnp = rcu_get_root(rsp);
 

kernel/rcutree.c static void print_cpu_stall(struct rcu_state *rsp) · line 824

Quoted 10 lines
kernel/rcutree.c +10 -0
+	raw_spin_lock_irqsave(&rnp->lock, flags);
+	if (rcu_stall_report_in_progress) {
+		raw_spin_unlock_irqrestore(&rnp->lock, flags);
+		return;
+	}
+
+	/* Reset timeout, dump_stack() may take a while on large machines. */
+	rsp->jiffies_stall = jiffies + 3 * jiffies_till_stall_check() + 3;
+	rcu_stall_report_in_progress++;
+	raw_spin_unlock_irqrestore(&rnp->lock, flags);

And do trylock (without disabling irqs) here as well. No need for rcu_stall_report_in_progress. You can update rsp->jiffies_stall to reduce cache thrashing on ->stalllock.

kernel/rcutree.c static void print_cpu_stall(struct rcu_state *rsp) · line 843

Quoted 9 lines
kernel/rcutree.c +2 -0
+
 	/*
 	 * OK, time to rat on ourselves...
 	 * See Documentation/RCU/stallwarn.txt for info on how to debug
@@ -813,6 +840,7 @@ static void print_cpu_stall(struct rcu_state *rsp)
 	if (ULONG_CMP_GE(jiffies, rsp->jiffies_stall))
 		rsp->jiffies_stall = jiffies +
 				     3 * jiffies_till_stall_check() + 3;
+	rcu_stall_report_in_progress--;

And ->stalllock makes this unnecessary as well.

Quoted 6 lines
kernel/rcutree.c +0 -1
 	raw_spin_unlock_irqrestore(&rnp->lock, flags);
 
 	set_need_resched();  /* kick ourselves to get things going. */
 
-Mike
#13 lore raw
Quoted 6 lines · Paul E. McKenney
Quoted 1 line · Mike Galbraith

Crickets chirping.. I know what _that_ means: "tsk tsk, you dummy" :)

In my case, it means that I suspect you would rather me continue working on my series of patches to further reduce RCU grace-period-initialization latencies on large systems than worry about this patch.

Well of course you, being vastly more qualified (duh), doing that instead of me doing that is highly desirable, but no, I'm not into slavery, either expressed or implied, so if it happens before I get to poking at it again, great, if not, oh well.

Really, I don't care. I trivially fixed the regression. The folks who need this are highly capable of piddling with it, and you know who they are. They ain't doing shit but trying to milk _me_ like a damn cow, so I can't be arsed to give a shit, I'm way too busy to have that luxury.

-Mike

#14 lore raw
In reply to Paul E. McKenney
Quoted 3 lines · Paul E. McKenney

In my case, it means that I suspect you would rather me continue working on my series of patches to further reduce RCU grace-period-initialization latencies on large systems than worry about this patch.

Hm, grumpy man may have misinterpreted that. He's off for a weekend of therapeutic bike riding and flower smelling in any case.

-Mike