Re: [PATCH] timer: silenct a lockdep splat with debugobjects

From: Peter Zijlstra
Date: Fri Mar 13 2020 - 14:08:26 EST


On Fri, Mar 13, 2020 at 11:42:21AM -0400, Qian Cai wrote:
> psi_enqueue() calls add_timer() with pi->lock and rq->lock held which
> in-turn could allcate with debugobjcets in the locking order,
>
> pi->lock
> rq->lock
> base->lock
> batched_entropy_u32.lock
>
> while the random code could always call into the scheduler via
> try_to_wake_up() in the locking order,
>
> batched_entropy_u32.lock
> pi->lock
>
> Thus, it could generate a lockdep splat below right after boot. Ideally,
> psi_enqueue() might be able to be called without either pi->lock or
> rq->lock held, but it is tricky to do.
>
> Since,
>
> 1) debugobjects is only used in a debug kernel.
> 2) the chance to trigger a real deadlock is relative low.
> 3) once the splat happened, it will disable lockdep to prevent it from
> catching any more important issues later.
>
> just silent the splat by temporarily lettting lockdep ignore lockes
> inside debug_timer_activate() which sounds like a reasonable tradeoff
> for debug kernels.


> diff --git a/kernel/time/timer.c b/kernel/time/timer.c
> index 4820823515e9..27bfb8376d71 100644
> --- a/kernel/time/timer.c
> +++ b/kernel/time/timer.c
> @@ -1036,7 +1036,13 @@ __mod_timer(struct timer_list *timer, unsigned long expires, unsigned int option
> }
> }
>
> + /*
> + * It will allocate under rq->lock and trigger a lockdep slat with
> + * random code. Don't disable lockdep with debugobjects.
> + */
> + lockdep_off();
> debug_timer_activate(timer);
> + lockdep_on();
>
> timer->expires = expires;
> /*

You have to be f'ing kidding me. You've just earned yourself a lifetime
membership of 'the tinker crew'.

> 00: [ 321.355501] -> #3 (batched_entropy_u32.lock){-.-.}:
> 00: [ 321.355523] lock_acquire+0x212/0x460
> 00: [ 321.355536] _raw_spin_lock_irqsave+0xc4/0xe0
> 00: [ 321.355551] get_random_u32+0x5a/0x138
> 00: [ 321.355564] new_slab+0x188/0x760
> 00: [ 321.355576] ___slab_alloc+0x5d2/0x928
> 00: [ 321.355589] __slab_alloc+0x52/0x88
> 00: [ 321.355801] kmem_cache_alloc+0x34a/0x558
> 00: [ 321.355819] fill_pool+0x29e/0x490
> 00: [ 321.355835] __debug_object_init+0xa0/0x828
> 00: [ 321.355848] debug_object_activate+0x200/0x368
> 00: [ 321.355864] add_timer+0x242/0x538
> 00: [ 321.355877] queue_delayed_work_on+0x13e/0x148
> 00: [ 321.355893] init_mm_internals+0x4c6/0x550
> 00: [ 321.355905] kernel_init_freeable+0x224/0x590
> 00: [ 321.355921] kernel_init+0x22/0x188
> 00: [ 321.355933] ret_from_fork+0x30/0x34

Did you actually look at debug_object_activate() and read?

The only reason that is calling into __debug_object_init() is because it
hadn't been initialized yet when it got activated. That *immediately*
should've been a clue.

You can initialize this stuff early. For instance:

INIT_DELAYED_WORK()
__INIT_DELAYED_WORK()
__init_timer()
init_timer_key()
debug_init()
debug_timer_init()
debug_object_init()
__debug_object_init()

And we're right at where the above callchain goes wrong.

Now, it actually looks like kernel/sched/psi.c actually initializes all
delayed works it uses. This then leaves other random delayed works to
establish the base->lock <- entropy.lock relation.

This just means we need to find and kill all such delayed_work users
that fail to properly initialize their data structure.

I'm not going to do that just now, the kids need attention.