Re: [PATCH v4] lib/spinlock_debug.c: prevent a recursive cycle in the debug code

[Sergey Senozhatsky]

On (01/28/16 15:08), Peter Hurley wrote:
[..]
> > even if at some level of recursion (nested printk calls)
> > spin_dump()->__spin_lock_debug()->arch_spin_trylock() acquires the
> > lock, it returns back with the spin lock unlocked anyway.
> > 
> > vprintk_emit()
> >  console_trylock()
> >   spin_lock()
> >    spin_dump()
> >     vprintk_emit()
> >      console_trylock()
> >       spin_lock()
> >        spin_dump()
> >         vprintk_emit()
> >          console_trylock()
> >           spin_lock()     << OK, got the lock finally
> 
> The problem is you have postulated a very shallow recursion.
> This looks much worse if this happens 1000 times, and
> probably won't recover to output anything.

well, the stack is surely limited, but on every
spin_dump()->spin_lock() recursive call it does another
round of

	u64 loops = loops_per_jiffy * HZ;

	for (i = 0; i < loops; i++) {
		if (arch_spin_trylock(&lock->raw_lock))
			return;
		__delay(1);
	}

so if you have 1000 spin_dump()->spin_lock() then, well,
something has been holding the lock for '1000 * loops_per_jiffy * HZ'.

and in particularly this case that somethign was holding the
spin lock doing trivial operations like

	count = sem->count - 1;
	if (likely(count >= 0))
		sem->count = count;

(or a bit more if it was in down()). but still.

and it's kinda hard to imagine console_sem lock being soooooooo
congested and unfair. on each given point of time in the worst
case there are `num_online_cpus() - 1' cpus spinning on that spin_lock
and 1 cpu holding that spinlock. which in Byungchul's case is, what,
3 spinning cpus, or 7 spinnign cpus?...


> Additionally, what if the console_sem is simply corrupted?
> A livelock with no output ever is not very helpful.

if it's corrupted then this is not a spinlock debug problem.
at all.


> As I wrote earlier, I don't think this is the way to fix
> recursion problems with printk() [by eliding output].
> 
> Rather, a way to effectively determine a recursion is in progress,
> and _at a minimum_ guaranteeing that the recursive output will
> eventually be output should be the goal.
> 
> Including dumb recursion like a console driver printing
> an error :/

this is not a case of printk recursion and it should be handled
just fine. console drivers are called under console_sem only.
logbuf lock is unlocked. vprintk_emit() adds message to the logbuf,
calls console_trylock() (which of course does not lock anything)
and returns back to console_driver code.

the only case when we really have a printk recursion is when
someone calls printk() from within the vprintk_emit() logbuf_lock
area.

print()
 spin_lock logbuf
   printk()
     spin_lock logbuf <<< recursion
 spin_unlock logbuf


	-ss

> Then, lockdep could remain enabled while calling console drivers.
> 
> Regards,
> Peter Hurley
> 
> >            sem->count--
> >           spin_unlock()   << unlock, return
> >        arch_spin_lock()   << got the lock, return
> >       sem->count--
> >       spin_unlock() << unlock, return
> >    arch_spin_lock() << got the lock, return
> >   sem->count--
> >   spin_unlock() << unlock, return
> > 
> > 
> > ...um
> > 
> > 
> >> But I found there's a possiblity in the debug code *itself* to cause a
> >> lockup.
> > 
> > please explain.
> > 
> > 	-ss
> > 
>