https://bugzilla.novell.com/show_bug.cgi?id=325913#c1 Summary: NFS4 stress test raises "Call Trace" in opensuse10.3alpha5 on power5 Product: openSUSE 10.3 Version: Beta 2 Platform: PowerPC-64 OS/Version: openSUSE 10.3 Status: NEW Severity: Normal Priority: P5 - None Component: Kernel AssignedTo: power-bugs@forge.provo.novell.com ReportedBy: bugproxy@us.ibm.com QAContact: qa@suse.de CC: power-bugs@forge.provo.novell.com Found By: --- Partner ID: LTC 36199 LTC Owner is: suzukikp@in.ibm.com LTC Originator is: mohd.omar@in.ibm.com ---problem description---------- nfs4 stress(fsstress) test raises "Call Trace"and "Oops" in opensuse10.3alpha5 on power5 ........... Jul 9 05:59:35 p630b kernel: RESERVE_SPACE(761) failed in function encode_lookup Jul 9 05:59:35 p630b kernel: ------------[ cut here ]------------ Jul 9 05:59:35 p630b kernel: kernel BUG at fs/nfs/nfs4xdr.c:849! Jul 9 05:59:35 p630b kernel: Oops: Exception in kernel mode, sig: 5 [#1] Jul 9 05:59:35 p630b kernel: SMP NR_CPUS=128 NUMA pSeries Jul 9 05:59:35 p630b kernel: Modules linked in: nfs lockd nfs_acl sunrpc ipv6 apparmor loop dm_mod fuse e100 mii sg sd_mod sym53c8xx scsi_transport_spi pata_sl82c105 libata scsi_mod Jul 9 05:59:35 p630b kernel: NIP: d00000000086fc68 LR: d00000000086fc58 CTR: c00000000008e408 Jul 9 05:59:35 p630b kernel: REGS: c0000000d7fe3210 TRAP: 0700 Tainted: G N (2.6.22-rc4-git3-2-ppc64) Jul 9 05:59:35 p630b kernel: MSR: 9000000000029032 CR: 28000484 XER: 00000000 Jul 9 05:59:35 p630b kernel: TASK = c00000002fc02040[4120] 'fsstress' THREAD: c0000000d7fe0000 CPU: 3 Jul 9 05:59:35 p630b kernel: GPR00: 0000000000000001 c0000000d7fe3490 d0000000008b3000 0000000000000037 Jul 9 05:59:35 p630b kernel: GPR04: 0000000000000000 0000000000000000 0000000000000000 0000000000000000 Jul 9 05:59:35 p630b kernel: GPR08: c0000001fe7a8040 0000000000000000 c000000005c87bf8 c0000000006493b0 Jul 9 05:59:35 p630b kernel: GPR12: 000000000000000a c0000000005e8e80 0000000000000000 0000000000000000 Jul 9 05:59:35 p630b kernel: GPR16: 0000000000000000 0000000000000000 0000000000000000 0000000000000000 Jul 9 05:59:35 p630b kernel: GPR20: 0000000000000000 0000000000000000 c0000000d7fe3a30 d0000000007c6424 Jul 9 05:59:35 p630b kernel: GPR24: c0000001d31409a0 c0000000f064e618 c0000000d7fe3920 c0000001d31409a0 Jul 9 05:59:35 p630b kernel: GPR28: 00000000000002f1 0000000028000444 d0000000008ae980 0000000000000000 Jul 9 05:59:35 p630b kernel: NIP [d00000000086fc68] .encode_lookup+0x6c/0xc0 [nfs] Jul 9 05:59:35 p630b kernel: LR [d00000000086fc58] .encode_lookup+0x5c/0xc0 [nfs] Jul 9 05:59:35 p630b kernel: Call Trace: Jul 9 05:59:35 p630b kernel: [c0000000d7fe3490] [d00000000086fc58] encode_lookup+0x5c/0xc0 [nfs] (unreliable) Jul 9 05:59:35 p630b kernel: [c0000000d7fe3530] [d000000000871b38] nfs4_xdr_enc_lookup+0x78/0xbc [nfs] Jul 9 05:59:35 p630b kernel: [c0000000d7fe3600] [d00000000078b634] rpcauth_wrap_req+0xd8/0x108 [sunrpc] Jul 9 05:59:35 p630b kernel: [c0000000d7fe36b0] [d000000000782688] call_transmit+0x228/0x2d8 [sunrpc] Jul 9 05:59:35 p630b kernel: [c0000000d7fe3750] [d00000000078a330] __rpc_execute+0xd4/0x35c [sunrpc] Jul 9 05:59:35 p630b kernel: [c0000000d7fe37f0] [d000000000782fc0] rpc_call_sync+0xb4/0x104 [sunrpc] Jul 9 05:59:35 p630b kernel: [c0000000d7fe38a0] [d00000000086a3bc] nfs4_proc_lookup+0x110/0x2cc [nfs] Jul 9 05:59:35 p630b kernel: [c0000000d7fe39c0] [d00000000084d92c] nfs_lookup+0x158/0x33c [nfs] Jul 9 05:59:35 p630b kernel: [c0000000d7fe3bc0] [c0000000000faf14] lookup_hash+0xfc/0x140 Jul 9 05:59:35 p630b kernel: [c0000000d7fe3c60] [c0000000000fd7ec] sys_renameat+0x164/0x230 Jul 9 05:59:35 p630b kernel: [c0000000d7fe3e30] [c0000000000086c8] syscall_exit+0x0/0x40 Jul 9 05:59:35 p630b kernel: Instruction dump: Jul 9 05:59:35 p630b kernel: e8410028 7fa4eb78 7c7f1b79 7fa00026 40820014 e8be83a8 e87e8350 4800c245 Jul 9 05:59:35 p630b kernel: e8410028 7fa80120 7c000026 54001ffe <0b000000> 3800000f 7b850020 387f0008 Jul 9 06:45:34 p630b syslog-ng[2750]: STATS: dropped 0 ---steps followed::----- 1. Install ltp-full-20070630.tgz in client(p630b) 2. create ext2,ext3 partitions, export file systems and setup nfs-server in server(p520b) and mount via nfs4 in client (p630b). In client run the following.. 3. ltp-full-20070630/testcases/kernel/fs/fsstress/fsstress -d /NFSVCLI/NFSV1 -l 0 -n 1000 -p 2 -r 4. ltp-full-20070630/testcases/kernel/fs/fsstress/fsstress -d /NFSVCLI/NFSV3 -l 0 -n 1000 -p 2 -r ---uname -a --------- server:: Linux linux-0gxvrp 2.6.22-rc4-git3-2-ppc64 #1 SMP 2007/06/12 15:00:04 UTC ppc64 ppc64 ppc64 GNU/Linux Client:: Linux p630b 2.6.22-rc4-git3-2-ppc64 #1 SMP 2007/06/12 15:00:04 UTC ppc64 ppc64 ppc64 GNU/Linux -----machine info---- server:: p520 (power5) client:: p630 (power4) ----Did the system produce an OOPS message on the console?------ Jul 9 05:59:35 p630b kernel: kernel BUG at fs/nfs/nfs4xdr.c:849! Jul 9 05:59:35 p630b kernel: Oops: Exception in kernel mode, sig: 5 [#1] Created an attachment (id=29104) --> (https://bugzilla.novell.com/attachment.cgi?id=29104) var-log-messages Created an attachment (id=29105) --> (https://bugzilla.novell.com/attachment.cgi?id=29105) dmesg-output hi suzuki, I executed fsstress with NFSv4 mounted partitions in opensuse10.3alpha6 with kernel : 2.6.22.1-2-ppc64 machine: p520b(p5) Here the results ------------------ kernel BUG at fs/nfs/nfs4xdr.c:480! Oops: Exception in kernel mode, sig: 5 [#1] SMP NR_CPUS=128 NUMA pSeries Modules linked in: nfs ipv6 nfsd exportfs nfs_acl lockd sunrpc apparmor loop dm_mod fuse e1000 sg sd_mod pata_pdc2027x ipr libata scsi_mod firmware_class NIP: d0000000006441e0 LR: d0000000006441d4 CTR: d00000000041e934 REGS: c00000006af87730 TRAP: 0700 Tainted: G N (2.6.22.1-2-ppc64) MSR: 8000000000029032 CR: 24008044 XER: 00000000 TASK = c00000007198e820[3106] 'rpciod/0' THREAD: c00000006af84000 CPU: 0 GPR00: 0000000000000001 c00000006af879b0 d000000000683080 0000000000000000 GPR04: 0000000000000240 c000000065b34400 bc91000000000000 bc918cf6f2f258f6 GPR08: 0005000000000000 c00000006698ab0c c00000006698a8c8 c00000006af87b68 GPR12: d00000000064df98 c0000000005f5880 0000000000000000 0000000000000000 GPR16: 0000000000000000 0000000000000000 0000000000000000 4000000001c00000 GPR20: c0000000005bfea0 00000000021c0110 0000000000272000 c0000000005c0110 GPR24: 00000000021bfea0 c00000006444e138 c000000063395808 c00000006af87b68 GPR28: c000000065b34400 0000000000000239 d00000000067ea00 c000000065352250 NIP [d0000000006441e0] .encode_string+0x34/0x60 [nfs] LR [d0000000006441d4] .encode_string+0x28/0x60 [nfs] Call Trace: [c00000006af87a40] [d000000000644784] .encode_open+0x3b0/0x3ec [nfs] [c00000006af87ae0] [d0000000006448f4] .nfs4_xdr_enc_open+0x88/0xf0 [nfs] [c00000006af87bb0] [d000000000413634] .rpcauth_wrap_req+0xd8/0x108 [sunrpc] [c00000006af87c60] [d00000000040a688] .call_transmit+0x228/0x2d8 [sunrpc] [c00000006af87d00] [d000000000412330] .__rpc_execute+0xd4/0x35c [sunrpc] [c00000006af87da0] [c00000000008f864] .run_workqueue+0x118/0x208 [c00000006af87e40] [c0000000000908b4] .worker_thread+0xf0/0x114 [c00000006af87f00] [c0000000000953f4] .kthread+0x78/0xc4 [c00000006af87f90] [c000000000028a00] .kernel_thread+0x4c/0x68 Instruction dump: fb81ffe0 fba1ffe8 7c9d2378 38840004 f8010010 f821ff71 7cbc2b78 78840020 48009dc9 e8410028 7c600074 7800d182 <0b000000> 7f84e378 7fa5eb78 4800908d thanks omar hi suzuki, test is still running and throwed one more Call trace, kernel BUG at fs/dcache.c:652! Oops: Exception in kernel mode, sig: 5 [#2] SMP NR_CPUS=128 NUMA pSeries Modules linked in: nfs ipv6 nfsd exportfs nfs_acl lockd sunrpc apparmor loop dm_mod fuse e1000 sg sd_mod pata_pdc2027x ipr libata scsi_mod firmware_class NIP: c00000000010dc24 LR: c00000000010dc20 CTR: c0000000000955b4 REGS: c000000072f97540 TRAP: 0700 Tainted: G N (2.6.22.1-2-ppc64) MSR: 8000000000029032 CR: 24000084 XER: 00000006 TASK = c000000072f8a040[8] 'events/1' THREAD: c000000072f94000 CPU: 1 GPR00: c00000000010dc20 c000000072f977c0 c00000000072ae40 0000000000000288 GPR04: 0000000000000000 0000000000000000 0000000000000000 0000000000000000 GPR08: c0000000021bb090 c000000000760478 c000000072993bf8 0000000000000000 GPR12: 0000000000004000 c0000000005f5a80 0000000000000000 0000000000000000 GPR16: 0000000000000000 0000000000000000 0000000000000000 4000000001c00000 GPR20: c0000000005bfea0 00000000021c0110 c000000072f97ce0 d00000000066e938 GPR24: c000000072f97c10 c000000000752980 0000000000000000 0000000000000000 GPR28: 0000000000000006 c000000065352220 c000000000679e88 c0000000659ef7e0 NIP [c00000000010dc24] .shrink_dcache_for_umount_subtree+0x240/0x3a4 LR [c00000000010dc20] .shrink_dcache_for_umount_subtree+0x23c/0x3a4 Call Trace: [c000000072f977c0] [c00000000010dc20] shrink_dcache_for_umount_subtree+0x23c/0x3a4 (unreliable) [c000000072f97850] [c00000000010e9e4] .shrink_dcache_for_umount+0x54/0x78 [c000000072f978d0] [c0000000000f7e20] .generic_shutdown_super+0x3c/0x1b8 [c000000072f97960] [c0000000000f800c] .kill_anon_super+0x24/0x88 [c000000072f979f0] [d00000000062574c] .nfs_kill_super+0x20/0x44 [nfs] [c000000072f97a80] [c0000000000f81a8] .deactivate_super+0xf0/0x144 [c000000072f97b10] [c000000000114824] .mntput_no_expire+0x9c/0x138 [c000000072f97ba0] [c000000000115050] .expire_mount_list+0x1b8/0x22c [c000000072f97c70] [c000000000116d18] .mark_mounts_for_expiry+0xf8/0x13c [c000000072f97d10] [d00000000062f350] .nfs_expire_automounts+0x24/0x60 [nfs] [c000000072f97da0] [c00000000008f864] .run_workqueue+0x118/0x208 [c000000072f97e40] [c0000000000908b4] .worker_thread+0xf0/0x114 [c000000072f97f00] [c0000000000953f4] .kthread+0x78/0xc4 [c000000072f97f90] [c000000000028a00] .kernel_thread+0x4c/0x68 Instruction dump: e8a90040 e93d0090 80fd0000 7fa4eb78 e87e80c0 e8dd0038 e9690030 7ce707b4 39290228 e90b0000 4bf6bd09 60000000 <0fe00000> 48000000 ebfd0028 7fbfe800 thanks --omar static void encode_string(struct xdr_stream *xdr, unsigned int len, const char *str) { __be32 *p; p = xdr_reserve_space(xdr, 4 + len); BUG_ON(p == NULL); <<<--- BUG_ON hit here .. __be32 * xdr_reserve_space(struct xdr_stream *xdr, size_t nbytes) { __be32 *p = xdr->p; __be32 *q; /* align nbytes on the next 32-bit boundary */ nbytes += 3; nbytes &= ~3; q = p + (nbytes >> 2); if (unlikely(q > xdr->end || q < p)) return NULL; <<<-- NULL is returned from here. This occurs when there is not enough space in the XDR buffer to reserve for the requested size. Omar, Is it possible to enable xmon and drop the system to xmon when you hit the BUG_ON ? Thanks Suzuki Created an attachment (id=30198) --> (https://bugzilla.novell.com/attachment.cgi?id=30198) Debug patch to get more information Omar, Please build the kernel with the debug patch attached here and run the tests. When you hit the problem, please upload the dmesg o/p. Thanks Suzuki Created an attachment (id=30437) --> (https://bugzilla.novell.com/attachment.cgi?id=30437) dmesg-output I added the patch and compiled the kernel. Performed the NFS4 stress tests, It generated a Call Trace.. ------------[ cut here ]------------ kernel BUG at /usr/src/linux-2.6.22.1-10/net/sunrpc/xdr.c:480! Oops: Exception in kernel mode, sig: 5 [#1] SMP NR_CPUS=128 NUMA pSeries Modules linked in: nfs ipv6 nfsd exportfs nfs_acl lockd sunrpc apparmor loop dm_mod fuse e100 mii sl82c105 sg sd_mod sym53c8xx scsi_transport_spi pata_sl82c105 libata scsi_mod NIP: d000000000113994 LR: d000000000113990 CTR: c0000000000955b4 REGS: c0000001eed9f190 TRAP: 0700 Tainted: G N (2.6.22.1-debug-10-debug) MSR: 9000000000029032 CR: 28000484 XER: 00000000 TASK = c0000001fd103820[30423] 'fsstress' THREAD: c0000001eed9c000 CPU: 0 GPR00: d000000000113990 c0000001eed9f410 d000000000147600 0000000000000065 GPR04: 0000000000000000 0000000000000000 0000000000000000 0000000000000000 GPR08: c000000004048090 c00000000071c478 c0000001fc0fbbf8 0000000000000000 GPR12: 000000000000000a c0000000005b8880 0000000000000000 0000000000000000 GPR16: 0000000000000000 0000000000000000 0000000000000000 0000000000000000 GPR20: 0000000000000000 0000000000000000 c0000001eed9fa30 d0000000001439ac GPR24: c0000000fa56f730 c0000000f9176270 c0000001eed9f920 c0000000fa56f730 GPR28: 00000000000002ef 00000000000002f7 d000000000144d80 c0000001eed9f5b8 NIP [d000000000113994] .xdr_reserve_space+0x60/0xb8 [sunrpc] LR [d000000000113990] .xdr_reserve_space+0x5c/0xb8 [sunrpc] Call Trace: [c0000001eed9f410] [d000000000113990] .xdr_reserve_space+0x5c/0xb8 [sunrpc] (unreliable) [c0000001eed9f490] [d000000000228c38] .encode_lookup+0x3c/0xc0 [nfs] [c0000001eed9f530] [d00000000022ab38] .nfs4_xdr_enc_lookup+0x78/0xbc [nfs] [c0000001eed9f600] [d000000000108634] .rpcauth_wrap_req+0xd8/0x108 [sunrpc] [c0000001eed9f6b0] [d0000000000ff688] .call_transmit+0x228/0x2d8 [sunrpc] [c0000001eed9f750] [d000000000107330] .__rpc_execute+0xd4/0x35c [sunrpc] [c0000001eed9f7f0] [d0000000000fffc0] .rpc_call_sync+0xb4/0x104 [sunrpc] [c0000001eed9f8a0] [d0000000002233bc] .nfs4_proc_lookup+0x110/0x2cc [nfs] [c0000001eed9f9c0] [d00000000020692c] .nfs_lookup+0x158/0x33c [nfs] [c0000001eed9fbc0] [c000000000101ac0] .lookup_hash+0xfc/0x140 [c0000001eed9fc60] [c000000000104398] .sys_renameat+0x164/0x230 [c0000001eed9fe30] [c0000000000086c8] syscall_exit+0x0/0x40 Instruction dump: 7d2b2a14 7fa90040 419d000c 7fa95840 40bc0028 e92a0008 e87e8018 7d645b78 80e90034 80c90030 48005d05 e8410028 <0fe00000> 48000000 f9230000 60000000 ---------------- thanks Here is the relevant information I got from the debug patch : xdr_reserve_space : FAILs : P: c00000000fd39084, nbytes: 760, xdr.buflen: 560, current len : 124 ------------[ cut here ]------------ kernel BUG at /usr/src/linux-2.6.22.1-10/net/sunrpc/xdr.c:480! Oops: Exception in kernel mode, sig: 5 [#1] XDR is trying to reserve 760 bytes in the XDR Buffer which has a capacity fo 560, out of which 124 bytes are already occupied. Debugging further. Thanks Suzuki Created an attachment (id=30498) --> (https://bugzilla.novell.com/attachment.cgi?id=30498) Debug patch to find who is exceeding the buffer limits We are facing a problem with buffer running out. This could be either from the RPC headers which gets added before the control reaches the NFS code or may be from the NFS code itself. The attached debug patch will detect if the RPC is exceeding its limits. Omar, Could you please run the tests with the two debug patches ? ( including this one and the previous one ) Please let us know the test results. Thanks Suzuki The problem was hit again : Aug 21 17:18:37 p630b kernel: xdr_reserve_space : FAILs : P: c0000001ef152884, nbytes: 468, xdr.buflen: 560, current len : 124 Aug 21 17:18:37 p630b kernel: ------------[ cut here ]------------ Aug 21 17:18:37 p630b kernel: kernel BUG at /usr/src/linux-2.6.22.1-16/net/sunrpc/xdr.c:480! With the debug kernel. This indicates that, the NFS is passing a larger data to encode which can not be held in the buffer. Debugging further. Thanks Suzuki I have built a new kernel with probes to check if the NFS is not checking the size of the name being looked up/opened. Will update the test results. Thanks Suzuki Created an attachment (id=30570) --> (https://bugzilla.novell.com/attachment.cgi?id=30570) var-log-message Hi suzuki, (In reply to comment #15)

