kernel panic when mount NFSv4

DISCUSSION Mi Jinlong 4 participants 6 messages Dec 14, 2010 – Dec 14, 2012

Subsystems (3)

Networking NFS client NFS server

lore

Share & tools

lore

Mi Jinlong

author

2010-12-14 08:54 UTC #0 lore raw

Hi,

When testing NFSv4 at RHEL6 with kernel 2.6.32, I got a kernel panic at NFS client's __rpc_create_common function.

The panic place is:
rpc_mkpipe

    __rpc_lookup_create()          <=== find pipefile *idmap*
    __rpc_mkpipe()                 <=== pipefile is *idmap*
      __rpc_create_common()
       ******  BUG_ON(!d_unhashed(dentry)); ******    *panic*

It means that the dentry's d_flags have be set DCACHE_UNHASHED, but it should not be set here.

Is someone known this bug? or give me some idea?

A reproduce program is append, but it can't reproduce the bug every time.
the export is: "/nfsroot *(rw,no_root_squash,fsid=0,insecure)"

And the panic message is append.

============================================================================
#!/bin/sh

LOOPTOTAL=768
LOOPCOUNT=0
ret=0

while [ $LOOPCOUNT -ne $LOOPTOTAL ]
do

	((LOOPCOUNT += 1))
	service nfs restart
	/usr/sbin/rpc.idmapd
	mount -t nfs4 127.0.0.1:/ /mnt|| return 1;
	ls -l /var/lib/nfs/rpc_pipefs/nfs/*/
	umount /mnt
	echo $LOOPCOUNT

done

===============================================================================

Code: af 60 01 00 00 89 fa 89 f0 e8 64 cf 89 f0 e8 5c 7c 64 cf 31 c0 8b 5c 24 10 8b 
74 24 14 8b 7c 24 18 8b 6c 24 1c 83 c4 20 c3 <0f> 0b eb fc 8b 46 28 c7 44 24 08 20
de ee f0 c7 44 24 04 56 ea 
EIP:[<f0ee92ea>] __rpc_create_common+0x8a/0xc0 [sunrpc] SS:ESP 0068:eccb5d28
---[ end trace 8f5606cd08928ed2]---
Kernel panic - not syncing: Fatal exception
Pid:7131, comm: mount.nfs4 Tainted: G     D   -------------------2.6.32 #1
Call Trace:
 [<c080ad18>] ? panic+0x42/0xed
 [<c080e42c>] ? oops_end+0xbc/0xd0
 [<c040b090>] ? do_invalid_op+0x0/0x90
 [<c040b10f>] ? do_invalid_op+0x7f/0x90
 [<f0ee92ea>] ? __rpc_create_common+0x8a/0xc0[sunrpc]
 [<f0edc433>] ? rpc_free_task+0x33/0x70[sunrpc]
 [<f0ed6508>] ? prc_call_sync+0x48/0x60[sunrpc]
 [<f0ed656e>] ? rpc_ping+0x4e/0x60[sunrpc]
 [<f0ed6eaf>] ? rpc_create+0x38f/0x4f0[sunrpc]
 [<c080d80b>] ? error_code+0x73/0x78
 [<f0ee92ea>] ? __rpc_create_common+0x8a/0xc0[sunrpc]
 [<c0532bda>] ? d_lookup+0x2a/0x40
 [<f0ee94b1>] ? rpc_mkpipe+0x111/0x1b0[sunrpc]
 [<f10a59f4>] ? nfs_create_rpc_client+0xb4/0xf0[nfs]
 [<f10d6c6d>] ? nfs_fscache_get_client_cookie+0x1d/0x50[nfs]
 [<f10d3fcb>] ? nfs_idmap_new+0x7b/0x140[nfs]
 [<c05e76aa>] ? strlcpy+0x3a/0x60
 [<f10a60ca>] ? nfs4_set_client+0xea/0x2b0[nfs]
 [<f10a6d0c>] ? nfs4_create_server+0xac/0x1b0[nfs]
 [<c04f1400>] ? krealloc+0x40/0x50
 [<f10b0e8b>] ? nfs4_remote_get_sb+0x6b/0x250[nfs]
 [<c04f14ec>] ? kstrdup+0x3c/0x60
 [<c0520739>] ? vfs_kern_mount+0x69/0x170
 [<f10b1a3c>] ? nfs_do_root_mount+0x6c/0xa0[nfs]
 [<f10b1b47>] ? nfs4_try_mount+0x37/0xa0[nfs]
 [<f10afe6d>] ? nfs4_validate_text_mount_data+-x7d/0xf0[nfs]
 [<f10b1c42>] ? nfs4_get_sb+0x92/0x2f0
 [<c0520739>] ? vfs_kern_mount+0x69/0x170
 [<c05366d2>] ? get_fs_type+0x32/0xb0
 [<c052089f>] ? do_kern_mount+0x3f/0xe0
 [<c053954f>] ? do_mount+0x2ef/0x740
 [<c0537740>] ? copy_mount_options+0xb0/0x120
 [<c0539a0e>] ? sys_mount+0x6e/0xa0

Mi Jinlong

author

2010-12-20 09:56 UTC #1 lore raw

hello,

At the latest kernel(2.6.37-rc6), I got warning message as below:

------------[ cut here ]------------
kernel BUG at net/sunrpc/rpc_pipe.c:469!
invalid opcode: 0000 [#1] SMP
last sysfs file: /sys/module/nfsd/initstate
Modules linked in: nfs fscache nfsd lockd nfs_acl auth_rpcgss sunrpc exportfs ipv6 ext3 jbd dm_mirror dm_region_hash dm_log dm_mod sg ppdev 8139too 8139cp r8169 mii parport_pc parport pcspkr serio_raw i2c_i801 iTCO_wdt iTCO_vendor_support snd_hda_codec_realtek snd_hda_intel snd_hda_codec snd_hwdep snd_seq snd_seq_device snd_pcm snd_timer snd soundcore snd_page_alloc ext4 mbcache jbd2 sd_mod crc_t10dif pata_acpi ata_generic ata_piix usb_storage nouveau ttm drm_kms_helper drm i2c_algo_bit i2c_core video output [last unloaded: scsi_wait_scan]

Pid: 7371, comm: mount.nfs4 Not tainted 2.6.37-rc6+ #2 E945GCZ/ASPIRE AG1720
EIP: 0060:[<fed81f6a>] EFLAGS: 00010246 CPU: 0
EIP is at __rpc_create_common+0x8a/0xc0 [sunrpc]
EAX: f64b4300 EBX: f0c3eb64 ECX: 00001180 EDX: f0c3eb64
ESI: f64b4300 EDI: 00001180 EBP: f09e0000 ESP: f12efd20
DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
Process mount.nfs4 (pid: 7371, ti=f12ee000 task=f0964530 task.ti=f12ee000)

Stack:
 f8456d84 c0520e1a f0c5f21c f12efd6c f0c3eb64 f64b4380 00001180 f8456d84
 fed82121 fed86a60 f09e0000 f48026d0 00000010 00000000 000000d0 f0c5f21c
 f8456d84 f64b4300 f09e0000 11bcc18d 00000005 f8456d84 f09e0000 f28b7400
Call Trace:
 [<c0520e1a>] ? d_lookup+0x2a/0x40
 [<fed82121>] ? rpc_mkpipe+0x111/0x1b0 [sunrpc]
 [<f844ddeb>] ? nfs_idmap_new+0x7b/0x140 [nfs]
 [<c05c42da>] ? strlcpy+0x3a/0x60
 [<f841fc3a>] ? nfs4_set_client+0xea/0x2b0 [nfs]
 [<f841fec1>] ? nfs4_create_server+0xc1/0x2d0 [nfs]
 [<f842afd9>] ? nfs4_remote_mount+0x59/0x2c0 [nfs]
 [<c0510f1d>] ? vfs_kern_mount+0x7d/0x230
 [<f842af80>] ? nfs4_remote_mount+0x0/0x2c0 [nfs]
 [<f842ab2c>] ? nfs_do_root_mount+0x6c/0xa0 [nfs]
 [<f842ac37>] ? nfs4_try_mount+0x37/0xa0 [nfs]
 [<f84291ad>] ? nfs4_validate_text_mount_data+0x7d/0xf0 [nfs]
 [<f842bf22>] ? nfs4_get_sb+0x92/0x2f0 [nfs]
 [<c051102c>] ? vfs_kern_mount+0x18c/0x230
 [<c0524762>] ? get_fs_type+0x32/0xb0
 [<c051112f>] ? do_kern_mount+0x3f/0xe0
 [<c0527356>] ? do_mount+0x306/0x6f0
 [<c0525640>] ? copy_mount_options+0xb0/0x120
 [<c05277ae>] ? sys_mount+0x6e/0xa0
 [<c040a59f>] ? sysenter_do_call+0x12/0x28
Code: af 50 01 00 00 89 fa 89 d8 e8 13 e3 79 c1 89 d8 e8 cc d5 79 c1 31 c0 8b 5c 24 10 8b 74 24 14 8b 7c 24 18 8b 6c 24 1c 83 c4 20 c3 <0f> 0b eb fe 8b 43 28 c7 44 24 08 00 6a d8 fe c7 44 24 04 8f 75
EIP: [<fed81f6a>] __rpc_create_common+0x8a/0xc0 [sunrpc] SS:ESP 0068:f12efd20
---[ end trace 49fbc098c75066aa ]---

Trond Myklebust

2010-12-20 21:19 UTC #2 lore raw

In reply to Mi Jinlong

Quoted 74 lines · Mi Jinlong

Hi,

When testing NFSv4 at RHEL6 with kernel 2.6.32, I got a kernel panic at NFS client's __rpc_create_common function.

The panic place is:
rpc_mkpipe

    __rpc_lookup_create()          <=== find pipefile *idmap*
    __rpc_mkpipe()                 <=== pipefile is *idmap*
      __rpc_create_common()
       ******  BUG_ON(!d_unhashed(dentry)); ******    *panic*

It means that the dentry's d_flags have be set DCACHE_UNHASHED, but it should not be set here.

Is someone known this bug? or give me some idea?

A reproduce program is append, but it can't reproduce the bug every time.
the export is: "/nfsroot *(rw,no_root_squash,fsid=0,insecure)"

And the panic message is append.

============================================================================
#!/bin/sh

LOOPTOTAL=768
LOOPCOUNT=0
ret=0

while [ $LOOPCOUNT -ne $LOOPTOTAL ]
do

	((LOOPCOUNT += 1))
	service nfs restart
	/usr/sbin/rpc.idmapd
	mount -t nfs4 127.0.0.1:/ /mnt|| return 1;
	ls -l /var/lib/nfs/rpc_pipefs/nfs/*/
	umount /mnt
	echo $LOOPCOUNT

