Bug 152099 - kernel oops at boot
Summary: kernel oops at boot
Status: RESOLVED FIXED
Alias: None
Product: SUSE Linux 10.1
Classification: openSUSE
Component: Kernel (show other bugs)
Version: Beta 4
Hardware: Other Other
: P5 - None : Normal (vote)
Target Milestone: ---
Assignee: Neil Brown
QA Contact: E-mail List
URL:
Whiteboard: fixreleased:kernel:sles10
Keywords:
Depends on:
Blocks:
 
Reported: 2006-02-19 16:31 UTC by Jon Nelson
Modified: 2006-10-09 09:17 UTC (History)
0 users

See Also:
Found By: Other
Services Priority:
Business Priority:
Blocker: ---
Marketing QA Status: ---
IT Deployment: ---


Attachments
Patch to fix lockup (1.50 KB, patch)
2006-04-20 06:04 UTC, Neil Brown
Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Jon Nelson 2006-02-19 16:31:16 UTC
Taken straight from dmesg:

ACPI: PCI Interrupt 0000:02:01.0[A] -> Link [LNKB] -> GSI 10 (level, low) -> IRQ 10
3c59x: Donald Becker and others. www.scyld.com/network/vortex.html
0000:02:01.0: 3Com PCI 3c905C Tornado at d8864000. Vers LK1.1.19
BUG: soft lockup detected on CPU#0!