I have built a new kernel with probes to check if the NFS is not checking the

size of the name being looked up/opened.

New build kernel throws Aug 22 11:48:19 p630b kernel: kernel BUG at /usr/src/linux-2.6.22.1-16/net/sunrpc/xdr.c:480! Aug 22 11:48:19 p630b kernel: Oops: Exception in kernel mode, sig: 5 [#1] Aug 22 11:48:19 p630b kernel: SMP NR_CPUS=128 NUMA pSeries Aug 22 11:48:20 p630b kernel: Modules linked in: nfs ipv6 nfsd exportfs nfs_acl lockd sunrpc apparmor loop dm_mod fuse e100 mii sg sd_mod sym53c8xx scsi_transport_spi pata_sl82c105 libata scsi_mod Aug 22 11:48:20 p630b kernel: NIP: d0000000006e6a08 LR: d0000000006e6a04 CTR: 0000000000000001 Aug 22 11:48:20 p630b kernel: REGS: c0000001e6142fa0 TRAP: 0700 Tainted: G N (2.6.22.1-16-debug) Aug 22 11:48:20 p630b kernel: MSR: 9000000000029032 CR: 28008424 XER: 00000000 --thanks -omar Here is the debug information that I got from the debug probes. As you can see, we are trying to pass large names for file/dir, which is not checked anywhere else. Aug 22 11:48:16 p630b kernel: nfs4 lookup: name too large(285) : lfXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX Aug 22 11:48:16 p630b kernel: Call Trace: Aug 22 11:48:16 p630b kernel: [c0000001e611f800] [c00000000000f33c] show_stack+0x68/0x1b0 (unreliable) Aug 22 11:48:16 p630b kernel: [c0000001e611f8a0] [d000000000905328] nfs4_proc_lookup+0x7c/0x2f0 [nfs] Aug 22 11:48:16 p630b kernel: [c0000001e611f9c0] [d0000000008e892c] nfs_lookup+0x158/0x33c [nfs] Aug 22 11:48:16 p630b kernel: [c0000001e611fbc0] [c000000000101ab0] lookup_hash+0xfc/0x140 Aug 22 11:48:16 p630b kernel: [c0000001e611fc60] [c000000000104388] sys_renameat+0x164/0x230 Aug 22 11:48:16 p630b kernel: [c0000001e611fe30] [c0000000000086c8] syscall_exit+0x0/0x40 Aug 22 11:48:18 p630b kernel: nfs4 open: Name too long to encode : 799 ( f1XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX ) Aug 22 11:48:18 p630b kernel: Call Trace: Aug 22 11:48:18 p630b kernel: [c0000001e6143330] [c00000000000f33c] show_stack+0x68/0x1b0 (unreliable) Aug 22 11:48:18 p630b kernel: [c0000001e61433d0] [d00000000090f900] nfs4_xdr_enc_open+0x70/0x138 [nfs] Aug 22 11:48:18 p630b kernel: [c0000001e61434b0] [d0000000006db6a8] rpcauth_wrap_req+0xd8/0x108 [sunrpc] Aug 22 11:48:18 p630b kernel: [c0000001e6143560] [d0000000006d26f8] call_transmit+0x298/0x34c [sunrpc] Aug 22 11:48:18 p630b kernel: [c0000001e6143610] [d0000000006da3a4] __rpc_execute+0xd4/0x35c [sunrpc] Aug 22 11:48:18 p630b kernel: [c0000001e61436b0] [d0000000006da6d0] rpc_run_task+0x54/0x70 [sunrpc] Aug 22 11:48:18 p630b kernel: [c0000001e6143740] [d000000000904a44] _nfs4_proc_open+0x70/0x238 [nfs] Aug 22 11:48:18 p630b kernel: [c0000001e61437f0] [d000000000904f30] nfs4_do_open+0xe8/0x208 [nfs] Aug 22 11:48:18 p630b kernel: [c0000001e61438c0] [d0000000009069a4] nfs4_atomic_open+0xd8/0x19c [nfs] Aug 22 11:48:18 p630b kernel: [c0000001e61439c0] [d0000000008ea50c] nfs_atomic_lookup+0x128/0x228 [nfs] Aug 22 11:48:19 p630b kernel: [c0000001e6143a60] [c000000000101ab0] lookup_hash+0xfc/0x140 Aug 22 11:48:19 p630b kernel: [c0000001e6143b00] [c0000000001050f8] open_namei+0x134/0x86c Aug 22 11:48:19 p630b kernel: [c0000001e6143bf0] [c0000000000f3848] do_filp_open+0x38/0x70 Aug 22 11:48:19 p630b kernel: [c0000001e6143d10] [c0000000000f38f4] do_sys_open+0x74/0x130 Aug 22 11:48:19 p630b kernel: [c0000001e6143dc0] [c000000000015270] compat_sys_creat+0x14/0x28 Aug 22 11:48:19 p630b kernel: [c0000001e6143e30] [c0000000000086c8] syscall_exit+0x0/0x40 Created an attachment (id=30651) --> (https://bugzilla.novell.com/attachment.cgi?id=30651) dmesg-output suzuki , check the logs for yesterdays test. thanks --omar Hi, I believe this is due to a bug in the NFS server information. As you can see : nfs4 lookup: name too large(436) : server: -1, The server is the namelen permitted by the server, which is -1 !!! So something is going wrong with the Server connection. Debugging further. Thanks Suzuki log-message for debugged kernel. Aug 24 16:52:36 p630b kernel: ------------[ cut here ]------------ Aug 24 16:52:36 p630b kernel: kernel BUG at /usr/src/linux-2.6.22.1-16/fs/nfs/client.c:729! Aug 24 16:52:36 p630b kernel: Oops: Exception in kernel mode, sig: 5 [#1] Aug 24 16:52:36 p630b kernel: SMP NR_CPUS=128 NUMA pSeries Aug 24 16:52:36 p630b kernel: Modules linked in: nfs ipv6 nfsd exportfs nfs_acl lockd sunrpc apparmor loop dm_mod fuse e100 mii sg sd_mod sym53c8xx scsi_transport_spi pata_sl82c105 libata scsi_mod Aug 24 16:52:36 p630b kernel: NIP: d0000000008e5c48 LR: d0000000008e5c44 CTR: c0000000000955a4 Aug 24 16:52:36 p630b kernel: REGS: c0000000fbe3b290 TRAP: 0700 Tainted: G N (2.6.22.1-16-debug) Aug 24 16:52:36 p630b kernel: MSR: 9000000000029032 CR: 24008484 XER: 00000000 Aug 24 16:52:36 p630b kernel: TASK = c000000005aea040[3888] 'mount.nfs4' THREAD: c0000000fbe38000 CPU: 0 Aug 24 16:52:36 p630b kernel: GPR00: d0000000008e5c44 c0000000fbe3b510 d00000000094e920 0000000000000033 Aug 24 16:52:36 p630b kernel: GPR04: 0000000000000000 0000000000000000 0000000000000000 0000000000000000 Aug 24 16:52:36 p630b kernel: GPR08: c000000004048090 c00000000071c478 c000000004e33bf8 0000000000000000 Aug 24 16:52:36 p630b kernel: GPR12: 000000000000000a c0000000005b6880 0000000000000000 0000000000000000 Aug 24 16:52:36 p630b kernel: GPR16: 0000000000000000 0000000000000000 0000000000000000 0000000000000003 Aug 24 16:52:36 p630b kernel: GPR20: 0000000000000000 0000000000000000 c0000001fe6ef5a0 0000000000000001 Aug 24 16:52:36 p630b kernel: GPR24: c0000000fbe3b824 d0000000007169c4 c0000000fbe3b824 c0000000fbe3b670 Aug 24 16:52:36 p630b kernel: GPR28: c0000001fe629c00 c00000010392e880 d000000000948f00 0000000000000000 Aug 24 16:52:36 p630b kernel: NIP [d0000000008e5c48] nfs_probe_fsinfo+0x5c0/0x670 [nfs] Aug 24 16:52:36 p630b kernel: LR [d0000000008e5c44] nfs_probe_fsinfo+0x5bc/0x670 [nfs] Aug 24 16:52:36 p630b kernel: Call Trace: Aug 24 16:52:36 p630b kernel: [c0000000fbe3b510] [d0000000008e5c44] nfs_probe_fsinfo+0x5bc/0x670 [nfs] (unreliable) Aug 24 16:52:36 p630b kernel: [c0000000fbe3b600] [d0000000008e75bc] nfs4_create_server+0x30c/0x47c [nfs] Aug 24 16:52:36 p630b kernel: [c0000000fbe3b790] [d0000000008f131c] nfs4_get_sb+0x258/0x39c [nfs] Aug 24 16:52:36 p630b kernel: [c0000000fbe3b910] [c0000000000f82dc] vfs_kern_mount+0xf0/0x1dc Aug 24 16:52:36 p630b kernel: [c0000000fbe3b9c0] [c0000000000f8438] do_kern_mount+0x60/0x144 Aug 24 16:52:36 p630b kernel: --- Exception: 301 at copy_mount_options+0xf8/0x1ac Aug 24 16:52:36 p630b kernel: LR = .copy_mount_options+0xf0/0x1ac Aug 24 16:52:36 p630b kernel: [c0000000fbe3ba70] [c000000000116390] do_mount+0x740/0x7e8 (unreliable) Aug 24 16:52:36 p630b kernel: [c0000000fbe3bd60] [c0000000001384e0] compat_sys_mount+0x228/0x2a4 Aug 24 16:52:36 p630b kernel: [c0000000fbe3be30] [c0000000000086c8] syscall_exit+0x0/0x40 Aug 24 16:52:36 p630b kernel: Instruction dump: Aug 24 16:52:36 p630b kernel: 4e800421 e8410028 2f830000 419c002c 8001007c 2b8000ff 78040020 909d00b4 Aug 24 16:52:36 p630b kernel: 409d0018 e87e80d8 48031311 e8410028 <0fe00000> 48000000 e93e80a0 3be00000 thanks --omar The problem is coming from the server side metadata information passed to the client : NFS Server has invalid namelen set : 4294967295 ( 0xffffffff = (int) -1 ) which allows to pass the lookup/open requests containing filenames <= the value above, which leads to a ENOSPC buffer problem. Debugging the NFS server. Thanks Suzuki I have found the root cause of the problem in the nfs4 client code : The problem is with the nfs_create_server code while trying to get the server handle. This problem occurs only if the mounting remote-directory is "/". In this case we don't try to get the file handle properly. I am testing a patch to fix the issue. Thanks Suzuki The NFS4 (at least nfs4) client does the following : 1) get the root dir handle for the remote server ( which would work fine ) 2) try to get the file handle for each directory in the path using lookup requests. for eg: mount -t nfs4 server:/IMAGES/Server/Linux tmp then: there will be a root handle lookup and then followed by lookup requests for IMAGES, Server & Linux. Now while trying to get the file handles for each of these components, the "/" are *eaten up* to avoid the server overheads. Here if we specify "/" as the remote server dir, the path is completely eaten up and hence, the client thinks that it has successfully finished finding the file handle for the remote directory and returns. But we haven't established a proper server connection with the server nor we have a proper file handle ! Now the bug submitter was trying : mount -t nfs4 <server>:/ <DIR> where the "/" dir was not exported at all ! Now the "/" path makes the client think that it has got a proper connection with the server and forwards the requests to the server. Due to the lack of proper initialization, the max_namelen allowed for the files is set to -1 (which is stored as unsigned int) in the client side. So, this makes any lookup /open requests to just pass through to the nfs server. But while trying to encode the request we run out of space for large names. The fix here would be to get the file handle for "/" also, to decide whether that particular directory is exported or not ! Will attach the patch later Thanks Suzuki It seems the mounting semantics is entirely different in NFS4, when compared to the previous versions. Reading through the NFS4 protocol ( RFC ) to get more information on what should be the ideal behaviour. Thanks Suzuki Created an attachment (id=31146) --> (https://bugzilla.novell.com/attachment.cgi?id=31146) Patch to fix the problem Hi, Omar has verified this patch on p630b to fix the problem that we have been facing. Thanks Suzuki -- Configure bugmail: https://bugzilla.novell.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are on the CC list for the bug.