done

===============================================================================

Code: af 60 01 00 00 89 fa 89 f0 e8 64 cf 89 f0 e8 5c 7c 64 cf 31 c0 8b 5c 24 10 8b 
74 24 14 8b 7c 24 18 8b 6c 24 1c 83 c4 20 c3 <0f> 0b eb fc 8b 46 28 c7 44 24 08 20
de ee f0 c7 44 24 04 56 ea 
EIP:[<f0ee92ea>] __rpc_create_common+0x8a/0xc0 [sunrpc] SS:ESP 0068:eccb5d28
---[ end trace 8f5606cd08928ed2]---
Kernel panic - not syncing: Fatal exception
Pid:7131, comm: mount.nfs4 Tainted: G     D   -------------------2.6.32 #1
Call Trace:
 [<c080ad18>] ? panic+0x42/0xed
 [<c080e42c>] ? oops_end+0xbc/0xd0
 [<c040b090>] ? do_invalid_op+0x0/0x90
 [<c040b10f>] ? do_invalid_op+0x7f/0x90
 [<f0ee92ea>] ? __rpc_create_common+0x8a/0xc0[sunrpc]
 [<f0edc433>] ? rpc_free_task+0x33/0x70[sunrpc]
 [<f0ed6508>] ? prc_call_sync+0x48/0x60[sunrpc]
 [<f0ed656e>] ? rpc_ping+0x4e/0x60[sunrpc]
 [<f0ed6eaf>] ? rpc_create+0x38f/0x4f0[sunrpc]
 [<c080d80b>] ? error_code+0x73/0x78
 [<f0ee92ea>] ? __rpc_create_common+0x8a/0xc0[sunrpc]
 [<c0532bda>] ? d_lookup+0x2a/0x40
 [<f0ee94b1>] ? rpc_mkpipe+0x111/0x1b0[sunrpc]
 [<f10a59f4>] ? nfs_create_rpc_client+0xb4/0xf0[nfs]
 [<f10d6c6d>] ? nfs_fscache_get_client_cookie+0x1d/0x50[nfs]
 [<f10d3fcb>] ? nfs_idmap_new+0x7b/0x140[nfs]
 [<c05e76aa>] ? strlcpy+0x3a/0x60
 [<f10a60ca>] ? nfs4_set_client+0xea/0x2b0[nfs]
 [<f10a6d0c>] ? nfs4_create_server+0xac/0x1b0[nfs]
 [<c04f1400>] ? krealloc+0x40/0x50
 [<f10b0e8b>] ? nfs4_remote_get_sb+0x6b/0x250[nfs]
 [<c04f14ec>] ? kstrdup+0x3c/0x60
 [<c0520739>] ? vfs_kern_mount+0x69/0x170
 [<f10b1a3c>] ? nfs_do_root_mount+0x6c/0xa0[nfs]
 [<f10b1b47>] ? nfs4_try_mount+0x37/0xa0[nfs]

