Bug 173843

Created attachment 121314 [details]
KDB info for kernel panic

Linux version 2.6.9-22.EL_1-2-2-2_dgs_smp (root.local) (gcc
version 3.4.3 20050227 (Red Hat 3.4.3-22)) #2 SMP Mon Nov 14 11:04:51 MST 2005

This is not a Red Hat-compiled kernel; as such, please be aware that we cannot
offer any support guarantees on it.

*** Bug 177122 has been marked as a duplicate of this bug. ***

This link is to the beginning of the mailing list thread referred to in
BZ175216, comment #163:

http://lkml.org/lkml/2006/1/20/303

Reading through the thread again now, and looking at what we'll need to do apply
the final patch to RHEL4.

*** Bug 167385 has been marked as a duplicate of this bug. ***

This issue is on Red Hat Engineering's list of planned work items 
for the upcoming Red Hat Enterprise Linux 4.4 release.  Engineering 
resources have been assigned and barring unforeseen circumstances, Red 
Hat intends to include this item in the 4.4 release.

*** Bug 177357 has been marked as a duplicate of this bug. ***

Created attachment 128228 [details]
Proposed patch

I have a couple of questions on this patch.  I have a series of machines where I
am very frequently getting this crash, so I am anxious to try the fix.

First, is it against 2.6.9-34.EL?  Do you think that this completely solves this
issue, and do you think it is reasonably safe/correct, etc?

Second, how does this compare to the fix for this that was suggested on the LKML
by Jan Blunck of SuSE in
http://marc.theaimsgroup.com/?l=linux-kernel&m=114192371504939&w=2 ?  It sounds
like they are pushing that one upstream, or are you going to also send your
patch upstream?

You are certainly welcome to try the attached patch.

My testing is against 2.6.9-34.24.EL.  This is the current build of RHEL-4
under development.  I don't know whether it would work against 2.6.9-34.EL
or not.  I suspect that it would, but until it is tried, I don't know.

My testing seems to indicate that things look good, but I'd like to look
at the changes some more.

Keep reading in the email thread pointed to in Comment #23.  They aren't
pushing Jan's original patch up, but another one, mentioned much further
down in the thread.  Additionally, I included another fix for a bug which
was introduced by the patch.  These changes are all in "mm", including this
last bug fix that I mentioned.

I built a kernel starting with
http://people.redhat.com/linville/kernels/rhel4/rpms/kernel-2.6.9-34.23.EL.jwltest.132.src.rpm
and adding in your patch.  I needed his kernel as I also needed updated sky2 
drivers.  Also, it was the only source I could find that was close to your 34.24
version.  I'm running with this now.  I'll let you know how things look after 
all of the machines have been run under heavy load for a while.

At this point it looks like there has been enough load that I would have had
something in the range of 10-20 nodes that would have crashed by now on this
bug. Everything has been running correctly.  Also, no new bugs have shown up due
to the  patches in this set.  I still need to resolve a few more issues with
John Linville on the network issues, but it looks to me like the patch in this
bug is a winner.
Thanks.

committed in stream U4 build 35.1. A test kernel with this patch is available
from http://people.redhat.com/~jbaron/rhel4/

