sched: Fix some load-balancer vs hotplug holes

Hi

Thomas had some hotplug stress funnies and these appear to cure things. Should go into this merge window thingy, except the last one, which is fine for later.

The first is an obvious regression and has a Fixes line, the second looks like a pre-existing hole, but might be made easier to hit, although I can't readily tell you how.

And while I could readily hit the first hole, I didn't manage to trigger the second, but Thomas had enough trace data to confirm he could.

On CPU hot unplug, when parking the last kthread we'll try and schedule into idle to kill the CPU. This last schedule can (and does) trigger newidle balance because at this point the sched domains are still up because of commit:

77d1dfda0e79 ("sched/topology, cpuset: Avoid spurious/wrong domain rebuilds")

Obviously pulling tasks to an already offline CPU is a bad idea, and all balancing operations _should_ be subject to cpu_active_mask, make it so.

---
 kernel/sched/fair.c |    6 ++++++
 1 file changed, 6 insertions(+)

@@ -8448,6 +8448,12 @@ static int idle_balance(struct rq *this_
 	this_rq->idle_stamp = rq_clock(this_rq);
 
 	/*
+	 * Do not pull tasks towards !active CPUs...
+	 */
+	if (!cpu_active(this_cpu))
+		return 0;
+
+	/*
 	 * This is OK, because current is on_cpu, which avoids it being picked
 	 * for load-balance and preemption/IRQs are still disabled avoiding
 	 * further scheduler activity on it and we're being very careful to

The load balancer applies cpu_active_mask to whatever sched_domains it finds, however in the case of active_balance there is a hole between setting rq->{active_balance,push_cpu} and running the stop_machine work doing the actual migration.

The @push_cpu can go offline in this window, which would result in us moving a task onto a dead cpu, which is a fairly bad thing.

Double check the active mask before the stop work does the migration.

CPU0 CPU1

<SoftIRQ>

					stop_machine(takedown_cpu)
    load_balance()			cpu_stopper_thread()
      ...				  work = multi_cpu_stop
      stop_one_cpu_nowait(		    /* wait for CPU0 */
	.func = active_load_balance_cpu_stop
      );

</SoftIRQ>

cpu_stopper_thread()

    work = multi_cpu_stop
      /* sync with CPU1 */
					    take_cpu_down()
					<idle>
					  play_dead();

    work = active_load_balance_cpu_stop
      set_task_cpu(p, CPU1); /* oops!! */

---
 kernel/sched/fair.c |    7 +++++++
 1 file changed, 7 insertions(+)