Quoted 8 lines

 [<f10afe6d>] ? nfs4_validate_text_mount_data+-x7d/0xf0[nfs]
 [<f10b1c42>] ? nfs4_get_sb+0x92/0x2f0
 [<c0520739>] ? vfs_kern_mount+0x69/0x170
 [<c05366d2>] ? get_fs_type+0x32/0xb0
 [<c052089f>] ? do_kern_mount+0x3f/0xe0
 [<c053954f>] ? do_mount+0x2ef/0x740
 [<c0537740>] ? copy_mount_options+0xb0/0x120
 [<c0539a0e>] ? sys_mount+0x6e/0xa0

Hi,

Does the following patch fix the problem?

Cheers
Trond

--------------------------
SUNRPC: Fix a BUG in __rpc_create_common

From: Trond Myklebust <[email protected]>

Mi Jinlong reports:

When testing NFSv4 at RHEL6 with kernel 2.6.32, I got a kernel panic at NFS client's __rpc_create_common function.

The panic place is:
rpc_mkpipe

      __rpc_lookup_create()          <=== find pipefile *idmap*
      __rpc_mkpipe()                 <=== pipefile is *idmap*
        __rpc_create_common()
         ******  BUG_ON(!d_unhashed(dentry)); ****** *panic*

The test is wrong: we can find ourselves with a hashed negative dentry here if the idmapper tried to look up the file before we got round to creating it.

