Re: [PATCH] elevator: Fix a race in elevator switching and md device initialization

[Tomoki Sekiyama <tomoki.sekiyama@hds.com>]

On 8/29/13 16:29 , "Vivek Goyal" <vgoyal@redhat.com> wrote:

>On Mon, Aug 26, 2013 at 09:45:15AM -0400, Tomoki Sekiyama wrote:
>> The soft lockup below happes at the boot time of the system using dm
>> multipath and automated elevator switching udev rules.
>> 
>> [  356.127001] BUG: soft lockup - CPU#3 stuck for 22s! [sh:483]
>> [  356.127001] RIP: 0010:[<ffffffff81072a7d>]  [<ffffffff81072a7d>]
>>lock_timer_base.isra.35+0x1d/0x50
>> ...
>> [  356.127001] Call Trace:
>> [  356.127001]  [<ffffffff81073810>] try_to_del_timer_sync+0x20/0x70
>> [  356.127001]  [<ffffffff8118b08a>] ?
>>kmem_cache_alloc_node_trace+0x20a/0x230
>> [  356.127001]  [<ffffffff810738b2>] del_timer_sync+0x52/0x60
>> [  356.127001]  [<ffffffff812ece22>] cfq_exit_queue+0x32/0xf0
>> [  356.127001]  [<ffffffff812c98df>] elevator_exit+0x2f/0x50
>> [  356.127001]  [<ffffffff812c9f21>] elevator_change+0xf1/0x1c0
>> [  356.127001]  [<ffffffff812caa50>] elv_iosched_store+0x20/0x50
>> [  356.127001]  [<ffffffff812d1d09>] queue_attr_store+0x59/0xb0
>> [  356.127001]  [<ffffffff812143f6>] sysfs_write_file+0xc6/0x140
>> [  356.127001]  [<ffffffff811a326d>] vfs_write+0xbd/0x1e0
>> [  356.127001]  [<ffffffff811a3ca9>] SyS_write+0x49/0xa0
>> [  356.127001]  [<ffffffff8164e899>] system_call_fastpath+0x16/0x1b
>> 
>> This is caused by a race between md device initialization and sysfs knob
>> to switch the scheduler.
>
>I think we can also improve changelog a bit. So IIUC, softlockup
>happens because one thread called del_timer_sync() on a timer which
>was not even initilized. Timer initialization should have happened
>in cfq_init_queue() using init_timer(). But before init_timer()
>could be called, elevator switch path called del_timer_sync().
>
>del_timer_sync() in turn calls lock_timer_base() which will loop
>infinitely if timer->base == NULL. And because we have not called
>init_timer() yet, I am assuming timer->base is null?
>
>Is this right analysis? If yes, then this patch should most likely
>fix following bz.
>
>https://bugzilla.redhat.com/show_bug.cgi?id=902012

I think your analysis is correct. If del_timer_sync() is called right after
cfqd is allocated (with __GFP_ZERO), timer->base == NULL. Otherwise it may
hit NULL pointer.

The other reason of NULL timer->base is that the timer is migrating in
__mod_timer(), but then the it must be set to non-NULL in a short time.

Maybe __mod_timer should use some illegal pointer value (like LIST_POISON1)
instead of NULL to represent the timer is migrating....
Actually, when I changed __mod_timer to timer_set_base(timer, 0xdeadbeaf),
made lock_timer_base wait while base == 0xdeadbeaf, and
added BUG_ON(!timer->base) to lock_timer_base, my system hits the BUG.

>I had concluded that some how timer->base is NULL but could not understand
>how come timer base is NULL when we have called init_timer() on it.
>
>Thanks
>Vivek

Thanks,
Tomoki