@@ -8560,6 +8560,13 @@ static int active_load_balance_cpu_stop(
 	struct rq_flags rf;
 
 	rq_lock_irq(busiest_rq, &rf);
+	/*
+	 * Between queueing the stop-work and running it is a hole in which
+	 * CPUs can become inactive. We should not move tasks from or to
+	 * inactive CPUs.
+	 */
+	if (!cpu_active(busiest_cpu) || !cpu_active(target_cpu))
+		goto out_unlock;
 
 	/* make sure the requested cpu hasn't gone down in the meantime */
 	if (unlikely(busiest_cpu != smp_processor_id() ||

Migrating tasks to offline CPUs is a pretty big fail, warn about it.

---
 kernel/sched/core.c |    4 ++++
 1 file changed, 4 insertions(+)

@@ -1173,6 +1173,10 @@ void set_task_cpu(struct task_struct *p,
 	WARN_ON_ONCE(debug_locks && !(lockdep_is_held(&p->pi_lock) ||
 				      lockdep_is_held(&task_rq(p)->lock)));
 #endif
+	/*
+	 * Clearly, migrating tasks to offline CPUs is a fairly daft thing.
+	 */
+	WARN_ON_ONCE(!cpu_online(new_cpu));
 #endif
 
 	trace_sched_migrate_task(p, new_cpu);

Hey Peter,

This seems to get hit on the latest -next:

[2035565360.446794] Unregister pv shared memory for cpu 2
[2035565360.467930] numa_remove_cpu cpu 2 node 2: mask now 6
[2035565360.471431] ------------[ cut here ]------------
[2035565360.472548] WARNING: CPU: 2 PID: 24 at
kernel/sched/core.c:1178 set_task_cpu (kernel/sched/core.c:1157)
[2035565360.473840] Modules linked in:
[2035565360.474632] CPU: 2 PID: 24 Comm: migration/2 Not tainted
4.14.0-rc2-next-20170927+ #252
[2035565360.476128] task: ffff8801ab7dc040 task.stack: ffff8801ab7e0000
[2035565360.477108] RIP: 0010:set_task_cpu (??:?)
[2035565360.477850] RSP: 0018:ffff8801ab807b18 EFLAGS: 00010096
[2035565360.478734] RAX: 0000000000000002 RBX: ffff8801a8d94040 RCX:
1ffff1003577cb3c
[2035565360.479872] RDX: 0000000000000004 RSI: 0000000000000002 RDI:
ffffffff9177d940
[2035565360.480998] RBP: ffff8801ab807b58 R08: 000000000000b6b2 R09:
ffff8801abbe5a2c
[2035565360.482356] R10: 0000000000000001 R11: 0000000000000001 R12:
ffff8801a8d94048
[2035565360.483490] R13: ffff8801ab807c88 R14: 0000000000000002 R15:
ffff8801a8d940a4
[2035565360.484617] FS:  0000000000000000(0000)
GS:ffff8801ab800000(0000) knlGS:0000000000000000
[2035565360.485881] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[2035565360.490482] CR2: 00000000012dfae4 CR3: 00000001a30c5002 CR4:
00000000000606a0
[2035565360.491836] Call Trace:
[2035565360.492301]  <IRQ>
[2035565360.492710] detach_task.isra.80 (kernel/sched/fair.c:6816)
[2035565360.493430] load_balance (./include/linux/list.h:78
kernel/sched/fair.c:6902 kernel/sched/fair.c:8201)
[2035565360.494094] ? find_busiest_group (kernel/sched/fair.c:8133)
[2035565360.494861] ? rebalance_domains (kernel/sched/fair.c:8785)
[2035565360.495571] rebalance_domains (kernel/sched/fair.c:8829)
[2035565360.496292] ? find_next_bit (lib/find_bit.c:65)
[2035565360.496961] ? pick_next_task_fair (kernel/sched/fair.c:8779)
[2035565360.497753] ? check_preemption_disabled (lib/smp_processor_id.c:52)
[2035565360.498574] run_rebalance_domains (kernel/sched/fair.c:9052)
[2035565360.499318] ? check_preemption_disabled (lib/smp_processor_id.c:52)
[2035565360.500388] __do_softirq (kernel/softirq.c:284
./include/linux/jump_label.h:141 ./include/trace/events/irq.h:141
kernel/softirq.c:285)
[2035565360.501039] ? hrtimer_interrupt (kernel/time/hrtimer.c:1370)
[2035565360.502014] irq_exit (kernel/softirq.c:364 kernel/softirq.c:405)
[2035565360.502598] smp_apic_timer_interrupt
(./arch/x86/include/asm/irq_regs.h:26
arch/x86/kernel/apic/apic.c:1043)
[2035565360.503605] apic_timer_interrupt (arch/x86/entry/entry_64.S:770)
[2035565360.504313]  </IRQ>
[2035565360.504724] RIP: 0010:multi_cpu_stop (??:?)
[2035565360.505503] RSP: 0018:ffff8801ab7e7d88 EFLAGS: 00000292
ORIG_RAX: ffffffffffffff11
[2035565360.506721] RAX: 0000000000000003 RBX: 0000000000000004 RCX:
000000000000000a
[2035565360.507862] RDX: 0000000000000004 RSI: 0000000000000040 RDI:
0000000000000292
[2035565360.508997] RBP: ffff8801ab7e7de0 R08: ffff8801ab7dc040 R09:
0000000000000000
[2035565360.510566] R10: 0000000000000001 R11: 1ffff1003577cb55 R12:
ffff8801aae2f890
[2035565360.511701] R13: ffff8801aae2f8b4 R14: dffffc0000000000 R15:
0000000000000003
[2035565360.512843] ? cpu_stop_queue_work (kernel/stop_machine.c:176)
[2035565360.513591] cpu_stopper_thread (kernel/stop_machine.c:480)
[2035565360.514316] ? cpu_stop_create (kernel/stop_machine.c:458)
[2035565360.515218] smpboot_thread_fn (kernel/smpboot.c:164)
[2035565360.515918] ? sort_range (kernel/smpboot.c:107)
[2035565360.516528] ? schedule (./arch/x86/include/asm/bitops.h:324
(discriminator 1) ./include/linux/thread_info.h:79 (discriminator 1)
./include/linux/sched.h:1605 (discriminator 1)
kernel/sched/core.c:3435 (discriminator 1))
[2035565360.517119] ? __kthread_parkme (kernel/kthread.c:188)
[2035565360.517835] kthread (kernel/kthread.c:242)
[2035565360.518413] ? sort_range (kernel/smpboot.c:107)
[2035565360.519008] ? kthread_create_on_node (kernel/kthread.c:198)
[2035565360.519792] ret_from_fork (arch/x86/entry/entry_64.S:437)
[2035565360.520407] Code: 09 84 d2 74 05 e8 94 38 4b 00 f7 83 84 00 00

00 fd ff ff ff 0f 84 a0 f9 ff ff 0f ff e9 99 f9 ff ff e8 68 18 ff ff e9 c7 fd ff ff <0f> ff e9 ea f9 ff ff e8 57 18 ff ff e9 f5 f9 ff ff e8 0d 84 0f
All code
========

   0: 09 84 d2 74 05 e8 94 or     %eax,-0x6b17fa8c(%rdx,%rdx,8)
   7: 38 4b 00             cmp    %cl,0x0(%rbx)
   a: f7 83 84 00 00 00 fd testl  $0xfffffffd,0x84(%rbx)
  11: ff ff ff
  14: 0f 84 a0 f9 ff ff     je     0xfffffffffffff9ba
  1a: 0f ff                 (bad)
  1c: e9 99 f9 ff ff       jmpq   0xfffffffffffff9ba
  21: e8 68 18 ff ff       callq  0xffffffffffff188e
  26: e9 c7 fd ff ff       jmpq   0xfffffffffffffdf2
  2b:* 0f ff                 (bad)   <-- trapping instruction
  2d: e9 ea f9 ff ff       jmpq   0xfffffffffffffa1c
  32: e8 57 18 ff ff       callq  0xffffffffffff188e
  37: e9 f5 f9 ff ff       jmpq   0xfffffffffffffa31
  3c: e8 0d 84 0f 00       callq  0xf844e

Code starting with the faulting instruction
===========================================
0: 0f ff (bad)

   2: e9 ea f9 ff ff       jmpq   0xfffffffffffff9f1
   7: e8 57 18 ff ff       callq  0xffffffffffff1863
   c: e9 f5 f9 ff ff       jmpq   0xfffffffffffffa06
  11: e8 0d 84 0f 00       callq  0xf8423
[2035565360.523585] ---[ end trace 812b7ff74114db6c ]---
[2035565360.524744] smpboot: CPU 2 is now offline

Thanks,
Sasha

Urgh, weird. That really shouldn't happen. Can you easily reproduce?

Looks like yes. Seems like it's enough to stress CPU hotplug + trinity.

If you have patches you want me try send them my way.

Thanks,
Sasha

OK, I'll see if I can reproduce building kernels and hotplug stress. Otherwise I'll try and cook up some debug patches for you.

I can't seem to trigger :-(

Can you please run with the below patch and:

  # echo 1 > /proc/sys/kernel/traceoff_on_warning

---
 kernel/sched/core.c |  3 +++
 kernel/sched/fair.c | 10 ++++++++++
 2 files changed, 13 insertions(+)

index 18a6966567da..c613f7756981 100644
@@ -5592,6 +5592,7 @@ int sched_cpu_activate(unsigned int cpu)
 	struct rq_flags rf;
 
 	set_cpu_active(cpu, true);
+	trace_printk("active: %d mask: %*pbl\n", cpu, cpumask_pr_args(cpu_active_mask));
 
 	if (sched_smp_initialized) {
 		sched_domains_numa_masks_set(cpu);

@@ -5624,6 +5625,7 @@ int sched_cpu_deactivate(unsigned int cpu)
 	int ret;
 
 	set_cpu_active(cpu, false);
+	trace_printk("not-active: %d mask: %*pbl\n", cpu, cpumask_pr_args(cpu_active_mask));
 	/*
 	 * We've cleared cpu_active_mask, wait for all preempt-disabled and RCU
 	 * users of this state to go away such that all new such users will

@@ -5632,6 +5634,7 @@ int sched_cpu_deactivate(unsigned int cpu)
 	 * Do sync before park smpboot threads to take care the rcu boost case.
 	 */
 	synchronize_rcu_mult(call_rcu, call_rcu_sched);
+	trace_printk("rcu-sync: %d\n", cpu);
 
 	if (!sched_smp_initialized)
 		return 0;

index 70ba32e08a23..cb8f43a59f33 100644
@@ -8150,8 +8150,11 @@ static int load_balance(int this_cpu, struct rq *this_rq,
 		.tasks		= LIST_HEAD_INIT(env.tasks),
 	};
 
+
 	cpumask_and(cpus, sched_domain_span(sd), cpu_active_mask);
 
+	trace_printk("dst_cpu: %d cpus: %*pbl\n", this_cpu, cpumask_pr_args(cpus));
+
 	schedstat_inc(sd->lb_count[idle]);
 
 redo:

@@ -8248,6 +8251,9 @@ static int load_balance(int this_cpu, struct rq *this_rq,
 
 			env.dst_rq	 = cpu_rq(env.new_dst_cpu);
 			env.dst_cpu	 = env.new_dst_cpu;
+
+			trace_printk("dst_cpu: %d\n", env.dst_cpu);
+
 			env.flags	&= ~LBF_DST_PINNED;
 			env.loop	 = 0;
 			env.loop_break	 = sched_nr_migrate_break;

@@ -8465,6 +8471,7 @@ static int idle_balance(struct rq *this_rq, struct rq_flags *rf)
 
 	update_blocked_averages(this_cpu);
 	rcu_read_lock();
+	trace_printk("rcu-read-lock: %d\n", this_cpu);
 	for_each_domain(this_cpu, sd) {
 		int continue_balancing = 1;
 		u64 t0, domain_cost;

@@ -8500,6 +8507,7 @@ static int idle_balance(struct rq *this_rq, struct rq_flags *rf)
 		if (pulled_task || this_rq->nr_running > 0)
 			break;
 	}
+	trace_printk("rcu-read-unlock: %d\n", this_cpu);
 	rcu_read_unlock();
 
 	raw_spin_lock(&this_rq->lock);

@@ -8790,6 +8798,7 @@ static void rebalance_domains(struct rq *rq, enum cpu_idle_type idle)
 	update_blocked_averages(cpu);
 
 	rcu_read_lock();
+	trace_printk("rcu-read-lock: %d\n", cpu);
 	for_each_domain(cpu, sd) {
 		/*
 		 * Decay the newidle max times here because this is a regular

@@ -8853,6 +8862,7 @@ static void rebalance_domains(struct rq *rq, enum cpu_idle_type idle)
 		rq->max_idle_balance_cost =
 			max((u64)sysctl_sched_migration_cost, max_cost);
 	}
+	trace_printk("rcu-read-unlock: %d\n", cpu);
 	rcu_read_unlock();
 
 	/*

The call stack trace looks like so:

[ 2073.492089] Unregister pv shared memory for cpu 2
[ 2073.495414] NOHZ: local_softirq_pending 202
[ 2073.516166] ------------[ cut here ]------------
[ 2073.519047] WARNING: CPU: 2 PID: 24 at kernel/sched/core.c:1178 set_task_cpu (kernel/sched/core.c:1157) 
[ 2073.520317] Modules linked in:
[ 2073.520816] CPU: 2 PID: 24 Comm: migration/2 Not tainted 4.14.0-rc2-next-20170927+ #256
[ 2073.522046] task: ffff8801ab7cc040 task.stack: ffff8801ab7d8000
[ 2073.522963] RIP: 0010:set_task_cpu (??:?) 
[ 2073.523655] RSP: 0018:ffff8801ab807b20 EFLAGS: 00010096
[ 2073.524662] RAX: 0000000000000002 RBX: ffff880189810040 RCX: 1ffff100356f993a
[ 2073.525747] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000046
[ 2073.526845] RBP: ffff8801ab807b60 R08: 0000000000000000 R09: 0000000000000000
[ 2073.527940] R10: 0000000000000000 R11: 0000000000000000 R12: 00000000001e5900
[ 2073.529027] R13: 0000000000000006 R14: 0000000000000002 R15: ffff8801898100a4
[ 2073.530118] FS:  0000000000000000(0000) GS:ffff8801ab800000(0000) knlGS:0000000000000000
[ 2073.531556] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 2073.532443] CR2: 00007ffd965f1be8 CR3: 0000000187ede001 CR4: 00000000000606a0
[ 2073.533546] Call Trace:
[ 2073.533944]  <IRQ>
[ 2073.534280] detach_task.isra.80 (kernel/sched/fair.c:6816) 
[ 2073.534939] load_balance (./include/linux/list.h:78 kernel/sched/fair.c:6902 kernel/sched/fair.c:8204) 
[ 2073.535543] ? find_busiest_group (kernel/sched/fair.c:8133) 
[ 2073.536252] rebalance_domains (kernel/sched/fair.c:8838) 
[ 2073.536903] ? pick_next_task_fair (kernel/sched/fair.c:8787) 
[ 2073.537628] ? check_preemption_disabled (lib/smp_processor_id.c:52) 
[ 2073.538395] run_rebalance_domains (kernel/sched/fair.c:9062) 
[ 2073.539096] ? check_preemption_disabled (lib/smp_processor_id.c:52) 
[ 2073.539850] __do_softirq (kernel/softirq.c:284 ./include/linux/jump_label.h:141 ./include/trace/events/irq.h:141 kernel/softirq.c:285) 
[ 2073.540424] ? check_preemption_disabled (lib/smp_processor_id.c:52) 
[ 2073.541189] irq_exit (kernel/softirq.c:364 kernel/softirq.c:405) 
[ 2073.541715] smp_apic_timer_interrupt (./arch/x86/include/asm/irq_regs.h:26 arch/x86/kernel/apic/apic.c:1043) 
[ 2073.542452] apic_timer_interrupt (arch/x86/entry/entry_64.S:770) 
[ 2073.543116]  </IRQ>
[ 2073.543463] RIP: 0010:multi_cpu_stop (??:?) 
[ 2073.544173] RSP: 0018:ffff8801ab7dfd88 EFLAGS: 00000292 ORIG_RAX: ffffffffffffff11
[ 2073.545326] RAX: 0000000000000007 RBX: 0000000000000004 RCX: 000000000000000a
[ 2073.546406] RDX: 0000000000000000 RSI: ffffffff9c46eee0 RDI: 0000000000000292
[ 2073.547503] RBP: ffff8801ab7dfde0 R08: 0000000000000000 R09: 0000000000000000
[ 2073.548587] R10: 0000000000000000 R11: 0000000000000000 R12: ffff88012aaf7890
[ 2073.549668] R13: ffff88012aaf78b4 R14: dffffc0000000000 R15: 0000000000000003
[ 2073.550765] ? __this_cpu_preempt_check (lib/smp_processor_id.c:63) 
[ 2073.551501] ? cpu_stop_queue_work (kernel/stop_machine.c:176) 
[ 2073.552195] cpu_stopper_thread (kernel/stop_machine.c:480) 
[ 2073.552845] ? cpu_stop_create (kernel/stop_machine.c:458) 
[ 2073.553462] smpboot_thread_fn (kernel/smpboot.c:164) 
[ 2073.554104] ? sort_range (kernel/smpboot.c:107) 
[ 2073.554671] ? schedule (./arch/x86/include/asm/bitops.h:324 (discriminator 1) ./include/linux/thread_info.h:79 (discriminator 1) ./include/linux/sched.h:1605 (discriminator 1) kernel/sched/core.c:3435 (discriminator 1)) 
[ 2073.555230] ? __kthread_parkme (kernel/kthread.c:188) 
[ 2073.555892] kthread (kernel/kthread.c:242) 
[ 2073.556408] ? sort_range (kernel/smpboot.c:107) 
[ 2073.556963] ? kthread_create_on_node (kernel/kthread.c:198) 
[ 2073.557693] ret_from_fork (arch/x86/entry/entry_64.S:437) 
[ 2073.558261] Code: 09 84 d2 74 05 e8 84 3a 4b 00 f7 83 84 00 00 00 fd ff ff ff 0f 84 a0 f9 ff ff 0f ff e9 99 f9 ff ff e8 78 18 ff ff e9 c7 fd ff ff <0f> ff e9 ea f9 ff ff e8 67 18 ff ff e9 f5 f9 ff ff e8 fd 85 0f 

All code
========

   0:	09 84 d2 74 05 e8 84 	or     %eax,-0x7b17fa8c(%rdx,%rdx,8)
   7:	3a 4b 00             	cmp    0x0(%rbx),%cl
   a:	f7 83 84 00 00 00 fd 	testl  $0xfffffffd,0x84(%rbx)
  11:	ff ff ff 
  14:	0f 84 a0 f9 ff ff    	je     0xfffffffffffff9ba
  1a:	0f ff                	(bad)  
  1c:	e9 99 f9 ff ff       	jmpq   0xfffffffffffff9ba
  21:	e8 78 18 ff ff       	callq  0xffffffffffff189e
  26:	e9 c7 fd ff ff       	jmpq   0xfffffffffffffdf2
  2b:*	0f ff                	(bad)  		<-- trapping instruction
  2d:	e9 ea f9 ff ff       	jmpq   0xfffffffffffffa1c
  32:	e8 67 18 ff ff       	callq  0xffffffffffff189e
  37:	e9 f5 f9 ff ff       	jmpq   0xfffffffffffffa31
  3c:	e8 fd 85 0f 00       	callq  0xf863e

Code starting with the faulting instruction
===========================================

   0:	0f ff                	(bad)  
   2:	e9 ea f9 ff ff       	jmpq   0xfffffffffffff9f1
   7:	e8 67 18 ff ff       	callq  0xffffffffffff1873
   c:	e9 f5 f9 ff ff       	jmpq   0xfffffffffffffa06
  11:	e8 fd 85 0f 00       	callq  0xf8613
[ 2073.561289] ---[ end trace 88455b894f38cbc5 ]---

And quite a few lines of your added trace (lmk if you need more, or all):

<idle>-0     [000] ..s2   104.829161: load_balance: dst_cpu: 6 cpus: 0-1,3-4,6-7,9
<idle>-0     [000] ..s1   104.829172: rebalance_domains: rcu-read-unlock: 6
<idle>-0     [000] ..s1   104.829177: rebalance_domains: rcu-read-lock: 0
<idle>-0     [000] ..s1   104.829179: load_balance: dst_cpu: 0 cpus: 0-1,3-4,6-7,9
<idle>-0     [000] ..s1   104.829183: rebalance_domains: rcu-read-unlock: 0
<idle>-0     [001] .Ns1   104.829313: rebalance_domains: rcu-read-lock: 1
<idle>-0     [001] .Ns1   104.829317: rebalance_domains: rcu-read-unlock: 1
<idle>-0     [006] .Ns1   104.829446: rebalance_domains: rcu-read-lock: 6
<idle>-0     [006] .Ns1   104.829450: rebalance_domains: rcu-read-unlock: 6
trinity-c28-3303  [006] d..1   104.829663: pick_next_task_fair: rcu-read-lock: 6
trinity-c28-3303  [006] d..1   104.829667: load_balance: dst_cpu: 6 cpus: 1,3-4,6-7,9
trinity-c28-3303  [006] d..1   104.829671: load_balance: dst_cpu: 6 cpus: 1,3-4,6-7,9
trinity-c28-3303  [006] d..1   104.829702: pick_next_task_fair: rcu-read-unlock: 6
kdevtmpfs-72    [001] d..1   104.830079: pick_next_task_fair: rcu-read-lock: 1
kdevtmpfs-72    [001] d..1   104.830083: load_balance: dst_cpu: 1 cpus: 1,9
kdevtmpfs-72    [001] d..1   104.830087: load_balance: dst_cpu: 1 cpus: 1,9
kdevtmpfs-72    [001] d..1   104.830097: pick_next_task_fair: rcu-read-unlock: 1
trinity-c37-3313  [000] d..1   104.830218: pick_next_task_fair: rcu-read-lock: 0
trinity-c37-3313  [000] d..1   104.830221: load_balance: dst_cpu: 0 cpus: 0-1,3-4,6-7,9
trinity-c37-3313  [000] d..1   104.830231: load_balance: dst_cpu: 0 cpus: 0-1,3-4,6-7,9
trinity-c37-3313  [000] d..1   104.830237: pick_next_task_fair: rcu-read-unlock: 0
trinity-c28-3303  [006] d..1   104.830912: pick_next_task_fair: rcu-read-lock: 6
trinity-c28-3303  [006] d..1   104.830916: load_balance: dst_cpu: 6 cpus: 1,3-4,6-7,9
trinity-c28-3303  [006] d..1   104.830919: load_balance: dst_cpu: 6 cpus: 1,3-4,6-7,9
trinity-c28-3303  [006] d..1   104.830950: pick_next_task_fair: rcu-read-unlock: 6
kworker/u26:2-413   [005] ..s1   104.831066: rebalance_domains: rcu-read-lock: 5
kworker/u26:2-413   [005] ..s1   104.831071: rebalance_domains: rcu-read-unlock: 5
rcu_preempt-9     [006] d..1   104.831127: pick_next_task_fair: rcu-read-lock: 6
rcu_preempt-9     [006] d..1   104.831130: load_balance: dst_cpu: 6 cpus: 1,3-4,6-7,9
rcu_preempt-9     [006] d..1   104.831133: load_balance: dst_cpu: 6 cpus: 1,3-4,6-7,9
rcu_preempt-9     [006] d..1   104.831138: pick_next_task_fair: rcu-read-unlock: 6
ksoftirqd/6-51    [006] d..1   104.831284: pick_next_task_fair: rcu-read-lock: 6
ksoftirqd/6-51    [006] d..1   104.831287: load_balance: dst_cpu: 6 cpus: 1,3-4,6-7,9
ksoftirqd/6-51    [006] d..1   104.831290: load_balance: dst_cpu: 6 cpus: 1,3-4,6-7,9
ksoftirqd/6-51    [006] d..1   104.831307: pick_next_task_fair: rcu-read-unlock: 6
kworker/u26:2-5519  [005] d..1   104.831458: pick_next_task_fair: rcu-read-lock: 5
kworker/u26:2-5519  [005] d..1   104.831462: load_balance: dst_cpu: 5 cpus: 1,9
kworker/u26:2-5519  [005] d..1   104.831473: load_balance: dst_cpu: 5 cpus: 1,9
kworker/u26:2-5519  [005] d..1   104.831479: pick_next_task_fair: rcu-read-unlock: 5
kworker/u26:2-5519  [005] d..1   104.831796: pick_next_task_fair: rcu-read-lock: 5
kworker/u26:2-5519  [005] d..1   104.831799: load_balance: dst_cpu: 5 cpus: 1,9
kworker/u26:2-5519  [005] dN.1   104.831823: pick_next_task_fair: rcu-read-unlock: 5
ksoftirqd/1-18    [001] d..1   104.831914: pick_next_task_fair: rcu-read-lock: 1
ksoftirqd/1-18    [001] d..1   104.831918: load_balance: dst_cpu: 1 cpus: 1,9
ksoftirqd/1-18    [001] d..1   104.831928: load_balance: dst_cpu: 1 cpus: 1,9
ksoftirqd/1-18    [001] d..1   104.831934: pick_next_task_fair: rcu-read-unlock: 1
kworker/u26:2-5519  [005] ..s2   104.832087: rebalance_domains: rcu-read-lock: 5
kworker/u26:2-5519  [005] ..s2   104.832091: rebalance_domains: rcu-read-unlock: 5
trinity-c37-3313  [000] ..s2   104.832097: rebalance_domains: rcu-read-lock: 0
trinity-c37-3313  [000] ..s2   104.832101: rebalance_domains: rcu-read-unlock: 0
trinity-c37-3313  [000] d..1   104.832188: pick_next_task_fair: rcu-read-lock: 0
trinity-c37-3313  [000] d..1   104.832190: load_balance: dst_cpu: 0 cpus: 0-1,3-4,6-7,9
trinity-c37-3313  [000] d..1   104.832195: load_balance: dst_cpu: 0 cpus: 0-1,3-4,6-7,9
trinity-c37-3313  [000] d..1   104.832206: pick_next_task_fair: rcu-read-unlock: 0
kworker/u26:2-5519  [005] d..1   104.832226: pick_next_task_fair: rcu-read-lock: 5
kworker/u26:2-5519  [005] d..1   104.832230: load_balance: dst_cpu: 5 cpus: 1,9
kworker/u26:2-5519  [005] d..1   104.832239: load_balance: dst_cpu: 5 cpus: 1,9
kworker/u26:2-5519  [005] d..1   104.832244: pick_next_task_fair: rcu-read-unlock: 5
trinity-c12-5517  [008] d..1   104.832468: pick_next_task_fair: rcu-read-lock: 8
trinity-c12-5517  [008] d..1   104.832472: load_balance: dst_cpu: 8 cpus: 0-1,3-4,6-7,9
trinity-c12-5517  [008] d..1   104.832479: load_balance: dst_cpu: 8 cpus: 0-1,3-4,6-7,9
kworker/u26:2-5519  [005] d..1   104.832499: pick_next_task_fair: rcu-read-lock: 5
kworker/u26:2-5519  [005] d..1   104.832502: load_balance: dst_cpu: 5 cpus: 1,9
kworker/u26:2-5519  [005] d..1   104.832506: load_balance: dst_cpu: 5 cpus: 1,9
kworker/u26:2-5519  [005] d..1   104.832520: pick_next_task_fair: rcu-read-unlock: 5
trinity-c28-3303  [006] d..1   104.832533: pick_next_task_fair: rcu-read-lock: 6
trinity-c28-3303  [006] d..1   104.832537: load_balance: dst_cpu: 6 cpus: 1,3-4,6-7,9
trinity-c12-5517  [008] d..1   104.832537: pick_next_task_fair: rcu-read-unlock: 8
trinity-c28-3303  [006] d..1   104.832540: load_balance: dst_cpu: 6 cpus: 1,3-4,6-7,9
trinity-c28-3303  [006] d..1   104.832550: pick_next_task_fair: rcu-read-unlock: 6
ksoftirqd/8-63    [008] d..1   104.832790: pick_next_task_fair: rcu-read-lock: 8
ksoftirqd/8-63    [008] d..1   104.832793: load_balance: dst_cpu: 8 cpus: 0-1,3-4,6-7,9
ksoftirqd/8-63    [008] d..1   104.832797: load_balance: dst_cpu: 8 cpus: 0-1,3-4,6-7,9
ksoftirqd/8-63    [008] d..1   104.832809: pick_next_task_fair: rcu-read-unlock: 8
<idle>-0     [005] .Ns1   104.833083: rebalance_domains: rcu-read-lock: 5
<idle>-0     [005] .Ns1   104.833087: rebalance_domains: rcu-read-unlock: 5
trinity-c78-4927  [000] d..1   104.833225: pick_next_task_fair: rcu-read-lock: 0
trinity-c78-4927  [000] d..1   104.833228: load_balance: dst_cpu: 0 cpus: 0-1,3-4,6-7,9
trinity-c78-4927  [000] d..1   104.833239: load_balance: dst_cpu: 0 cpus: 0-1,3-4,6-7,9
trinity-c78-4927  [000] d..1   104.833260: pick_next_task_fair: rcu-read-unlock: 0
kworker/u26:2-5519  [005] d..1   104.833545: pick_next_task_fair: rcu-read-lock: 5
kworker/u26:2-5519  [005] d..1   104.833548: load_balance: dst_cpu: 5 cpus: 1,9
kworker/u26:2-5519  [005] d..1   104.833785: load_balance: dst_cpu: 5 cpus: 1,9
kworker/u26:2-5519  [005] d..1   104.833799: pick_next_task_fair: rcu-read-unlock: 5
trinity-c28-3303  [006] ..s1   104.834090: rebalance_domains: rcu-read-lock: 6
trinity-c28-3303  [006] ..s1   104.834094: rebalance_domains: rcu-read-unlock: 6
rcu_preempt-9     [006] d..1   104.834193: pick_next_task_fair: rcu-read-lock: 6
rcu_preempt-9     [006] d..1   104.834196: load_balance: dst_cpu: 6 cpus: 1,3-4,6-7,9
rcu_preempt-9     [006] d..1   104.834200: load_balance: dst_cpu: 6 cpus: 1,3-4,6-7,9
rcu_preempt-9     [006] d..1   104.834210: pick_next_task_fair: rcu-read-unlock: 6
ksoftirqd/6-51    [006] d..1   104.834309: pick_next_task_fair: rcu-read-lock: 6
ksoftirqd/6-51    [006] d..1   104.834312: load_balance: dst_cpu: 6 cpus: 1,3-4,6-7,9
ksoftirqd/6-51    [006] d..1   104.834315: load_balance: dst_cpu: 6 cpus: 1,3-4,6-7,9
ksoftirqd/6-51    [006] d..1   104.834323: pick_next_task_fair: rcu-read-unlock: 6
<idle>-0     [000] .Ns1   104.834449: rebalance_domains: rcu-read-lock: 0
<idle>-0     [000] .Ns1   104.834452: load_balance: dst_cpu: 0 cpus: 0-1,3-4,6-7,9
<idle>-0     [000] .Ns2   104.834457: load_balance: dst_cpu: 0 cpus: 0-1,3-4,6-7,9
<idle>-0     [000] .Ns1   104.834459: rebalance_domains: rcu-read-unlock: 0
trinity-c37-3313  [000] d..1   104.834761: pick_next_task_fair: rcu-read-lock: 0
trinity-c37-3313  [000] d..1   104.834764: load_balance: dst_cpu: 0 cpus: 0-1,3-4,6-7,9
trinity-c37-3313  [000] d..1   104.834769: load_balance: dst_cpu: 0 cpus: 0-1,3-4,6-7,9
trinity-c37-3313  [000] d..1   104.834780: pick_next_task_fair: rcu-read-unlock: 0
trinity-c79-3355  [005] .Ns1   104.835721: rebalance_domains: rcu-read-lock: 5
trinity-c79-3355  [005] .Ns1   104.835725: rebalance_domains: rcu-read-unlock: 5
<idle>-0     [008] .Ns1   104.835746: rebalance_domains: rcu-read-lock: 8
<idle>-0     [008] .Ns1   104.835751: load_balance: dst_cpu: 8 cpus: 0-1,3-4,6-7,9
<idle>-0     [008] .Ns2   104.835759: load_balance: dst_cpu: 8 cpus: 0-1,3-4,6-7,9
<idle>-0     [008] .Ns1   104.835761: rebalance_domains: rcu-read-unlock: 8
trinity-c28-3303  [006] d..1   104.835817: pick_next_task_fair: rcu-read-lock: 6
trinity-c28-3303  [006] d..1   104.835820: load_balance: dst_cpu: 6 cpus: 1,3-4,6-7,9
trinity-c28-3303  [006] d..1   104.835824: load_balance: dst_cpu: 6 cpus: 1,3-4,6-7,9
trinity-c28-3303  [006] d..1   104.835829: pick_next_task_fair: rcu-read-unlock: 6
rcu_sched-10    [008] d..1   104.835871: pick_next_task_fair: rcu-read-lock: 8
rcu_sched-10    [008] d..1   104.835874: load_balance: dst_cpu: 8 cpus: 0-1,3-4,6-7,9
rcu_sched-10    [008] d..1   104.835879: load_balance: dst_cpu: 8 cpus: 0-1,3-4,6-7,9
rcu_sched-10    [008] d..1   104.835915: pick_next_task_fair: rcu-read-unlock: 8
trinity-c63-3339  [008] d..1   104.836114: pick_next_task_fair: rcu-read-lock: 8
trinity-c63-3339  [008] d..1   104.836117: load_balance: dst_cpu: 8 cpus: 0-1,3-4,6-7,9
trinity-c63-3339  [008] d..1   104.836122: load_balance: dst_cpu: 8 cpus: 0-1,3-4,6-7,9
trinity-c63-3339  [008] d..1   104.836133: pick_next_task_fair: rcu-read-unlock: 8
ksoftirqd/1-18    [001] ..s.   104.836352: rebalance_domains: rcu-read-lock: 1
ksoftirqd/1-18    [001] ..s.   104.836356: rebalance_domains: rcu-read-unlock: 1
<idle>-0     [000] .Ns1   104.836602: rebalance_domains: rcu-read-lock: 0
<idle>-0     [000] .Ns1   104.836606: rebalance_domains: rcu-read-unlock: 0
migration/0-12    [000] ..s1   104.837059: rebalance_domains: rcu-read-lock: 0
migration/0-12    [000] ..s1   104.837063: rebalance_domains: rcu-read-unlock: 0
migration/6-50    [006] ..s2   104.837087: rebalance_domains: rcu-read-lock: 6
migration/6-50    [006] ..s2   104.837092: rebalance_domains: rcu-read-unlock: 6
<idle>-0     [001] .Ns1   104.843088: rebalance_domains: rcu-read-lock: 1
<idle>-0     [001] .Ns1   104.843093: rebalance_domains: rcu-read-unlock: 1
<idle>-0     [008] .Ns1   104.843269: rebalance_domains: rcu-read-lock: 8
<idle>-0     [008] .Ns1   104.843273: rebalance_domains: rcu-read-unlock: 8
migration/2-24    [002] ..s1   104.855994: rebalance_domains: rcu-read-lock: 2
migration/2-24    [002] ..s1   104.856000: load_balance: dst_cpu: 2 cpus: 6

Thanks,
Sasha

Yeah, could you please upload all of it somewhere? That chunk didn't include any hotplug bits at all.

Much thanks, clue:

[ 2073.495414] NOHZ: local_softirq_pending 202 -- (TIMER_SOFTIRQ | RCU_SOFTIRQ)

cpuhp/2-22 [002] .... 104.797971: sched_cpu_deactivate: not-active: 2 mask: 0-1,3-4,6-7,9

cpuhp/2-22 [002] .... 104.825166: sched_cpu_deactivate: rcu-sync: 2

migration/2-24    [002] ..s1   104.855994: rebalance_domains: rcu-read-lock: 2
migration/2-24    [002] ..s1   104.856000: load_balance: dst_cpu: 2 cpus: 6

supposed fix; could you please verify?

---
 kernel/sched/fair.c | 7 +++++++
 1 file changed, 7 insertions(+)

index 350dbec01523..35f0168fb609 100644
@@ -8392,6 +8392,13 @@ static int should_we_balance(struct lb_env *env)
 	struct sched_group *sg = env->sd->groups;
 	int cpu, balance_cpu = -1;
 
+	/*
+	 * Ensure the balancing environment is consistent; can happen
+	 * when the softirq triggers 'during' hotplug.
+	 */
+	if (!cpumask_test_cpu(env->dst_cpu, env->cpus))
+		return 0;
+
 	/*
 	 * In the newly idle case, we will allow all the cpu's
 	 * to do the newly idle load balance.

Patch works, thanks!

Thanks,
Sasha

I'm forever late for editing my kernel cmdline, add a runtime knob to disable the "sched_debug" thing.

---

@@ -181,11 +181,16 @@ static const struct file_operations sche
 	.release	= single_release,
 };
 
+__read_mostly bool sched_debug_enabled;
+
 static __init int sched_init_debug(void)
 {
 	debugfs_create_file("sched_features", 0644, NULL, NULL,
 			&sched_feat_fops);
 
+	debugfs_create_bool("sched_debug", 0644, NULL,
+			&sched_debug_enabled);
+
 	return 0;
 }
 late_initcall(sched_init_debug);

@@ -1954,6 +1954,8 @@ extern struct sched_entity *__pick_first
 extern struct sched_entity *__pick_last_entity(struct cfs_rq *cfs_rq);
 
 #ifdef	CONFIG_SCHED_DEBUG
+extern bool sched_debug_enabled;
+
 extern void print_cfs_stats(struct seq_file *m, int cpu);
 extern void print_rt_stats(struct seq_file *m, int cpu);
 extern void print_dl_stats(struct seq_file *m, int cpu);

@@ -14,11 +14,9 @@ cpumask_var_t sched_domains_tmpmask2;
 
 #ifdef CONFIG_SCHED_DEBUG
 
-static __read_mostly int sched_debug_enabled;
-
 static int __init sched_debug_setup(char *str)
 {
-	sched_debug_enabled = 1;
+	sched_debug_enabled = true;
 
 	return 0;
 }