Just replace the BUG_ON() with a d_drop(dentry).

Reported-by Mi Jinlong <[email protected]>

Signed-off-by Trond Myklebust <[email protected]>

---

 net/sunrpc/rpc_pipe.c |    2 +-
 1 files changed, 1 insertions(+), 1 deletions(-)

net/sunrpc/rpc_pipe.c +1 -1

index 10a17a3..5356d95 100644
@@ -466,7 +466,7 @@ static int __rpc_create_common(struct inode *dir, struct dentry *dentry,
 {
 	struct inode *inode;
 
-	BUG_ON(!d_unhashed(dentry));
+	d_drop(dentry);
 	inode = rpc_get_inode(dir->i_sb, mode);
 	if (!inode)
 		goto out_err;

Signature · 6 lines

Trond Myklebust
Linux NFS client maintainer

NetApp
[email protected]
www.netapp.com

Mi Jinlong

author

2010-12-21 05:34 UTC #3 lore raw

Quoted 84 lines · Trond Myklebust

Quoted 74 lines · Mi Jinlong

Hi,

When testing NFSv4 at RHEL6 with kernel 2.6.32, I got a kernel panic at NFS client's __rpc_create_common function.

The panic place is:
rpc_mkpipe

    __rpc_lookup_create()          <=== find pipefile *idmap*
    __rpc_mkpipe()                 <=== pipefile is *idmap*
      __rpc_create_common()
       ******  BUG_ON(!d_unhashed(dentry)); ******    *panic*

It means that the dentry's d_flags have be set DCACHE_UNHASHED, but it should not be set here.

Is someone known this bug? or give me some idea?

A reproduce program is append, but it can't reproduce the bug every time.
the export is: "/nfsroot *(rw,no_root_squash,fsid=0,insecure)"

And the panic message is append.

============================================================================
#!/bin/sh

LOOPTOTAL=768
LOOPCOUNT=0
ret=0

while [ $LOOPCOUNT -ne $LOOPTOTAL ]
do

	((LOOPCOUNT += 1))
	service nfs restart
	/usr/sbin/rpc.idmapd
	mount -t nfs4 127.0.0.1:/ /mnt|| return 1;
	ls -l /var/lib/nfs/rpc_pipefs/nfs/*/
	umount /mnt
	echo $LOOPCOUNT

done

===============================================================================

Code: af 60 01 00 00 89 fa 89 f0 e8 64 cf 89 f0 e8 5c 7c 64 cf 31 c0 8b 5c 24 10 8b 
74 24 14 8b 7c 24 18 8b 6c 24 1c 83 c4 20 c3 <0f> 0b eb fc 8b 46 28 c7 44 24 08 20
de ee f0 c7 44 24 04 56 ea 
EIP:[<f0ee92ea>] __rpc_create_common+0x8a/0xc0 [sunrpc] SS:ESP 0068:eccb5d28
---[ end trace 8f5606cd08928ed2]---
Kernel panic - not syncing: Fatal exception
Pid:7131, comm: mount.nfs4 Tainted: G     D   -------------------2.6.32 #1
Call Trace:
 [<c080ad18>] ? panic+0x42/0xed
 [<c080e42c>] ? oops_end+0xbc/0xd0
 [<c040b090>] ? do_invalid_op+0x0/0x90
 [<c040b10f>] ? do_invalid_op+0x7f/0x90
 [<f0ee92ea>] ? __rpc_create_common+0x8a/0xc0[sunrpc]
 [<f0edc433>] ? rpc_free_task+0x33/0x70[sunrpc]
 [<f0ed6508>] ? prc_call_sync+0x48/0x60[sunrpc]
 [<f0ed656e>] ? rpc_ping+0x4e/0x60[sunrpc]
 [<f0ed6eaf>] ? rpc_create+0x38f/0x4f0[sunrpc]
 [<c080d80b>] ? error_code+0x73/0x78
 [<f0ee92ea>] ? __rpc_create_common+0x8a/0xc0[sunrpc]
 [<c0532bda>] ? d_lookup+0x2a/0x40
 [<f0ee94b1>] ? rpc_mkpipe+0x111/0x1b0[sunrpc]
 [<f10a59f4>] ? nfs_create_rpc_client+0xb4/0xf0[nfs]
 [<f10d6c6d>] ? nfs_fscache_get_client_cookie+0x1d/0x50[nfs]
 [<f10d3fcb>] ? nfs_idmap_new+0x7b/0x140[nfs]
 [<c05e76aa>] ? strlcpy+0x3a/0x60
 [<f10a60ca>] ? nfs4_set_client+0xea/0x2b0[nfs]
 [<f10a6d0c>] ? nfs4_create_server+0xac/0x1b0[nfs]
 [<c04f1400>] ? krealloc+0x40/0x50
 [<f10b0e8b>] ? nfs4_remote_get_sb+0x6b/0x250[nfs]
 [<c04f14ec>] ? kstrdup+0x3c/0x60
 [<c0520739>] ? vfs_kern_mount+0x69/0x170
 [<f10b1a3c>] ? nfs_do_root_mount+0x6c/0xa0[nfs]
 [<f10b1b47>] ? nfs4_try_mount+0x37/0xa0[nfs]

Quoted 8 lines

 [<f10afe6d>] ? nfs4_validate_text_mount_data+-x7d/0xf0[nfs]
 [<f10b1c42>] ? nfs4_get_sb+0x92/0x2f0
 [<c0520739>] ? vfs_kern_mount+0x69/0x170
 [<c05366d2>] ? get_fs_type+0x32/0xb0
 [<c052089f>] ? do_kern_mount+0x3f/0xe0
 [<c053954f>] ? do_mount+0x2ef/0x740
 [<c0537740>] ? copy_mount_options+0xb0/0x120
 [<c0539a0e>] ? sys_mount+0x6e/0xa0

Quoted 3 lines

Hi,
Does the following patch fix the problem?

Thanks Trond.

After this patch, NFS client runs correctly.

Quoted 51 lines

Cheers
Trond
--------------------------
SUNRPC: Fix a BUG in __rpc_create_common
From: Trond Myklebust <[email protected]>
Mi Jinlong reports:
When testing NFSv4 at RHEL6 with kernel 2.6.32, I got a kernel panic at NFS client's __rpc_create_common function.
The panic place is:
rpc_mkpipe
      __rpc_lookup_create()          <=== find pipefile *idmap*
      __rpc_mkpipe()                 <=== pipefile is *idmap*
        __rpc_create_common()
         ******  BUG_ON(!d_unhashed(dentry)); ****** *panic*
The test is wrong: we can find ourselves with a hashed negative dentry here if the idmapper tried to look up the file before we got round to creating it.
Just replace the BUG_ON() with a d_drop(dentry).
Reported-by Mi Jinlong <[email protected]>
Signed-off-by Trond Myklebust <[email protected]>
---
 net/sunrpc/rpc_pipe.c |    2 +-
 1 files changed, 1 insertions(+), 1 deletions(-)
net/sunrpc/rpc_pipe.c +1 -1
index 10a17a3..5356d95 100644
@@ -466,7 +466,7 @@ static int __rpc_create_common(struct inode *dir, struct dentry *dentry,
 {
 	struct inode *inode;
 
-	BUG_ON(!d_unhashed(dentry));
+	d_drop(dentry);
 	inode = rpc_get_inode(dir->i_sb, mode);
 	if (!inode)
 		goto out_err;

Signature · 3 lines

----
thanks
Mi Jinlong

Jonathan Nieder

2012-12-14 05:40 UTC #4 lore raw

In reply to Trond Myklebust

Hi Willy et al,

Please consider

beb0f0a9fba1 kernel panic when mount NFSv4, 2010-12-20

for application to kernel.org's 2.6.32.y and 2.6.34.y trees. The patch was applied upstream during the 2.6.38 merge window, so newer kernels don't need it.

(Context: <http://bugs.debian.org/695872>.) Tom Downes (cc-ed) experienced the bug on a Debian kernel close to 2.6.32.58 and confirmed that the patch doesn't seem to hurt.

The patch is part of Fedora 13's 2.6.34-based and Fedora 14's 2.6.35-based kernels[1]. It was also included in the RHEL kernel at some point between 2.6.32-71.29.1.el6 and 2.6.32-131.0.15.el6[2].

Thoughts of all kinds welcome, as always.

Regards,
Jonathan

[1] https://bugzilla.redhat.com/673207
[2] https://oss.oracle.com/git/?p=redpatch.git;a=commit;h=8028cccdc4b1

Willy Tarreau

2012-12-14 07:20 UTC #5 lore raw

Hi Jonathan,

Quoted 14 lines · Jonathan Nieder

Hi Willy et al,
Please consider
beb0f0a9fba1 kernel panic when mount NFSv4, 2010-12-20
for application to kernel.org's 2.6.32.y and 2.6.34.y trees. The patch was applied upstream during the 2.6.38 merge window, so newer kernels don't need it.
(Context: <http://bugs.debian.org/695872>.) Tom Downes (cc-ed) experienced the bug on a Debian kernel close to 2.6.32.58 and confirmed that the patch doesn't seem to hurt.

Quoted 5 lines

The patch is part of Fedora 13's 2.6.34-based and Fedora 14's 2.6.35-based kernels[1]. It was also included in the RHEL kernel at some point between 2.6.32-71.29.1.el6 and 2.6.32-131.0.15.el6[2].
Thoughts of all kinds welcome, as always.

Thank you for all the details, as always :-)

I'm queuing this patch for 2.6.32.61.

Best regards,
Willy