Re: [RFC][PATCH -next 2/2] printk: set may_schedule for some of console_trylock callers

[Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com>]

On (01/20/16 12:50), Sergey Senozhatsky wrote:
[..]
> > Hmm, the notifiers are called via __raw_notifier_call_chain().
> > There is a comment above this function:
> > 
> >  *	Calls each function in a notifier chain in turn.  The functions
> >  *	run in an undefined context.
> >  *	All locking must be provided by the caller.
> > 
> > But hmm, you are right that the notifiers do malloc, take mutextes,
> > etc. The question is if schedule does something in this case. I would
> > expect that the is no running task assigned to this CPU at this stage.
> > So, cond_resched is probably a noop in this case.

I did some modifications to notifier, just to check how real that theoretical
race condition can possible be.

And here are notifications sent by *offline* cpu to itself (to offline cpu).

[   73.861462] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:sched_cpu_active+0x0/0x55
[   73.861466] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:sched_domains_numa_masks_update+0x0/0xd
[   73.861469] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:cpuset_cpu_active+0x0/0x42
[   73.861473] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:vgetcpu_cpu_notifier+0x0/0x30
[   73.861476] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:uncore_cpu_notifier+0x0/0x20f
[   73.861480] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:perf_cpu_notify+0x0/0x36
[   73.861483] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:x86_pmu_notifier+0x0/0xb0
[   73.861490] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:cstate_cpu_notifier+0x0/0x1c1
[   73.861493] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:migration_call+0x0/0x328
[   73.861496] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:smpboot_thread_call+0x0/0x28
[   73.861500] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:workqueue_cpu_up_callback+0x0/0x426
[   73.861503] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:page_alloc_cpu_notify+0x0/0x41
[   73.861506] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:slab_cpuup_callback+0x0/0xed
[   73.861508] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:sched_ilb_notifier+0x0/0x78
[   73.861511] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:rcu_cpu_notify+0x0/0x3f0
[   73.861514] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:rb_cpu_notify+0x0/0xde
[   73.861516] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:rb_cpu_notify+0x0/0xde
[   73.861520] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:radix_tree_callback+0x0/0x50
[   73.861522] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:timer_cpu_notify+0x0/0x136
[   73.861525] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:hrtimer_cpu_notify+0x0/0x290
[   73.861528] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:hotplug_cfd+0x0/0x80
[   73.861531] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:buffer_cpu_notify+0x0/0x85
[   73.861533] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:ratelimit_handler+0x0/0x27
[   73.861536] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:cpu_callback+0x0/0x150
[   73.861538] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:relay_hotcpu_callback+0x0/0xc7
[   73.861540] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:hotplug_hrtick+0x0/0x76
[   73.861543] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:memcg_cpu_hotplug_callback+0x0/0x3d
[   73.861546] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:blk_cpu_notify+0x0/0x8d
[   73.861549] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:blk_mq_main_cpu_notify+0x0/0x67
[   73.861552] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:blk_mq_queue_reinit_notify+0x0/0x1b3
[   73.861556] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:dev_cpu_callback+0x0/0x195
[   73.861559] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:cpu_callback+0x0/0x4e
[   73.861562] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:vmstat_cpuup_callback+0x0/0x83
[   73.861565] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:percpu_counter_hotcpu_callback+0x0/0x8b
[   73.861567] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:cpu_hotplug_notify+0x0/0x65
[   73.861571] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:topology_cpu_callback+0x0/0x6e
[   73.861574] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:cacheinfo_cpu_callback+0x0/0x76
[   73.861577] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:mce_cpu_callback+0x0/0xee
[   73.861580] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:mc_cpu_callback+0x0/0xad
[   73.861582] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:console_cpu_notify+0x0/0x35
[   73.861587] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:acpi_cpu_soft_notify+0x0/0xe0 [processor]
[   73.861590] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:boost_notify+0x0/0x5f [acpi_cpufreq]
[   73.861593] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:cpufreq_cpu_callback+0x0/0x46
[   73.861597] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:coretemp_cpu_callback+0x0/0x1bd [coretemp]
[   73.861599] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:workqueue_cpu_down_callback+0x0/0xde
[   73.861602] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:hpet_cpuhp_notify+0x0/0x162
[   73.861604] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:sched_cpu_inactive+0x0/0x27
[   73.861606] SELF NOTIFY [by swapper/2] from cpu:2 to:2 (dec:2) action name:CPU_STARTING [code:10] callback:cpuset_cpu_inactive+0x0/0x231


so on my quite small x86_64 kernel (I'm trying to keep unneeded stuff out of the image), that's a bit
bigger than I'd expected.




so I have the new patch set. and it seems to be working on my simple tests.

but... hm... a bit concerned about CPU_DOWN path.

DOWN notification sequence is
CPU_DOWN_PREPARE -> __cpu_disable() -> CPU_DYING -> CPU_DEAD -> CPU_POST_DEAD

__cpu_disable() is getting called before cpu_notify(CPU_DYING), and
__cpu_disable() sets set_cpu_online(cpu, false).

kernel/sched/core.c   migration_call()

	case CPU_DYING:
		sched_ttwu_pending();
		/* Update our root-domain */
		raw_spin_lock_irqsave(&rq->lock, flags);
		if (rq->rd) {
			BUG_ON(!cpumask_test_cpu(cpu, rq->rd->span));
			set_rq_offline(rq);
		}
		migrate_tasks(rq);
		BUG_ON(rq->nr_running != 1); /* the migration thread */
		raw_spin_unlock_irqrestore(&rq->lock, flags);
		break;

so it's only when CPU is already !cpu_online scheduler does set_rq_offline() and
migrate_tasks(rq).

the good news is that CPU_DOWN_PREPARE disables CPU's rq ->hrtick_timer,
so no rq ticks. but what happens on !CONFIG_SCHED_HRTICK systems?... scheduler_tick
is getting disabled because we clear APIC and thus stop timer interrupts? I have a
little knowledge here, sorry. so I'll better ask. Is it possible to get !online cpu
and still iterating in this console_unlock() loop? I suspect that the answer is no,
but better be sure.

	-ss