Re: [PATCH 6/9] printk: Release lockbuf_lock before calling console_trylock_for_printk()

Jan Kara
2014-01-03T07:49:40Z

On Thu 02-01-14 20:53:05, Steven Rostedt wrote:
> On Mon, 23 Dec 2013 21:39:27 +0100
> Jan Kara <jack@suse.cz> wrote:
>
> > There's no reason to hold lockbuf_lock when entering
> > console_trylock_for_printk(). The first thing this function does is
> > calling down_trylock(console_sem) and if that fails it immediately
> > unlocks lockbuf_lock. So lockbuf_lock isn't needed for that branch.
> > When down_trylock() succeeds, the rest of console_trylock() is OK
> > without lockbuf_lock (it is called without it from other places), and
> > the only remaining thing in console_trylock_for_printk() is
> > can_use_console() call. For that call console_sem is enough (it
> > iterates all consoles and checks CON_ANYTIME flag).
> >
> > So we drop logbuf_lock before entering console_trylock_for_printk()
> > which simplifies the code.
>
> I'm very nervous about this change. The interlocking between console
> lock and logbuf_lock seems to be very subtle. Especially the comment
> where logbuf_lock is defined:
>
> /*
> * The logbuf_lock protects kmsg buffer, indices, counters. It is also
> * used in interesting ways to provide interlocking in console_unlock();
> */
>
> Unfortunately, it does not specify what those "interesting ways" are.
Hum, yes. So I was digging in history and the comment was added by Andrew
Morton in early 2002 when converting console_lock to console_sem +
logbuf_lock. I'm sure he remembers all the details ;) It is part of commit
a880f45a48be2956d2c78a839c472287d54435c1 in linux-history.git.

Looking into that commit I think the comment refers to the following trick:
printk()
/* This stops the holder of console_sem just where we want him */
spin_lock_irqsave(&logbuf_lock, flags);
...
if (!down_trylock(&console_sem)) {
/*
* We own the drivers. We can drop the spinlock and let
* release_console_sem() print the text
*/
spin_unlock_irqrestore(&logbuf_lock, flags);
...
} else {
/*
* Someone else owns the drivers. We drop the spinlock, which
* allows the semaphore holder to proceed and to call the
* console drivers with the output which we just produced.
*/
spin_unlock_irqrestore(&logbuf_lock, flags);
}

release_console_sem() (equivalent of today's console_unlock()):
for ( ; ; ) {
spin_lock_irqsave(&logbuf_lock, flags);
...
if (con_start == log_end)
break; /* Nothing to print */
...
spin_unlock_irqrestore(&logbuf_lock, flags);
call_console_drivers(_con_start, _log_end);
}
up(&console_sem);
spin_unlock_irqrestore(&logbuf_lock, flags);

This interesting combination of console_sem and logbuf_lock locking makes
sure we cannot exit the loop in release_console_sem() before printk()
decides whether it should do printing or not. So the appended message gets
reliably printed either by current holder of console_sem or by CPU in
printk(). Apparently this trick got broken sometime later and then fixed up
again by rechecking 'console_seq != log_next_seq' after releasing
console_sem. So I think the comment isn't valid anymore.

> Now what I think this does is to make sure whoever wrote to the logbuf
> first, does the flushing. With your change we now have:
>
> CPU 0 CPU 1
> ----- -----
> printk("blah");
> lock(logbuf_lock);
>
> printk("bazinga!");
> lock(logbuf_lock);
> <blocked>
>
> unlock(logbuf_lock);
> < NMI comes in delays CPU>
>
> <get logbuf_lock>
> unlock(logbuf_lock)
> console_trylock_for_printk()
> console_unlock();
> < dumps output >
>
>
> Now is this a bad thing? I don't know. But the current locking will
> make sure that the first writer into logbuf_lock gets to do the
> dumping, and all the others will just add onto that writer.
>
> Your change now lets the second or third or whatever writer into printk
> be the one that dumps the log.
I agree and I admit I didn't think about this. But given how printk
buffering works this doesn't seem to be any problem at all. But I can
comment about this in the changelog.

> Again, this may not be a big deal, but as printk is such a core part of
> the Linux kernel, and this is a very subtle change, I rather be very
> cautious here and try to think what can go wrong when this happens.
Sure. Thanks for review!

Honza
--
Jan Kara <jack@suse.cz>
SUSE Labs, CR