Pid: 1618, comm:                mdadm
EIP: 0060:[<c0137c60>] CPU: 0
EIP is at find_get_pages+0x4c/0x53
 EFLAGS: 00000246    Not tainted  (2.6.16-rc3-git3-2-default #1)
EAX: d7cb219c EBX: 00000001 ECX: 00000001 EDX: c12ca540
ESI: 0000000e EDI: 004acece EBP: d7cb219c DS: 007b ES: 007b
CR0: 8005003b CR2: 0805ab30 CR3: 16a5b000 CR4: 000006d0
 [<c013ba3a>] pagevec_lookup+0x17/0x1d
 [<c013bd7b>] invalidate_mapping_pages+0x99/0xac
 [<c01a36fc>] blkdev_ioctl+0x94/0x665
 [<c0136a44>] __generic_file_aio_read+0x148/0x18f
 [<c0135919>] file_read_actor+0x0/0xe0
 [<c0137acb>] generic_file_read+0x0/0xac
 [<c0137b63>] generic_file_read+0x98/0xac
 [<c0127ba7>] autoremove_wake_function+0x0/0x2d
 [<c01558fe>] block_ioctl+0x0/0x16
 [<c0155911>] block_ioctl+0x13/0x16
 [<c015e63a>] do_ioctl+0x16/0x49
 [<c015e86c>] vfs_ioctl+0x1ff/0x216
 [<c015e8cb>] sys_ioctl+0x48/0x61
 [<c0102a5b>] sysenter_past_esp+0x54/0x79
cs: IO port probe 0x100-0x3af: clean.
cs: IO port probe 0x3e0-0x4ff: excluding 0x4d0-0x4d7
cs: IO port probe 0x820-0x8ff: clean.
cs: IO port probe 0xc00-0xcf7: clean.
cs: IO port probe 0xa00-0xaff: clean.
device-mapper: 4.5.0-ioctl (2005-10-04) initialised: dm-devel@redhat.com
Comment 1 Olaf Kirch 2006-02-22 11:18:24 UTC
mdadm triggers a soft lockup in find_get_pages:

        read_lock_irq(&mapping->tree_lock);

It seems we're leaking a write lock somewhere.

Jon, can you reproduce this?
Comment 2 Jon Nelson 2006-02-22 13:45:31 UTC
I'll see what I can do - I've been working on a bunch of other items recently.
 I seem to recall seeing at least one other oops at boot time, although I don't think it was exactly the same.
Comment 3 Chris L Mason 2006-02-22 18:47:21 UTC
The other oops may have been the holder of the write lock.  We need whichever oops was first.
Comment 4 Jon Nelson 2006-02-22 20:16:41 UTC
(In reply to comment #3)
> The other oops may have been the holder of the write lock.  We need whichever
> oops was first.
> 

I don't want to be misunderstood - I believe I have seen multiple, different oopses, all at boot time. However, not /every/ boot seems to generate an oops.
Comment 5 Neil Brown 2006-02-23 03:53:15 UTC
This trace isn't making any sense at all to me.

mdadm calls and ioctl which goes through block_ioctl to generic_file_read.
What ioctl would do that?

There is no mention of 'md_ioctl' in the trace, so it doesn't look like an md-specific ioctl is being called.  The only other ioctls mdadm calls are BLKGETSIZE BLKGETSIZE64 and BLKFLSBUF. I don't see any of them calling generic_file_read...

I guess it is possible that if md is a module, maybe it's symbols aren't being printed for some reason.  There is an md ioctl that could possibly call generic_file_read but you would still expect read_cache_page to be in the trace.  And this would only happen when starting an array the had a write-intent bitmap stored in a separate file.

Are there any md arrays with the bitmap in a separate file?

Very weird .... have you considered memcheck??  Probably a long shot...
Comment 6 Jon Nelson 2006-02-23 05:15:24 UTC
This was a fresh 10.1 beta4 install, no raid devices at all. I do use LVM, though, if that matters.  I do not get the same oops every time I boot, nor do I even *get* an oops every time I boot. Both the frequency and the oops itself seem random.  As far as the machine goes, I've had it about 3 years and it's been rock solid running 9.1 through 10.0, and a bunch of stuff prior to that.

I will try to find some time to boot it a bunch of times and see if I can get more oopses for you.  When they happen, they invariably happen early in the boot process.
Comment 7 Olaf Kirch 2006-02-23 09:52:43 UTC
re comment #5 - the generic_file_read addresses on the stack are probably
leftovers from earlier calls.

In the light of comment #6, this may be bad RAM. Please try running memtest
for a few hours, just to be sure.

If your RAM is okay, please run hwinfo on your machine and attach the
output to this bug report.
Comment 8 Jon Nelson 2006-02-28 04:40:03 UTC
I haven't been able to make this happen with beta5, so I'm not sure what you want to do here.


I'm quite sure the memory is fine (it was a daily use machine that was rock solid up until a few weeks ago when I started with the betas).
Comment 9 Neil Brown 2006-02-28 05:06:13 UTC
Well, if you cannot reproduce it, maybe we can assume it is fixed.

On reviewing the trace, the only thing I can come up with is that maybe invalidate_mapping_pages is just taking a loooong time to invalidate all the pages that make have been cached for some block device.

The location of the lockup :  find_get_pages+0x4c/0x53 : looks to be more like the unlock than the lock, so I don't think it is a lock leak.

Chris:  You probably know more about the MM than me.  Would it make sense to put a cond_resched() in invalidate_mapping_pages just after the unlock_page ??
Comment 10 Chris L Mason 2006-03-01 00:05:45 UTC
invalidate_mapping_pages seems to expect no schedules at all.  We would have to audit the callers for spin locks.
Comment 11 Olaf Kirch 2006-03-01 09:14:41 UTC
It's quite possible this is a false positive of the softlock detection
code. Let's resolve this as INVALID.
Comment 12 Neil Brown 2006-03-02 03:32:46 UTC
Does 'softlock' have false positives?  10 seconds without a schedule is a long time in anybodies book...

I might still look into cond_resched in invalidate_mapping_pages, but I'm happy with this bug going INVALID for now.  It can always be reopened if it recurs.
Comment 13 Neil Brown 2006-04-20 06:00:11 UTC
I've had a very similar bug reported on linux-raid, so I'm re-opening this bug.
Comment 14 Neil Brown 2006-04-20 06:04:19 UTC
Created attachment 79158 [details]
Patch to fix lockup

I believe this patch fixes  the lockup.
Comment 15 Neil Brown 2006-04-20 06:05:08 UTC
Leaving this  bug as 'assigned' to remind me to get the patch into CVS
after seeking  feedback on linux-kernel.
Comment 16 Jon Nelson 2006-05-05 22:26:24 UTC
I haven't had this bug since beta5 or so.
I tested all betas and release candidates through rc3 *except* rc2.
Comment 17 Neil Brown 2006-08-08 02:12:41 UTC
I didn't get this into SLES10, but it will be in -SP1 and any maintenance
update.

The reason it hasn't hit since beta5 is probably just luck.
The bug only hits if a race is lost, and lots of variables could affect that.
Comment 18 Klaus Wagner 2006-08-22 15:03:39 UTC
Present and active in CVS SLES10_GA_BRANCH for this bug:
patches.fixes/truncate-soft-lockup

Adding whiteboard flag for maintenance tracking.
Comment 19 Harald Mueller-Ney 2006-08-23 08:15:31 UTC
Approved for maintenance (just for completeness)
Comment 20 Klaus Wagner 2006-10-09 09:17:06 UTC
truncate-soft-lockup: Patch published in kernelupdate 2.6.16.21-0.25, dated Sep 19, 2006 & released Oct 04, 2006. Setting Whiteboard Status -> fixreleased