2009-03-10 15:16:57

by Alan D. Brunelle

[permalink] [raw]
Subject: PROBLEM: kernel BUG at mm/slab.c:3002!

If some fields are empty or look unusual you may have an old version.
Compare to the current minimal requirements in Documentation/Changes.

Linux seatpost 2.6.29-rc7 #3 SMP Tue Mar 10 10:15:07 EDT 2009 x86_64 x86_64 x86_64 GNU/Linux

Gnu C 4.3
Gnu make 3.81
binutils 2.19
util-linux 2.14.1
mount support
module-init-tools 3.4
e2fsprogs 1.41.1
reiserfsprogs 3.6.19
xfsprogs 2.10.1
quota-tools 3.16.
PPP 2.4.5
Linux C Library 2.9
Dynamic linker (ldd) 2.9
Procps 3.2.7
Net-tools 1.60
Kbd 1.14.1
oprofile 0.9.4
Sh-utils 6.12
udev 128
wireless-tools 30
Modules Loaded fuse ext2 loop dm_mod sd_mod crc_t10dif bnx2 qla2xxx sg scsi_transport_fc rtc_cmos ipmi_si shpchp sr_mod rtc_core ipmi_msghandler pcspkr rtc_lib serio_raw hpwdt pci_hotplug cdrom button scsi_tgt container hpilo usbhid hid ehci_hcd uhci_hcd ohci_hcd usbcore edd ext3 mbcache jbd fan ide_pci_generic amd74xx ide_core pata_amd thermal processor thermal_sys hwmon cciss ata_generic libata scsi_mod


Attachments:
seatpost.log (19.36 kB)
ver_linux.txt (1.20 kB)
doit.py (1.87 kB)
Download all attachments

2009-03-10 17:14:31

by Alan D. Brunelle

[permalink] [raw]
Subject: Re: PROBLEM: kernel BUG at mm/slab.c:3002!

Alan D. Brunelle wrote:
> Running blktrace & I/O loads cause a kernel BUG at mm/slab.c:3002!.
>
> I'm running some moderate I/O loads (using 12 devices behind a Smart
> Array on a 16-way x86_64 box, I'm doing asynchronous direct sequential
> reads to each disk in parallel), and whilst attempting to get blktrace
> data I routinely run into this.
>
> I first started seeing this in 2.6.29-rc6, so I bumped to 2.6.29-rc7 and
> made a couple of successful runs, then ran into it again. (I've
> attached the script I was using, but I'm not sure it's very helpful...)
>
> The environment the system under test is in is rather difficult to
> bisect in, but if need be, I can certainly go through the (painful)
> motions to do so...
>
> I only ran this a couple of times on 2.6.27.7-4 (SLESS 11 b6 kernel),
> and both times it worked there - not sure how far back the problem occurs...
>
> I'm open to any SLAB debug tracing options that may help with this...
>
> Alan D.Brunelle
> Hewlett-Packard
>

Hm, it isn't SLAB-related: reconfigured w/ SLUB and got:

BUG: unable to handle kernel NULL pointer dereference at 0000000000000030g
IP: [<ffffffff802d0fda>] deactivate_super+0x11/0x8cg
PGD 1867047067 PUD 1853074067 PMD 0 g
Oops: 0000 [#1] SMP g
last sysfs file:
/sys/devices/pci0000:40/0000:40:10.0/0000:41:02.0/local_cpusg
CPU 15 g
Modules linked in: xfs exportfs fuse ext2 loop dm_mod sd_mod crc_t10dif
qla2xxx sg bnx2 scsi_transport_fc rtc_cmos sr_mod ipmi_si rtc_core
pcspkr ipmi_msghandler hpwdt hpilo container shpchp serio_raw scsi_tgt
rtc_lib button cdrom pci_hotplug usbhid hid uhci_hcd ohci_hcd ehci_hcd
usbcore edd ext3 mbcache jbd fan ide_pci_generic amd74xx ide_core
pata_amd thermal processor thermal_sys hwmon cciss ata_generic libata
scsi_modg
Pid: 12527, comm: blktrace Not tainted 2.6.29-rc7 #4 ProLiant DL585 G5 g
RIP: 0010:[<ffffffff802d0fda>] [<ffffffff802d0fda>]
deactivate_super+0x11/0x8cg
RSP: 0018:ffff88087a4e1b38 EFLAGS: 00010246g
RAX: ffff881829debf00 RBX: 0000000000000000 RCX: 00000000fffffffeg
RDX: 0000000000000d74 RSI: ffffffff80ab4b00 RDI: 0000000000000000g
RBP: ffff88087a4e1b48 R08: 0000000000000000 R09: 0000000000000000g
R10: ffff88107cc3d760 R11: ffff88187b84deb8 R12: ffff881829debf00g
R13: 0000000000000200 R14: ffffffff809a7d00 R15: ffff881829debfd8g
FS: 00007fab4778f6f0(0000) GS:ffff88207c202380(0000)
knlGS:0000000000000000g
CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003bg
CR2: 0000000000000030 CR3: 0000001801474000 CR4: 00000000000006e0g
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000g
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400g
Process blktrace (pid: 12527, threadinfo ffff88087a4e0000, task
ffff880821e70000)g
Stack:g
ffff88189c255d00 ffff881829debf00 ffff88087a4e1b88 ffffffff802e4f22g
0000000000000000 ffffffff80ab82b8 ffffffff80ab82b0 ffff881829debf00g
ffff8820798f6148 0000000000000016 ffff88087a4e1bb8 ffffffff802e8faeg
Call Trace:g
[<ffffffff802e4f22>] mntput_no_expire+0x144/0x18fg
[<ffffffff802e8fae>] simple_release_fs+0x68/0x70g
[<ffffffff8032cd10>] debugfs_remove+0x5b/0x60g
[<ffffffff80289c02>] ? relay_remove_buf+0x0/0x2cg
[<ffffffff8036c255>] blk_remove_buf_file_callback+0x1a/0x20g
[<ffffffff80289c21>] relay_remove_buf+0x1f/0x2cg
[<ffffffff8037155d>] kref_put+0x4b/0x57g
[<ffffffff80289c85>] relay_close_buf+0x35/0x3ag
[<ffffffff8028a08c>] relay_close+0x5e/0xecg
[<ffffffff8036ca9f>] blk_trace_remove+0x50/0x1e3g
[<ffffffff8036cd0f>] blk_trace_ioctl+0xb3/0xcfg
[<ffffffffa03aa4c5>] ? xfs_write+0x6c8/0x6e3 [xfs]g
[<ffffffff80363d78>] blkdev_ioctl+0x803/0x853g
[<ffffffff804b1100>] ? _spin_lock+0x17/0x1ag
[<ffffffff803702ac>] ? kobject_put+0x47/0x4bg
[<ffffffff803f6e38>] ? put_device+0x15/0x17g
[<ffffffffa000017a>] ? scsi_device_put+0x3d/0x42 [scsi_mod]g
[<ffffffffa0312bcb>] ? scsi_disk_put+0x3a/0x3f [sd_mod]g
[<ffffffff802f30a3>] block_ioctl+0x38/0x3cg
[<ffffffff802db638>] vfs_ioctl+0x2a/0x78g
[<ffffffff802dbacc>] do_vfs_ioctl+0x446/0x482g
[<ffffffff802cfc80>] ? __fput+0x18c/0x199g
[<ffffffff802dbb5d>] sys_ioctl+0x55/0x77g
[<ffffffff8020c42a>] system_call_fastpath+0x16/0x1bg
Code: 48 8b 7f 68 48 85 ff 74 05 e8 45 cb 00 00 48 89 df e8 8d ff ff ff
5b 5b c9 c3 55 48 c7 c6 00 4b ab 80 48 89 e5 41 54 53 48 89 fb <4c> 8b
67 30 48 8d bf a8 00 00 00 e8 0a de 09 00 85 c0 74 62 81 g
RIP [<ffffffff802d0fda>] deactivate_super+0x11/0x8cg
RSP <ffff88087a4e1b38>g
CR2: 0000000000000030g

2009-03-10 17:20:52

by Matt Mackall

[permalink] [raw]
Subject: Re: PROBLEM: kernel BUG at mm/slab.c:3002!

On Tue, 2009-03-10 at 11:16 -0400, Alan D. Brunelle wrote:
> Running blktrace & I/O loads cause a kernel BUG at mm/slab.c:3002!.

Pid: 11346, comm: blktrace Tainted: G B 2.6.29-rc7 #3 ProLiant
DL585 G5

That 'B' there indicates you've hit 'bad page' before this. That bug
seems to be strongly correlated with some form of hardware trouble.
Unfortunately, that makes everything after that point a little suspect.

Both this slab BUG and the bad page issue are "shouldn't happen"
situations that are generally caused by memory changing out from under
the subsystem, either by some other code scribbling on the relevant
memory or DRAM trouble or the like. If you want to pursue this further,
please gather up a collection of any bad page reports you can find on
your system and change the BUG code at slab.c:3002 to read something
like:

if (slabp->inuse < 0 || slabp->inuse >= cachep->num) {
printk("SLAB: slabp %p inuse %d max %d\n",
slabp, slabp->inuse, cachep->num);
BUG();
}

We might find that the slab and the bad page are the same page or
nearby. We might find that inuse has a single bit flipped (hardware
error). Or we might find that it has a revealing value scribbled over it
that points to the culprit. From your trace, it appears to contain 0x70,
which is a rather large number of objects to have on a slab but as we
don't know what slab it is, it's hard to say what happened.

--
http://selenic.com : development and support for Mercurial and Linux

2009-03-10 17:29:42

by Alan D. Brunelle

[permalink] [raw]
Subject: Re: PROBLEM: kernel BUG at mm/slab.c:3002!

Matt Mackall wrote:
> On Tue, 2009-03-10 at 11:16 -0400, Alan D. Brunelle wrote:
>> Running blktrace & I/O loads cause a kernel BUG at mm/slab.c:3002!.
>
> Pid: 11346, comm: blktrace Tainted: G B 2.6.29-rc7 #3 ProLiant
> DL585 G5
>
> That 'B' there indicates you've hit 'bad page' before this. That bug
> seems to be strongly correlated with some form of hardware trouble.
> Unfortunately, that makes everything after that point a little suspect.


/If/ it were a hardware issue, that might explain the subsequent issue
when I switched to SLUB instead...

How does one look for "bad page reports"?

I /will/ go back and change mm/slab.c as suggested - that will help some
I'm sure (and switch back to SLAB, of course).

>
> Both this slab BUG and the bad page issue are "shouldn't happen"
> situations that are generally caused by memory changing out from under
> the subsystem, either by some other code scribbling on the relevant
> memory or DRAM trouble or the like. If you want to pursue this further,
> please gather up a collection of any bad page reports you can find on
> your system and change the BUG code at slab.c:3002 to read something
> like:
>
> if (slabp->inuse < 0 || slabp->inuse >= cachep->num) {
> printk("SLAB: slabp %p inuse %d max %d\n",
> slabp, slabp->inuse, cachep->num);
> BUG();
> }
>
> We might find that the slab and the bad page are the same page or
> nearby. We might find that inuse has a single bit flipped (hardware
> error). Or we might find that it has a revealing value scribbled over it
> that points to the culprit. From your trace, it appears to contain 0x70,
> which is a rather large number of objects to have on a slab but as we
> don't know what slab it is, it's hard to say what happened.
>

2009-03-10 17:42:19

by Christoph Lameter

[permalink] [raw]
Subject: Re: PROBLEM: kernel BUG at mm/slab.c:3002!

Oh nice memory corruption. May have something to do with the vmap work by
Nick.

2009-03-10 17:45:18

by Matt Mackall

[permalink] [raw]
Subject: Re: PROBLEM: kernel BUG at mm/slab.c:3002!

On Tue, 2009-03-10 at 13:29 -0400, Alan D. Brunelle wrote:
> Matt Mackall wrote:
> > On Tue, 2009-03-10 at 11:16 -0400, Alan D. Brunelle wrote:
> >> Running blktrace & I/O loads cause a kernel BUG at mm/slab.c:3002!.
> >
> > Pid: 11346, comm: blktrace Tainted: G B 2.6.29-rc7 #3 ProLiant
> > DL585 G5
> >
> > That 'B' there indicates you've hit 'bad page' before this. That bug
> > seems to be strongly correlated with some form of hardware trouble.
> > Unfortunately, that makes everything after that point a little suspect.
>
>
> /If/ it were a hardware issue, that might explain the subsequent issue
> when I switched to SLUB instead...

Well it was almost certainly not a bug in SLAB itself (and your SLUB
test is obviously quite conclusive there). We'd have lots of reports.
It's probably too early to conclude it's hardware though.

> How does one look for "bad page reports"?

It'll look something like this (pasted from Google):

>> kernel: Bad page state at free_hot_cold_page (in process 'beam',
>> page c1a95320)
>> kernel: flags:0x40020118 mapping:f401adc0 mapped:0 count:0
>> private:0x00000000

--
http://selenic.com : development and support for Mercurial and Linux

2009-03-10 18:54:12

by Alan D. Brunelle

[permalink] [raw]
Subject: Re: PROBLEM: kernel BUG at mm/slab.c:3002!

Matt Mackall wrote:
> On Tue, 2009-03-10 at 13:29 -0400, Alan D. Brunelle wrote:
>> Matt Mackall wrote:
>>> On Tue, 2009-03-10 at 11:16 -0400, Alan D. Brunelle wrote:
>>>> Running blktrace & I/O loads cause a kernel BUG at mm/slab.c:3002!.
>>> Pid: 11346, comm: blktrace Tainted: G B 2.6.29-rc7 #3 ProLiant
>>> DL585 G5
>>>
>>> That 'B' there indicates you've hit 'bad page' before this. That bug
>>> seems to be strongly correlated with some form of hardware trouble.
>>> Unfortunately, that makes everything after that point a little suspect.
>>
>> /If/ it were a hardware issue, that might explain the subsequent issue
>> when I switched to SLUB instead...
>
> Well it was almost certainly not a bug in SLAB itself (and your SLUB
> test is obviously quite conclusive there). We'd have lots of reports.
> It's probably too early to conclude it's hardware though.
>
>> How does one look for "bad page reports"?
>
> It'll look something like this (pasted from Google):
>
>>> kernel: Bad page state at free_hot_cold_page (in process 'beam',
>>> page c1a95320)
>>> kernel: flags:0x40020118 mapping:f401adc0 mapped:0 count:0
>>> private:0x00000000
>

Interestingly enough, I'm not seeing the kernel detect such things - but
in going into the hardware server logs, a co-worker found "unrecoverable
system errors" being detected at about the same times we're seeing the
panics.

We're investigating hardware issues now, if those don't pan out, I'll
continue looking at possible software memory corruptors...

Alan

2009-03-10 22:07:09

by Hugh Dickins

[permalink] [raw]
Subject: Re: PROBLEM: kernel BUG at mm/slab.c:3002!

On Tue, 10 Mar 2009, Alan D. Brunelle wrote:
> Matt Mackall wrote:
> > On Tue, 2009-03-10 at 13:29 -0400, Alan D. Brunelle wrote:
> >> Matt Mackall wrote:
> >>> On Tue, 2009-03-10 at 11:16 -0400, Alan D. Brunelle wrote:
> >>>> Running blktrace & I/O loads cause a kernel BUG at mm/slab.c:3002!.
> >>> Pid: 11346, comm: blktrace Tainted: G B 2.6.29-rc7 #3 ProLiant
> >>> DL585 G5
> >>>
> >>> That 'B' there indicates you've hit 'bad page' before this. That bug
> >>> seems to be strongly correlated with some form of hardware trouble.
> >>> Unfortunately, that makes everything after that point a little suspect.
> >>
> >> /If/ it were a hardware issue, that might explain the subsequent issue
> >> when I switched to SLUB instead...
> >
> > Well it was almost certainly not a bug in SLAB itself (and your SLUB
> > test is obviously quite conclusive there). We'd have lots of reports.
> > It's probably too early to conclude it's hardware though.
> >
> >> How does one look for "bad page reports"?
> >
> > It'll look something like this (pasted from Google):
> >
> >>> kernel: Bad page state at free_hot_cold_page (in process 'beam',
> >>> page c1a95320)
> >>> kernel: flags:0x40020118 mapping:f401adc0 mapped:0 count:0
> >>> private:0x00000000
> >
>
> Interestingly enough, I'm not seeing the kernel detect such things - but
> in going into the hardware server logs, a co-worker found "unrecoverable
> system errors" being detected at about the same times we're seeing the
> panics.

In 2.6.29-rc, the "B" taint should be associated with mm/page_alloc.c's
bad_page() KERN_ALERT "BUG: Bad page state in process %s pfn:%05lx\n",
but it could also now come from mm/memory.c's print_bad_pte()
KERN_ALERT "BUG: Bad page map in process %s pte:%08llx pmd:%08llx\n",
which replaces the old mm/rmap.c Eeeks, and some other cases too.

Hugh

2009-03-11 02:21:20

by Nick Piggin

[permalink] [raw]
Subject: Re: PROBLEM: kernel BUG at mm/slab.c:3002!

On Tue, Mar 10, 2009 at 01:40:02PM -0400, Christoph Lameter wrote:
> Oh nice memory corruption. May have something to do with the vmap work by
> Nick.

Hmm, it might but I can't really tell. It happens in the vmap code
when kmallocing something, but it isn't obviously causing it AFAIKS.

Could you print out the values of the fields involved in the BUG()?
That might give some clues...

2009-03-11 14:28:59

by Alan D. Brunelle

[permalink] [raw]
Subject: Re: PROBLEM: kernel BUG at mm/slab.c:3002!

Nick Piggin wrote:
> On Tue, Mar 10, 2009 at 01:40:02PM -0400, Christoph Lameter wrote:
>> Oh nice memory corruption. May have something to do with the vmap work by
>> Nick.
>
> Hmm, it might but I can't really tell. It happens in the vmap code
> when kmallocing something, but it isn't obviously causing it AFAIKS.
>
> Could you print out the values of the fields involved in the BUG()?
> That might give some clues...
> --
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to [email protected]
> More majordomo info at http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at http://www.tux.org/lkml/
>

FYI: The current assumption is that there is a hardware issue here
resulting in corrupted memory. We are seeing some odd things in the
hardware logs (but Linux apparently is /not/ detecting anything - no bad
pages reported, for example). We tried a firmware update for the
platform, but that did not fix things.

My next steps are to see what kind of platform diagnostics are
available, and I'm also trying to acquire another system to try the
tests on (to see if they reproduce or not).

Alan