2008-08-26 23:23:50

by Aaron Straus

[permalink] [raw]
Subject: drivers/char/random.c line 728 BUG

Hi,

We saw this oops. Kernel is vanilla 2.6.26.2. Machine is Dell
PowerEdge 1750.

I saw one other instance mentioned on kerneloops but the link didn't
seem to go to the proper place.

Let me know if you need more information.

Thanks,
=a=

------------[ cut here ]------------
kernel BUG at drivers/char/random.c:728!
invalid opcode: 0000 [#1] PREEMPT SMP
Modules linked in: nfs lockd autofs4 sunrpc firmware_class ohci_hcd usbcore tg3 [last unloaded: x_tables]

Pid: 31251, comm: python Not tainted (2.6.26.2-asb #18)
EIP: 0060:[<c0219cd7>] EFLAGS: 00010206 CPU: 1
EIP is at account+0x1f/0xca
EAX: 00000400 EBX: c03c2f98 ECX: 00000000 EDX: 00001000
ESI: c03c2f98 EDI: 00001000 EBP: 00000000 ESP: f6b8ff38
DS: 007b ES: 007b FS: 00d8 GS: 0033 SS: 0068
Process python (pid: 31251, ti=f6b8e000 task=f790c6c0 task.ti=f6b8e000)
Stack: 3e2efd76 00000000 1ff38c67 32a39c7a 00001000 c03c2f98 c021a215 b76a6000
c021a183 00000000 00000001 b76a6000 c014f8ed 00000000 f71e7a80 b76a6000
c021a215 00001000 c015d9e3 f6b8ffa0 f71e7a80 fffffff7 00000000 f6b8e000
Call Trace:
[<c021a215>] urandom_read+0x0/0xa
[<c021a183>] extract_entropy_user+0x21/0xb3
[<c014f8ed>] do_mmap_pgoff+0x1e7/0x232
[<c021a215>] urandom_read+0x0/0xa
[<c015d9e3>] vfs_read+0x81/0xf4
[<c015dd96>] sys_read+0x3c/0x63
[<c0102bf1>] sysenter_past_esp+0x6a/0x91
[<c0300000>] native_cpu_up+0x2ee/0x63d
=======================
Code: 5f 5d e9 b5 a3 0e 00 5b 5e 5f 5d c3 55 57 56 53 83 ec 10 89 c3 89 d7 89 4c 24 04 8b 6c 24 24 8b 00 8b 00 c1 e0 05 39 43 1c 7e 04 <0f> 0b eb fe 8d 43 14 89 44 24 08 e8 39 a1 0e 00 89 44 24 0c 8b
EIP: [<c0219cd7>] account+0x1f/0xca SS:ESP 0068:f6b8ff38
---[ end trace 275ff84df4f1fc30 ]---

--
===================
Aaron Straus
[email protected]


2008-08-28 22:59:35

by Aaron Straus

[permalink] [raw]
Subject: Re: drivers/char/random.c line 728 BUG

Hi,

On Aug 26 03:59 PM, Aaron Straus wrote:
> kernel BUG at drivers/char/random.c:728!

OK so that's (outside spinlock):

BUG_ON(r->entropy_count > r->poolinfo->POOLBITS);

in credit_entropy_bits we do (inside spinlock):

r->entropy_count += nbits;
if (r->entropy_count < 0) {
DEBUG_ENT("negative entropy/overflow\n");
r->entropy_count = 0;
} else if (r->entropy_count > r->poolinfo->POOLBITS)
r->entropy_count = r->poolinfo->POOLBITS;

I wonder if we got unlucky and did the:

r->entropy_count += nbits

- overflowed the entropy_count THEN
- another thread hits the BUG before this thread reaches

r->entropy_count = r->poolinfo->POOLBITS;

--

I notice before this commit:

commit adc782dae6c4c0f6fb679a48a544cfbcd79ae3dc
Author: Matt Mackall <[email protected]>
Date: Tue Apr 29 01:03:07 2008 -0700

random: simplify and rename credit_entropy_store

The credit_entropy_store function looks like this:

spin_lock_irqsave(&r->lock, flags);

if (r->entropy_count + nbits < 0) {
DEBUG_ENT("negative entropy/overflow (%d+%d)\n",
r->entropy_count, nbits);
r->entropy_count = 0;
} else if (r->entropy_count + nbits > r->poolinfo->POOLBITS) {
r->entropy_count = r->poolinfo->POOLBITS;
} else {
r->entropy_count += nbits;
if (nbits)
DEBUG_ENT("added %d entropy credits to %s\n",
nbits, r->name);
}


Notice the old version is careful not to overflow r->entropy_count at
any point (even within the spinlock). So perhaps that's why we didn't
hit this BUG() in the past?

Thanks!

=a=


--
===================
Aaron Straus
[email protected]

2008-08-29 19:48:47

by Andrew Morton

[permalink] [raw]
Subject: Re: drivers/char/random.c line 728 BUG

On Thu, 28 Aug 2008 15:59:24 -0700
Aaron Straus <[email protected]> wrote:

> Hi,
>
> On Aug 26 03:59 PM, Aaron Straus wrote:
> > kernel BUG at drivers/char/random.c:728!
>
> OK so that's (outside spinlock):
>
> BUG_ON(r->entropy_count > r->poolinfo->POOLBITS);
>
> in credit_entropy_bits we do (inside spinlock):
>
> r->entropy_count += nbits;
> if (r->entropy_count < 0) {
> DEBUG_ENT("negative entropy/overflow\n");
> r->entropy_count = 0;
> } else if (r->entropy_count > r->poolinfo->POOLBITS)
> r->entropy_count = r->poolinfo->POOLBITS;
>
> I wonder if we got unlucky and did the:
>
> r->entropy_count += nbits
>
> - overflowed the entropy_count THEN
> - another thread hits the BUG before this thread reaches
>
> r->entropy_count = r->poolinfo->POOLBITS;
>
> --
>
> I notice before this commit:
>
> commit adc782dae6c4c0f6fb679a48a544cfbcd79ae3dc
> Author: Matt Mackall <[email protected]>
> Date: Tue Apr 29 01:03:07 2008 -0700
>
> random: simplify and rename credit_entropy_store
>
> The credit_entropy_store function looks like this:
>
> spin_lock_irqsave(&r->lock, flags);
>
> if (r->entropy_count + nbits < 0) {
> DEBUG_ENT("negative entropy/overflow (%d+%d)\n",
> r->entropy_count, nbits);
> r->entropy_count = 0;
> } else if (r->entropy_count + nbits > r->poolinfo->POOLBITS) {
> r->entropy_count = r->poolinfo->POOLBITS;
> } else {
> r->entropy_count += nbits;
> if (nbits)
> DEBUG_ENT("added %d entropy credits to %s\n",
> nbits, r->name);
> }
>
>
> Notice the old version is careful not to overflow r->entropy_count at
> any point (even within the spinlock). So perhaps that's why we didn't
> hit this BUG() in the past?
>

yep, I would agree with all that.

How's this look?


From: Andrew Morton <[email protected]>

Fix a bug reported by and diagnosed by Aaron Straus.

This is a regression intruduced into 2.6.26 by

commit adc782dae6c4c0f6fb679a48a544cfbcd79ae3dc
Author: Matt Mackall <[email protected]>
Date: Tue Apr 29 01:03:07 2008 -0700

random: simplify and rename credit_entropy_store

credit_entropy_bits() does:

spin_lock_irqsave(&r->lock, flags);
...
if (r->entropy_count > r->poolinfo->POOLBITS)
r->entropy_count = r->poolinfo->POOLBITS;

so there is a time window in which this BUG_ON():

static size_t account(struct entropy_store *r, size_t nbytes, int min,
int reserved)
{
unsigned long flags;

BUG_ON(r->entropy_count > r->poolinfo->POOLBITS);

/* Hold lock while accounting */
spin_lock_irqsave(&r->lock, flags);

can trigger.

We could fix this by moving the assertion inside the lock, but it seems
safer and saner to revert to the old behaviour wherein
entropy_store.entropy_count at no time exceeds
entropy_store.poolinfo->POOLBITS.

Reported-by: Aaron Straus <[email protected]>
Cc: Matt Mackall <[email protected]>
Cc: Theodore Ts'o <[email protected]>
Cc: <[email protected]> [2.6.26.x]
Signed-off-by: Andrew Morton <[email protected]>
---

drivers/char/random.c | 17 +++++++++--------
1 file changed, 9 insertions(+), 8 deletions(-)

diff -puN drivers/char/random.c~drivers-char-randomc-fix-a-race-which-can-lead-to-a-bogus-bug drivers/char/random.c
--- a/drivers/char/random.c~drivers-char-randomc-fix-a-race-which-can-lead-to-a-bogus-bug
+++ a/drivers/char/random.c
@@ -520,6 +520,7 @@ static void mix_pool_bytes(struct entrop
static void credit_entropy_bits(struct entropy_store *r, int nbits)
{
unsigned long flags;
+ int entropy_count;

if (!nbits)
return;
@@ -527,20 +528,20 @@ static void credit_entropy_bits(struct e
spin_lock_irqsave(&r->lock, flags);

DEBUG_ENT("added %d entropy credits to %s\n", nbits, r->name);
- r->entropy_count += nbits;
- if (r->entropy_count < 0) {
+ entropy_count = r->entropy_count;
+ entropy_count += nbits;
+ if (entropy_count < 0) {
DEBUG_ENT("negative entropy/overflow\n");
- r->entropy_count = 0;
- } else if (r->entropy_count > r->poolinfo->POOLBITS)
- r->entropy_count = r->poolinfo->POOLBITS;
+ entropy_count = 0;
+ } else if (entropy_count > r->poolinfo->POOLBITS)
+ entropy_count = r->poolinfo->POOLBITS;

/* should we wake readers? */
- if (r == &input_pool &&
- r->entropy_count >= random_read_wakeup_thresh) {
+ if (r == &input_pool && entropy_count >= random_read_wakeup_thresh) {
wake_up_interruptible(&random_read_wait);
kill_fasync(&fasync, SIGIO, POLL_IN);
}
-
+ r->entropy_count = entropy_count;
spin_unlock_irqrestore(&r->lock, flags);
}

_

2008-08-29 19:55:37

by Andrew Morton

[permalink] [raw]
Subject: Re: drivers/char/random.c line 728 BUG

On Fri, 29 Aug 2008 12:48:07 -0700
Andrew Morton <[email protected]> wrote:

> We could fix this by moving the assertion inside the lock, but it seems
> safer and saner to revert to the old behaviour wherein
> entropy_store.entropy_count at no time exceeds
> entropy_store.poolinfo->POOLBITS.

The fixed version even generates improved code.

Let's try to avoid repeats:

--- a/drivers/char/random.c~drivers-char-randomc-fix-a-race-which-can-lead-to-a-bogus-bug-fix
+++ a/drivers/char/random.c
@@ -407,7 +407,7 @@ struct entropy_store {
/* read-write data: */
spinlock_t lock;
unsigned add_ptr;
- int entropy_count;
+ int entropy_count; /* Must at no time exceed ->POOLBITS! */
int input_rotate;
};

_

2008-08-29 22:32:09

by Aaron Straus

[permalink] [raw]
Subject: Re: drivers/char/random.c line 728 BUG

Hi,

On Aug 29 12:48 PM, Andrew Morton wrote:
> yep, I would agree with all that.

Thanks for responding.

> How's this look?

Quick question off list... below

> - if (r == &input_pool &&
> - r->entropy_count >= random_read_wakeup_thresh) {
> + if (r == &input_pool && entropy_count >= random_read_wakeup_thresh) {
> wake_up_interruptible(&random_read_wait);
> kill_fasync(&fasync, SIGIO, POLL_IN);
> }
> -
> + r->entropy_count = entropy_count;

Here you set the entropy_count in the pool *after* waking up the reader.
I was a little worried the reader would find the entropy_count unchanged
and go back to sleep.


Regards,
=a=

--
===================
Aaron Straus
[email protected]

2008-08-29 22:43:13

by Andrew Morton

[permalink] [raw]
Subject: Re: drivers/char/random.c line 728 BUG

On Fri, 29 Aug 2008 15:31:55 -0700
Aaron Straus <[email protected]> wrote:

> > - if (r == &input_pool &&
> > - r->entropy_count >= random_read_wakeup_thresh) {
> > + if (r == &input_pool && entropy_count >= random_read_wakeup_thresh) {
> > wake_up_interruptible(&random_read_wait);
> > kill_fasync(&fasync, SIGIO, POLL_IN);
> > }
> > -
> > + r->entropy_count = entropy_count;
>
> Here you set the entropy_count in the pool *after* waking up the reader.
> I was a little worried the reader would find the entropy_count unchanged
> and go back to sleep.
>

Probably it doesn't matter because of the coverage of the lock but yes,
let's do the assignment first.

--- a/drivers/char/random.c~drivers-char-randomc-fix-a-race-which-can-lead-to-a-bogus-bug-fix-fix
+++ a/drivers/char/random.c
@@ -535,13 +535,13 @@ static void credit_entropy_bits(struct e
entropy_count = 0;
} else if (entropy_count > r->poolinfo->POOLBITS)
entropy_count = r->poolinfo->POOLBITS;
+ r->entropy_count = entropy_count;

/* should we wake readers? */
if (r == &input_pool && entropy_count >= random_read_wakeup_thresh) {
wake_up_interruptible(&random_read_wait);
kill_fasync(&fasync, SIGIO, POLL_IN);
}
- r->entropy_count = entropy_count;
spin_unlock_irqrestore(&r->lock, flags);
}

_