linux-kernel - Re: [RFC PATCH 1/2] printk: print initial logbuf contents before re-enabling interrupts

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [day] [month] [year] [list]

Message-ID: <20140425142056.GB12157@arm.com>
Date:	Fri, 25 Apr 2014 15:20:56 +0100
From:	Will Deacon <will.deacon@....com>
To:	Peter Zijlstra <peterz@...radead.org>
Cc:	"linux-kernel@...r.kernel.org" <linux-kernel@...r.kernel.org>,
	Andrew Morton <akpm@...ux-foundation.org>,
	Kay Sievers <kay@...y.org>
Subject: Re: [RFC PATCH 1/2] printk: print initial logbuf contents before
 re-enabling interrupts

On Fri, Apr 25, 2014 at 03:01:20PM +0100, Peter Zijlstra wrote:
> On Fri, Apr 25, 2014 at 02:29:37PM +0100, Will Deacon wrote:
> > On Thu, Apr 17, 2014 at 12:36:09PM +0100, Will Deacon wrote:
> > > When running on a hideously slow system (~10Mhz FPGA) with a bunch of
> 
> Hey, still faster then the 4.77 MHz 8088 chips I started with :-)

... but you didn't have to run KVM guests on that sucker!

> > > debug printk invocations on the timer interrupt path, we end up filling
> > > the log buffer faster than we can drain it.
> > > 
> > > The reason is that console_unlock (which is responsible for moving
> > > messages out of logbuf to hand over to the console driver) removes one
> > > message at a time, briefly re-enabling interrupts between each of them.
> > > If the interrupt path prints more than a single message, then we can
> > > easily generate more messages than we can print for a regular, recurring
> > > interrupt (e.g. a 1khz timer). This results in messages getting silently
> > > dropped, leading to counter-intuitive, incomplete printk traces on the
> > > console.
> > > 
> > > Rather than run the console_unlock loop with interrupts disabled (which
> > > has obvious latency problems), this patch records the sequence number of
> > > the last message in the log buffer after taking the logbuf_lock. We can
> > > then print this fixed amount of work before re-enabling interrupts again,
> > > making sure we keep up with ourself. Other CPUs could still potentially
> > > flood the buffer, but there's little that we can do to protect against
> > > that.
> > 
> > Any thoughts on these two patches? I can understand the reluctance to make
> > changes to printk, but I had a horrible time debugging timers without these
> > patches!
> 
> They look fine to me.

Thanks, Peter. Andrew, would you mind taking these please? They look a bit
out of place in the arm64 tree.

I can repost them if necessary.

Cheers,

Will
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/