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

From: Sergey Senozhatsky
Date: Wed Jan 20 2016 - 06:50:40 EST


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