I just had two nodes fail on something that looks like it is the same issue. 
This is much less frequent than it was before, but at least at a quick glance
looks about the same.  /etc/messages shows:
May  4 22:37:19 compute-139-9 kernel: Unable to handle kernel paging request at
virtual address bb965a56
May  4 22:37:19 compute-139-9 kernel:  printing eip:
May  4 22:37:19 compute-139-9 kernel: bb965a56
May  4 22:37:19 compute-139-9 kernel: *pde = 00000000
May  4 22:37:19 compute-139-9 kernel: Oops: 0000 [#1]
May  4 22:37:19 compute-139-9 kernel: SMP
May  4 22:37:19 compute-139-9 kernel: Modules linked in: nfs nfsd exportfs lockd
nfs_acl md5 ipv6 autofs4 i2c_dev i2c_core sunrpc ipt_REJECT ipt_state
ip_conntrack iptable_filter ip_tables dm_mod button battery ac uhci_hcd ehci_hcd
shpchp sky2 ext3 jbd ata_piix libata sd_mod scsi_mod
May  4 22:37:19 compute-139-9 kernel: CPU:    3
May  4 22:37:19 compute-139-9 kernel: EIP:    0060:[<bb965a56>]    Not tainted VLI
May  4 22:37:19 compute-139-9 kernel: EFLAGS: 00010286   (2.6.9-34.23.EL.lumi.1smp)
May  4 22:37:19 compute-139-9 kernel: EIP is at 0xbb965a56
May  4 22:37:19 compute-139-9 kernel: eax: f612092c   ebx: f612092c   ecx:
f8ab8c1c   edx: bb965a56
May  4 22:37:19 compute-139-9 kernel: esi: f6e07d5c   edi: f6e07d64   ebp:
f612092c   esp: f7da6edc
May  4 22:37:19 compute-139-9 kernel: ds: 007b   es: 007b   ss: 0068
May  4 22:37:19 compute-139-9 kernel: Process kswapd0 (pid: 54,
threadinfo=f7da6000 task=f7dd38b0)
May  4 22:37:19 compute-139-9 kernel: Stack: c0171769 f7e68240 c016f31e 00000000
00000021 00000000 00000080 00000000
May  4 22:37:19 compute-139-9 kernel:        f7ffe9c0 c016f6e4 c0149568 0008fc00
00000000 00000001 00000000 0007a863
May  4 22:37:19 compute-139-9 kernel:        000000d0 00000020 c032a380 00000001
c0328f80 00000002 c014a803 c02d2561
May  4 22:37:19 compute-139-9 kernel: Call Trace:
May  4 22:37:19 compute-139-9 kernel:  [<c0171769>] iput+0x30/0x61
May  4 22:37:19 compute-139-9 kernel:  [<c016f31e>] prune_dcache+0x29d/0x31b
May  4 22:37:19 compute-139-9 kernel:  [<c016f6e4>] shrink_dcache_memory+0x16/0x2d
May  4 22:37:19 compute-139-9 kernel:  [<c0149568>] shrink_slab+0xf8/0x161
May  4 22:37:19 compute-139-9 kernel:  [<c014a803>] balance_pgdat+0x1e1/0x30e
May  4 22:37:19 compute-139-9 kernel:  [<c02d2561>] schedule+0x86d/0x8db
May  4 22:37:19 compute-139-9 kernel:  [<c014a9fa>] kswapd+0xca/0xcc
May  4 22:37:19 compute-139-9 kernel:  [<c01204a5>]
autoremove_wake_function+0x0/0x2d
May  4 22:37:19 compute-139-9 kernel:  [<c02d4526>] ret_from_fork+0x6/0x14
May  4 22:37:19 compute-139-9 kernel:  [<c01204a5>]
autoremove_wake_function+0x0/0x2d
May  4 22:37:19 compute-139-9 kernel:  [<c014a930>] kswapd+0x0/0xcc
May  4 22:37:19 compute-139-9 kernel:  [<c01041f5>]
kernel_thread_helper+0x5/0xbMay  4 22:37:19 compute-139-9 kernel: Code:  Bad EIP
value.
May  4 22:37:19 compute-139-9 kernel:  <0>Fatal exception: panic in 5 seconds

hmmm, did you get the 'busy inodes after unmount message' ?

Sorry, I don't know as that had scrolled off of the console when I attached a
display to it, and it never shows up in the logs that I have found.

It is positively known that this system, which crashed, was running the patched
kernel?  (Just checking everything...)

Is it possible to get a coredump from a failed system to see what other
threads that there might have been around?

Yes, it was running the patched kernel (nootice in the line above 
May  4 22:37:19 compute-139-9 kernel: EFLAGS: 00010286  
(2.6.9-34.23.EL.lumi.1smp) - thus the 34.23 from linville, plus your patch.

I believe I still have a couple of nodes in the crashed state right now.  Can
you give me a good pointer about what I need to do to get a dump?

Can you try the latest kernel from Jason's people's page?  
Is there any patches in 34.23 from Linville's kernel that is not 
in the 35.1? 

I don't see this "2.6.9-34.23.EL.lumi.1smp" kernel on beehive,
so I'm guessing this kernel was customer-built?  We would need the
associated kernel debuginfo package in order to debug any vmcore.

Is there a problem such that they cannot use Jason's latest kernel
which we know has the patch properly applied?

Anyway, they can either use diskdump or netdump to get a vmcore.  

For diskdump, they would need to install the "diskdumputils" user
package, and read the /usr/share/doc/diskdump-<release>/README file
to determine whether diskdump is advisable, or possible.  If so,
the directions are there.

For netdump, they need to install the "netdump" package on the
panicking client, and the "netdump-server" package on a remote
server that contains enough space to hold the client's full
memory-sized vmcore file on the filesystem containing the 
/var/crash directory.  

After the netdump-server package has been installed on the
remote server machine, the netdump-server daemon can be started
up there, typically without any additional configuration, by:

1. doing a "service netdump-server start"

Then the netdump client needs to be configured to talk with the
remote netdump-server daemon.  After installing the netdump
package on the client, the instructions can be found in
/usr/share/doc/netdump-<version>/README.client, but at a
minimum, it's simply a matter of:

1. edit /etc/sysconfig/netdump to have NETDUMPADDR point to the
   IP address of the server.
2. do a "service netdump propagate" one time, to register the
   client with the netdump-server.
3. do a "service netdump start" on the client.

Then, wait for a crash...

Created attachment 128758 [details]
reproducer script

*** Bug 136809 has been marked as a duplicate of this bug. ***

Sorry I haven't had a chance to get back to this yet - other work is in the way!
I need two things patched in order to get a (semi)stable kernel.  One is this
inode issue, but the other is the sky2 driver.  The version in the official kernel 
is quite early (and bad) and also causes numerous problems with the nodes
dropping off of the network.  So I had started from Linville's patched kernel
and dropped this on in on top of that.  The good news is it had improved both
situations a lot.  The bad news is that neither of the issues was completely
resolved.  I know that the last I looked John had updated his set to 1.2 of
sky2, but from looking upstream it looks like 1.3 might be needed to really
(hopefully) fix the remaining issues, so I may need to wait for him to get that
one till I test again.

The problem is that I have only seen this on a production set of 200 or so
machines, and it has only been a "random" failure under certain workloads, so it
is pretty hard to test anything.

I see there is a reproducer script - does this mean that someone has set
something up that seems to trigger this "reliably"?  If so, I could certainly
try it.  Also, if you can point me to where I can get a test kernel I might be
able to try, but as I said, I need to slip it into a production system.

Bill, thanks for the info...

The reproducer attached to this case was provided by another customer for the
RHEL3 version of this problem. They also provided a tarball of data that got
extracted but that can't be released. That said, presumably any tarball of data
(maybe a kernel source tree?) should have a similar effect. You'll want to run
several of these at once (I did 3 at a time, IIRC). When I was working on
reproducing this on RHEL3, it was never very reliable, but usually would crash
within 24 hours.

The big thing that seemed to trigger the problem was the sync commands in the
scripts. Not sure if that's a factor on RHEL4. An interim workaround for this
customer was to remove the extraneous syncs from the scripts that were
triggering the problem.

One other question -- are the kernels you're working with using any 3rd party
modules? In particular, anything filesystem-related such as clearcase?

I'll try to get a chance to stress things using that script to see if I can make
things more deterministic. No third-party modules are loaded.  Also just ext3
files straight on SATA direct attached disk (and possibly via NFS) - no md, no lvm.

Stratus may have just hit this BUG running a pump test.  There were running
2.6.9-34.24 plus a required ioapic patch that has since been included in U4. 
Here's what they report:

On Wed, 10 May 2006, Santos, Paul wrote:

> Lstlinux11 (4300/T40, 4.0.83, SINAP 16.A16, 134.111.82.174)
> 
> FWIW, Here's lstlinux11's second crash running pump (mtp2drv)
> tests...Was running max/heavy pump tests this time.
> 
> ...
> ohrsd_close:Close Failed min=0x5000e RSip=0x000001009fe62500
> LastCommandStatus = 0x3e, RSipState=3, ux_dev=0xbc
> ohrsd_close:Close Failed min=0x5000f RSip=0x000001015ff12500
> LastCommandStatus = 0x3e, RSipState=3, ux_dev=0xfc
> ohrsd_close:Close Failed min=0x5000e RSip=0x000001015ff13500
> LastCommandStatus = 0x3e, RSipState=3, ux_dev=0xec   
> ohrsd_close:Close Failed min=0x5000c RSip=0x000001015eaa3900
> LastCommandStatus = 0x3e, RSipState=3, ux_dev=0x9c
> ohrsd_close:Close Failed min=0x5000d RSip=0x000001015ff20900
> LastCommandStatus = 0x3e, RSipState=3, ux_dev=0x3c
> VFS: Busy inodes after unmount. Self-destruct in 5 seconds.  Have a nice
> day...
> Unable to handle kernel paging request at 00000000f97cff98 RIP:
> <ffffffff80309d17>{_spin_lock_irqsave+12}
> PML4 12ed4d067 PGD 0
> Oops: 0000 [1] SMP
> CPU 0
> Modules linked in: streams(U) sg(U) ppp_generic slhc md5 ipv6 parport_pc
> lp parport autofs4 i2c_dev i2c_core
> nfs lockd nfs_acl sunrpc ds yenta_socket pcmcia_core atyfb(U)
> ipmi_devintf ftmod(U) fosil(U) ipmi_msghandler
> dm_mirror dm_multipath dm_mod button battery ac joydev ohci_hcd(U)
> ehci_hcd e1000(U) bonding(U) ext3 jbd raid1(U) sata_vsc(U) libata(U)
> sd_mod(U) scsi_mod(U)
> Pid: 9401, comm: sh Tainted: PF     2.6.9-34.24.apricot.ELsmp
> RIP: 0010:[<ffffffff80309d17>] <ffffffff80309d17>{_spin_lock_irqsave+12}
> RSP: 0018:0000010144009c58  EFLAGS: 00010002
> RAX: 000001000aaca7e0 RBX: 00000000f97cff94 RCX: 0000000000000000
> RDX: 0000010146ef3740 RSI: 0000010146ef36c0 RDI: 00000000f97cff94
> RBP: 0000010144009c98 R08: 000001015d989928 R09: 0000000000000000
> R10: 0000000000000048 R11: 000001012b2992c0 R12: 00000000f97cff94
> R13: 0000010146ef36c0 R14: 000001015f0ff030 R15: 000001015e393a40
> FS:  0000000000000000(0000) GS:ffffffff804e2200(0000)
> knlGS:0000000000000000
> CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
> CR2: 00000000f97cff98 CR3: 0000000000101000 CR4: 00000000000006e0
> Process sh (pid: 9401, threadinfo 0000010144008000, task
> 000001015f0ff030)
> Stack: 0000010146ef36c0 0000000000000202 00000000f97cff8c
> ffffffff80133d4a
>        000001000aaca7e0 000001015f0ff030 0000000000000000
> 0000010146ef36c0
>        00000000f97cff8c ffffffff801358c1
> Call Trace:<ffffffff80133d4a>{complete+25}
> <ffffffff801358c1>{mm_release+64}
>        <ffffffff80182edf>{flush_old_exec+2011}
> <ffffffff80192d5c>{dnotify_parent+34}
>        <ffffffff801791a8>{vfs_read+248}
> <ffffffff8012f789>{load_elf32_binary+0}
>        <ffffffff8012fd82>{load_elf32_binary+1529}
> <ffffffff80179084>{do_sync_read+173}
>        <ffffffff8012f789>{load_elf32_binary+0}
> <ffffffff80183737>{search_binary_handler+194}
>        <ffffffff80183a6c>{do_execve+398}
> <ffffffff8011022e>{system_call+126}
>        <ffffffff8010ee27>{sys_execve+52}
> <ffffffff80110652>{stub_execve+106}
> 
> 
> Code: 81 7f 04 ad 4e ad de 74 1f 48 8b 74 24 18 48 c7 c7 03 38 32
> RIP <ffffffff80309d17>{_spin_lock_irqsave+12} RSP <0000010144009c58>
> CR2: 00000000f97cff98
>  <0>Kernel panic - not syncing: Oops

I haven't had a chance to try anything more yet, but I did just notice that on
at least one of the machines running the patched 34.23.EL kernel I have had two
times that I got messages:
messages.1:May  4 13:43:34 compute-8-1 kernel: VFS: Busy inodes after unmount.
Self-destruct in 5 seconds.  Have a nice day...
messages:May  9 12:05:42 compute-8-1 kernel: VFS: Busy inodes after unmount.
Self-destruct in 5 seconds.  Have a nice day...
[root@compute-8-1 log]# date
Thu May 11 10:04:01 PDT 2006
[root@compute-8-1 log]# uptime
 10:04:03 up 12 days, 22:51,  1 user,  load average: 0.05, 0.14, 0.29

So I've gotten that message twice, but the kernel didn't panic.

Anyway, hopefully in the next few days I can try that stress script on a few of
my nodes to see if I can pin down the issues with my current setup.

Re: comment 46 -- sky2 version 1.3

Bill, I now have sky2 1.3 available in my test kernels.  Feel free to use 
these kernels for any further testing you do...thanks!

I figured I should add some more information to this bug.  I had tried the
stress script that was posted, but it was not able to trigger things.  On the
other hand our standard workload was able to.  

I'm afraid I'm not going to be able to help debug this at this point.  We ended
up going about this in a different way. We ended up replacing the kernel with
the latest one (at that time) from the FC4 updates - 2.6.17-1.2139_FC4smp. This
has the sky driver updates we needed, plus it also had a change that came in at
2.6.10 that we will be needing in order to map large memory areas for an add-in
PCIe card that we are using (and wasn't backported into the RHEL kernels).  So
because of those two things, we decided to try the FC4 kernel.  It has been
running flawlessly now under heavy and varied load.  I don't know if this
specific bug had been addressed directly in there in some different way, or if
the numerous other changes caused things to avoid the problematic code path. All
I can say is that with the time and workload the RHEL kernel would have crashed
on somewhere between between 10 and 40 of the nodes by now, and we haven't had a
single hiccup.  Since I also needed the newest sky driver and the 2.6.10 page
map change, I'm just going to end up running with this FC4 kernel.

I'm sorry I can't help any more at this point to get things solved in the RHEL
environment.

An advisory has been issued which should help the problem
described in this bug report. This report is therefore being
closed with a resolution of ERRATA. For more information
on the solution and/or where to find the updated files,
please follow the link below. You may reopen this bug report
if the solution does not work for you.

http://rhn.redhat.com/errata/RHSA-2006-0575.html

*** Bug 177122 has been marked as a duplicate of this bug. ***