oops in proc_sys_compare

oops in proc_sys_compare

[Hugh Dickins]

I got this oops below, after several hours of swap-heavy kernel builds
in tmpfs, on 2.6.27-rc1-mm1 a couple of weeks ago.  Tried to reproduce
it without success, then got a very similar trace (not saved) from
2.6.27-rc3 itself doing the same test yesterday: again oopsing in
proc_sys_compare on address -16, looks like it's trying for
PROC_I(dentry->d_inode)->sysctl but d_inode is NULL.

I looked to see what's been going on in fs/proc recently, and your
[PATCH] sanitize proc_sysctl 9043476f726802f4b00c96d0c4f418dde48d1304
does sound like it might be implicated.  I've only seen this on
PowerPC G5, similar tests on x86_32 and _64 haven't shown it:
maybe a memory barrier needed somewhere?

Hugh

Unable to handle kernel paging request for data at address 0xfffffffffffffff0
Faulting instruction address: 0xc000000000121ec4
Oops: Kernel access of bad area, sig: 11 [#1]
PREEMPT SMP NR_CPUS=4 PowerMac
Modules linked in:
NIP: c000000000121ec4 LR: c000000000121eb4 CTR: 0000000000000000
REGS: c000000002af33f0 TRAP: 0300   Not tainted  (2.6.27-rc1-mm1)
MSR: 9000000000009032 <EE,ME,IR,DR>  CR: 24222482  XER: 00000000
DAR: fffffffffffffff0, DSISR: 0000000040000000
TASK = c000000002d22500[26561] 'sh' THREAD: c000000002af0000 CPU: 3
GPR00: 0000000000000078 c000000002af3670 c0000000005cf520 0000000000000000 
GPR04: c0000000021ba01b 000000000000000b c000000015e63596 c0000000021ba011 
GPR08: 0001f59632fdb346 0000000000000000 000000000001ffff 0000000000000000 
GPR12: 0000000020222424 c0000000005ec800 0000000000000000 0000000000000000 
GPR16: 00000000200be41c 0000000000000000 c000000002af38d0 c000000002af38b0 
GPR20: c000000002af38c0 c000000002af3bf8 0000000000000101 0000000000000024 
GPR24: c0000000021ba011 0000000032fdb346 000000000000000b c000000002af38c0 
GPR28: c000000015e634f8 c000000015e634e0 c000000000562498 c000000015e63510 
NIP [c000000000121ec4] .proc_sys_compare+0x48/0x7c
LR [c000000000121eb4] .proc_sys_compare+0x38/0x7c
Call Trace:
[c000000002af3670] [c000000000522620] root_table_header+0x0/0x58 (unreliable)
[c000000002af36f0] [c0000000000dabdc] .__d_lookup+0xf4/0x1f0
[c000000002af37a0] [c0000000000d0978] .do_lookup+0x38/0x128
[c000000002af3840] [c0000000000d1438] .__link_path_walk+0x9d0/0xf30
[c000000002af3950] [c0000000000d19f0] .path_walk+0x58/0xc4
[c000000002af3a00] [c0000000000d1b94] .do_path_lookup+0x138/0x17c
[c000000002af3ab0] [c0000000000d1cc8] .__path_lookup_intent_open+0x78/0xdc
[c000000002af3b60] [c0000000000d2960] .do_filp_open+0xcc/0x764
[c000000002af3d00] [c0000000000c5454] .do_sys_open+0x80/0x14c
[c000000002af3db0] [c000000000108378] .compat_sys_open+0x24/0x38
[c000000002af3e30] [c0000000000076ac] syscall_exit+0x0/0x40
Instruction dump:
60000000 80a40004 80090004 7f802800 409e003c e8890008 e87f0008 4bf0aa45 
60000000 2fa30000 409e0024 e93fffe0 <e869fff0> 4bf2f84d 60000000 7c630034 
---[ end trace ac14ee183d55eec5 ]---

Re: oops in proc_sys_compare

[Al Viro]

On Thu, Aug 14, 2008 at 07:31:06PM +0100, Hugh Dickins wrote:
> I got this oops below, after several hours of swap-heavy kernel builds
> in tmpfs, on 2.6.27-rc1-mm1 a couple of weeks ago.  Tried to reproduce
> it without success, then got a very similar trace (not saved) from
> 2.6.27-rc3 itself doing the same test yesterday: again oopsing in
> proc_sys_compare on address -16, looks like it's trying for
> PROC_I(dentry->d_inode)->sysctl but d_inode is NULL.
> 
> I looked to see what's been going on in fs/proc recently, and your
> [PATCH] sanitize proc_sysctl 9043476f726802f4b00c96d0c4f418dde48d1304
> does sound like it might be implicated.  I've only seen this on
> PowerPC G5, similar tests on x86_32 and _64 haven't shown it:
> maybe a memory barrier needed somewhere?
 
Bloody interesting.  We never create negative hashed dentries in there and
AFAICS we should never get d_delete() called on those...  Missing barrier
would mean serious trouble in dcache.c and not just for /proc/sys...

Are you sure about oops decoding?  At least disassembly of proc_sys_compare()
in the kernel image in question would be nice to see...

Re: oops in proc_sys_compare

[Hugh Dickins]

On Fri, 15 Aug 2008, Al Viro wrote:
> On Thu, Aug 14, 2008 at 07:31:06PM +0100, Hugh Dickins wrote:
> > I got this oops below, after several hours of swap-heavy kernel builds
> > in tmpfs, on 2.6.27-rc1-mm1 a couple of weeks ago.  Tried to reproduce
> > it without success, then got a very similar trace (not saved) from
> > 2.6.27-rc3 itself doing the same test yesterday: again oopsing in
> > proc_sys_compare on address -16, looks like it's trying for
> > PROC_I(dentry->d_inode)->sysctl but d_inode is NULL.
> > 
> > I looked to see what's been going on in fs/proc recently, and your
> > [PATCH] sanitize proc_sysctl 9043476f726802f4b00c96d0c4f418dde48d1304
> > does sound like it might be implicated.  I've only seen this on
> > PowerPC G5, similar tests on x86_32 and _64 haven't shown it:
> > maybe a memory barrier needed somewhere?
>  
> Bloody interesting.  We never create negative hashed dentries in there and
> AFAICS we should never get d_delete() called on those...  Missing barrier
> would mean serious trouble in dcache.c and not just for /proc/sys...
> 
> Are you sure about oops decoding?  At least disassembly of proc_sys_compare()
> in the kernel image in question would be nice to see...

Here it is: I'd changed config meanwhile, so this is from a rebuild,
but symbol addresses fit exactly with the trace (and the 2.6.27-rc1-mm1
fs/proc/proc_sysctl.c is identical to that in 2.6.27-rc3 or current git).
I did try "objdump -Sd" at first, but that just looked more confusing.

c000000000121e7c <.proc_sys_compare>:
proc_sys_compare():
/home/hugh/26271E1/fs/proc/proc_sysctl.c:383
c000000000121e7c:	7c 08 02 a6 	mflr    r0
c000000000121e80:	fb e1 ff f0 	std     r31,-16(r1)
c000000000121e84:	7c a9 2b 78 	mr      r9,r5
c000000000121e88:	7c 9f 23 78 	mr      r31,r4
c000000000121e8c:	f8 01 00 10 	std     r0,16(r1)
c000000000121e90:	f8 21 ff 81 	stdu    r1,-128(r1)
/home/hugh/26271E1/fs/proc/proc_sysctl.c:385
c000000000121e94:	60 00 00 00 	nop
c000000000121e98:	80 a4 00 04 	lwz     r5,4(r4)
c000000000121e9c:	80 09 00 04 	lwz     r0,4(r9)
c000000000121ea0:	7f 80 28 00 	cmpw    cr7,r0,r5
c000000000121ea4:	40 9e 00 3c 	bne-    cr7,c000000000121ee0 <.proc_sys_compare+0x64>
/home/hugh/26271E1/fs/proc/proc_sysctl.c:387
c000000000121ea8:	e8 89 00 08 	ld      r4,8(r9)
c000000000121eac:	e8 7f 00 08 	ld      r3,8(r31)
c000000000121eb0:	4b f0 aa 45 	bl      c00000000002c8f4 <.memcmp>
c000000000121eb4:	60 00 00 00 	nop
c000000000121eb8:	2f a3 00 00 	cmpdi   cr7,r3,0
c000000000121ebc:	40 9e 00 24 	bne-    cr7,c000000000121ee0 <.proc_sys_compare+0x64>
PROC_I():
/home/hugh/26271E1/fs/proc/proc_sysctl.c:384
c000000000121ec0:	e9 3f ff e0 	ld      r9,-32(r31)
c000000000121ec4:	e8 69 ff f0 	ld      r3,-16(r9)
c000000000121ec8:	4b f2 f8 4d 	bl      c000000000051714 <.sysctl_is_seen>
c000000000121ecc:	60 00 00 00 	nop
proc_sys_compare():
/home/hugh/26271E1/fs/proc/proc_sysctl.c:389
c000000000121ed0:	7c 63 00 34 	cntlzw  r3,r3
c000000000121ed4:	54 63 d9 7e 	rlwinm  r3,r3,27,5,31
c000000000121ed8:	78 63 00 20 	clrldi  r3,r3,32
c000000000121edc:	48 00 00 08 	b       c000000000121ee4 <.proc_sys_compare+0x68>
c000000000121ee0:	38 60 00 01 	li      r3,1
/home/hugh/26271E1/fs/proc/proc_sysctl.c:390
c000000000121ee4:	38 21 00 80 	addi    r1,r1,128
c000000000121ee8:	e8 01 00 10 	ld      r0,16(r1)
c000000000121eec:	eb e1 ff f0 	ld      r31,-16(r1)
c000000000121ef0:	7c 08 03 a6 	mtlr    r0
c000000000121ef4:	4e 80 00 20 	blr