Patchwork [PATCH/RFC,v5,4/5] : core: Add dump device to call on oopses and panics

login
register
mail settings
Submitter Artem Bityutskiy
Date Nov. 30, 2009, 8:51 a.m.
Message ID <1259571118.7518.56.camel@localhost>
Download mbox | patch
Permalink /patch/39790/
State RFC
Headers show

Comments

Artem Bityutskiy - Nov. 30, 2009, 8:51 a.m.
On Mon, 2009-11-30 at 08:46 +0100, Jörn Engel wrote:
> On Mon, 30 November 2009 09:27:51 +0200, Artem Bityutskiy wrote:
> > 
> > To me it looks like 'log_end' is not supposed to wrap. What makes you
> > think it can? In which cases it can?
> 
> It is a 32bit variable.  Would do you expect happens once you reach
> 0xffffffff and add 1?

Yes, now I see log_end is an ever increasing variable.

How about this patch on top of the existing one (untested):



Then the whole function will look like this:

/**
 * kmsg_dump - dump kernel log to kernel message dumpers.
 * @reason: the reason (oops, panic etc) for dumping
 *
 * Iterate through each of the dump devices and call the oops/panic
 * callbacks with the log buffer.
 */
void kmsg_dump(enum kmsg_dump_reason reason)
{
        unsigned long end = ACCESS_ONCE(log_end) & LOG_BUF_MASK;
        struct kmsg_dumper *dumper;
        const char *s1, *s2;
        unsigned long l1, l2;
        unsigned long flags;

        /*
         * Have we ever rotated around the circular buffer? If we never did,
         * we have to have zeroes at the end.
         */
        if (log_buf[end]) {
                s1 = log_buf + end;
                l1 = log_buf_len - end;
        } else {
                s1 = "";
                l1 = 0;
        }

        s2 = log_buf;
        l2 = end;

        if (!spin_trylock_irqsave(&dump_list_lock, flags)) {
                printk(KERN_ERR "dump_kmsg: dump list lock is held during %s, skipping dump\n",
                                kmsg_to_str(reason));
                return;
        }
        list_for_each_entry(dumper, &dump_list, list)
                dumper->dump(dumper, reason, s1, l1, s2, l2);
        spin_unlock_irqrestore(&dump_list_lock, flags);
}
Jörn Engel - Nov. 30, 2009, 9:35 a.m.
On Mon, 30 November 2009 10:51:58 +0200, Artem Bityutskiy wrote:
> 
> How about this patch on top of the existing one (untested):
> 
> +	/*
> +	 * Have we ever rotated around the circular buffer? If we never did,
> +	 * we have to have zeroes at the end.
> +	 */
> +	if (log_buf[end]) {
> +		s1 = log_buf + end;
> +		l1 = log_buf_len - end;
> +	} else {
> +		s1 = "";
> +		l1 = 0;

So now you are assuming that a) the buffer is initially zeroed and b)
noone ever writes NUL to it.  Is that correct?

I'm not sure whether those assumptions are valid.  If they are, then
this will obviously work.  Otherwise we can just always assume the
wrapped case.

Jörn
Artem Bityutskiy - Nov. 30, 2009, 9:40 a.m.
On Mon, 2009-11-30 at 10:35 +0100, Jörn Engel wrote:
> On Mon, 30 November 2009 10:51:58 +0200, Artem Bityutskiy wrote:
> > 
> > How about this patch on top of the existing one (untested):
> > 
> > +	/*
> > +	 * Have we ever rotated around the circular buffer? If we never did,
> > +	 * we have to have zeroes at the end.
> > +	 */
> > +	if (log_buf[end]) {
> > +		s1 = log_buf + end;
> > +		l1 = log_buf_len - end;
> > +	} else {
> > +		s1 = "";
> > +		l1 = 0;
> 
> So now you are assuming that a) the buffer is initially zeroed and b)
> noone ever writes NUL to it.  Is that correct?

a) seems to be true because the buffer is either a static array or a
bootmem alloc, which seems to memzero the buffers it returns, at least
AFAICS. But I did not test this.

vs b). well, the printk ring buffer should contain ASCII, so I assumed
binary zeroes should not be possible there.

> I'm not sure whether those assumptions are valid.  If they are, then
> this will obviously work.  Otherwise we can just always assume the
> wrapped case.

Of course someone who has more knowlege about the printk buffer should
comment on this.

The other alternative I was thinking about was to introduce a boolean
flag, and set it to one as soon as 'lon_end' becomes larger than
'log_buf_len'.
Simon Kagstrom - Nov. 30, 2009, 9:53 a.m.
On Mon, 30 Nov 2009 11:40:55 +0200
Artem Bityutskiy <dedekind1@gmail.com> wrote:

> > > +	/*
> > > +	 * Have we ever rotated around the circular buffer? If we never did,
> > > +	 * we have to have zeroes at the end.
> > > +	 */
> > > +	if (log_buf[end]) {
> > > +		s1 = log_buf + end;
> > > +		l1 = log_buf_len - end;
> > > +	} else {
> > > +		s1 = "";
> > > +		l1 = 0;
> > 
> > So now you are assuming that a) the buffer is initially zeroed and b)
> > noone ever writes NUL to it.  Is that correct?
> 
> a) seems to be true because the buffer is either a static array or a
> bootmem alloc, which seems to memzero the buffers it returns, at least
> AFAICS. But I did not test this.

True as far as I can see.

> vs b). well, the printk ring buffer should contain ASCII, so I assumed
> binary zeroes should not be possible there.

Yes, if this would be printed with printk it sounds like a bug to me.

I've tested your patch, and it seems to work fine both 1) before the
buffer is filled, 2) when the buffer has wrapped and 3) when log_end
wraps (although that part was a quick hack).

So

Tested-by: Simon Kagstrom <simon.kagstrom@netinsight.net>

// Simon
Jörn Engel - Nov. 30, 2009, 9:54 a.m.
On Mon, 30 November 2009 11:40:55 +0200, Artem Bityutskiy wrote:
> 
> The other alternative I was thinking about was to introduce a boolean
> flag, and set it to one as soon as 'lon_end' becomes larger than
> 'log_buf_len'.

I've thought about that as well.  The drawback is that we would have to
check in the regular printk path - by the time the panic notifier is
running it is too late.  So it adds cost to the regular case.

Jörn
Simon Kagstrom - Nov. 30, 2009, 12:03 p.m.
On Mon, 30 Nov 2009 11:56:42 +0000
David Woodhouse <dwmw2@infradead.org> wrote:

> On Mon, 2009-11-30 at 12:37 +0100, Simon Kagstrom wrote:
> > I'm a bit worried about taking the lock here - can't we end up with a
> > deadlock if we happen to crash in the wrong place? 
> 
> Um, yes -- just as the existing version can end up with a deadlock if we
> happen to crash while adding or removing a dumper and holding _that_
> lock. Try calling kmsg_dump_unregister(NULL), or putting a dumper in a
> module and then unloading that module without deregistering it, etc.

Well, actually we've thought of that:

	if (!spin_trylock_irqsave(&dump_list_lock, flags)) {
		printk(KERN_ERR "dump_kmsg: dump list lock is held during %s, skipping dump\n",
				kmsg_to_str(reason));
		return;
	}
	list_for_each_entry(dumper, &dump_list, list)
		dumper->dump(dumper, reason, s1, l1, s2, l2);
	spin_unlock_irqrestore(&dump_list_lock, flags);

Anyway, I'm happy with the explanation, so keep the lock in.

// Simon

Patch

diff --git a/kernel/printk.c b/kernel/printk.c
index f711b99..66995ca 100644
--- a/kernel/printk.c
+++ b/kernel/printk.c
@@ -1486,28 +1486,27 @@  static const char *kmsg_to_str(enum kmsg_dump_reason reason)
  */
 void kmsg_dump(enum kmsg_dump_reason reason)
 {
-	unsigned long len = ACCESS_ONCE(log_end);
+	unsigned long end = ACCESS_ONCE(log_end) & LOG_BUF_MASK;
 	struct kmsg_dumper *dumper;
 	const char *s1, *s2;
 	unsigned long l1, l2;
 	unsigned long flags;
 
-	s1 = "";
-	l1 = 0;
-	s2 = log_buf;
-	l2 = len;
-
-	/* Have we rotated around the circular buffer? */
-	if (len > log_buf_len) {
-		unsigned long pos = len & LOG_BUF_MASK;
-
-		s1 = log_buf + pos;
-		l1 = log_buf_len - pos;
-
-		s2 = log_buf;
-		l2 = pos;
+	/*
+	 * Have we ever rotated around the circular buffer? If we never did,
+	 * we have to have zeroes at the end.
+	 */
+	if (log_buf[end]) {
+		s1 = log_buf + end;
+		l1 = log_buf_len - end;
+	} else {
+		s1 = "";
+		l1 = 0;
 	}
 
+	s2 = log_buf;
+	l2 = end;
+
 	if (!spin_trylock_irqsave(&dump_list_lock, flags)) {
 		printk(KERN_ERR "dump_kmsg: dump list lock is held during %s, skipping dump\n",
 				kmsg_to_str(reason));