Bug 763340 (GLUSTER-1608)

Summary: stat fop on dir returns ENOENT from server-resolution path
Product: [Community] GlusterFS Reporter: Shehjar Tikoo <shehjart>
Component: protocolAssignee: Shehjar Tikoo <shehjart>
Status: CLOSED CURRENTRELEASE QA Contact:
Severity: high Docs Contact:
Priority: low    
Version: 3.1-alphaCC: amarts, gluster-bugs, lakshmipathi
Target Milestone: ---   
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: Type: ---
Regression: RTP Mount Type: nfs
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Shehjar Tikoo 2010-09-15 08:15:28 UTC
In resolve_entry_simple, we can see pargfid consisting of all 0s.


[2010-09-15 16:43:19.304402] E [server-resolve.c:154:resolve_deep_continue] nfs-4d3r-triple-server: entry simple
[2010-09-15 16:43:19.304413] T [server-resolve.c:340:resolve_entry_simple] FHSTR: 00000000-0000-0000-0000-000000000000
[2010-09-15 16:43:19.304423] D [server-resolve.c:166:resolve_deep_continue] nfs-4d3r-triple-server: return value of resolve_*_simple 1
[2010-09-15 16:43:19.304448] D [server3_1-fops.c:1479:server_stat_cbk] nfs-4d3r-triple-server: 29350: STAT /s4882 (0) ==> -1 (No such file or directory)

Comment 1 Shehjar Tikoo 2010-09-15 11:07:37 UTC
At the nfs server, the request-reply for the fop is shown below:

[2010-09-15 16:32:06.165450] D [nfs3-helpers.c:2228:nfs3_log_common_call] nfs-nfsv3: XID: c0d4477c, ACCESS: args: FH: hashcount 1, exportid 00000000-0000-
0000-000000000000, gfid 0ec76fb9-56fa-4648-b987-ec998ed21ff3
[2010-09-15 16:32:06.165462] T [nfs3.c:1356:nfs3_access] nfs-nfsv3: FH to Volume: 4dist-master
[2010-09-15 16:32:06.165471] T [nfs3-helpers.c:3029:nfs3_fh_resolve_inode] nfs-nfsv3: FH needs inode resolution
[2010-09-15 16:32:06.165480] T [nfs3-helpers.c:2478:nfs3_fh_resolve_inode_done] nfs-nfsv3: FH inode resolved
[2010-09-15 16:32:06.165491] T [nfs.c:410:nfs_user_create] nfs: uid: 0, gid 0, gids: 7
[2010-09-15 16:32:06.165499] T [nfs.c:418:nfs_user_create] nfs: gid: 0
[2010-09-15 16:32:06.165507] T [nfs.c:418:nfs_user_create] nfs: gid: 1
[2010-09-15 16:32:06.165514] T [nfs.c:418:nfs_user_create] nfs: gid: 2
[2010-09-15 16:32:06.165522] T [nfs.c:418:nfs_user_create] nfs: gid: 3
[2010-09-15 16:32:06.165529] T [nfs.c:418:nfs_user_create] nfs: gid: 4
[2010-09-15 16:32:06.165536] T [nfs.c:418:nfs_user_create] nfs: gid: 6
[2010-09-15 16:32:06.165544] T [nfs.c:418:nfs_user_create] nfs: gid: 10
[2010-09-15 16:32:06.165552] T [nfs-fops.c:374:nfs_fop_stat] nfs: Stat: /s4906
[2010-09-15 16:32:06.165560] T [nfs-fops.c:133:nfs_create_frame] nfs: uid: 0, gid 0, gids: 7
[2010-09-15 16:32:06.165568] T [nfs-fops.c:135:nfs_create_frame] nfs: gid: 0
[2010-09-15 16:32:06.165575] T [nfs-fops.c:135:nfs_create_frame] nfs: gid: 1
[2010-09-15 16:32:06.165583] T [nfs-fops.c:135:nfs_create_frame] nfs: gid: 2
[2010-09-15 16:32:06.165590] T [nfs-fops.c:135:nfs_create_frame] nfs: gid: 3
[2010-09-15 16:32:06.165597] T [nfs-fops.c:135:nfs_create_frame] nfs: gid: 4
[2010-09-15 16:32:06.165605] T [nfs-fops.c:135:nfs_create_frame] nfs: gid: 6
[2010-09-15 16:32:06.165612] T [nfs-fops.c:135:nfs_create_frame] nfs: gid: 10
[2010-09-15 16:32:06.165627] T [rpc-clnt.c:1198:rpc_clnt_record] : Auth Info: pid: 0, uid: 0, gid: 0, owner: 17479
[2010-09-15 16:32:06.165637] T [rpc-clnt.c:1098:rpc_clnt_record_build_header] rpc-clnt: Request fraglen 228, payload: 100, rpc hdr: 128
[2010-09-15 16:32:06.165658] T [rpc-clnt.c:1198:rpc_clnt_record] : Auth Info: pid: 0, uid: 0, gid: 0, owner: 17479
[2010-09-15 16:32:06.165668] T [rpc-clnt.c:1098:rpc_clnt_record_build_header] rpc-clnt: Request fraglen 228, payload: 100, rpc hdr: 128
[2010-09-15 16:32:06.165689] T [rpc-clnt.c:1198:rpc_clnt_record] : Auth Info: pid: 0, uid: 0, gid: 0, owner: 17479
[2010-09-15 16:32:06.165699] T [rpc-clnt.c:1098:rpc_clnt_record_build_header] rpc-clnt: Request fraglen 228, payload: 100, rpc hdr: 128
[2010-09-15 16:32:06.165754] T [rpc-clnt.c:1198:rpc_clnt_record] : Auth Info: pid: 0, uid: 0, gid: 0, owner: 17479
[2010-09-15 16:32:06.165765] T [rpc-clnt.c:1098:rpc_clnt_record_build_header] rpc-clnt: Request fraglen 228, payload: 100, rpc hdr: 128
[2010-09-15 16:32:06.166256] T [rpc-clnt.c:624:rpc_clnt_reply_init] rpc-clnt: RPC XID: 30260 Program: GlusterFS 3.1, ProgVers: 310, Proc: 1
[2010-09-15 16:32:06.166277] D [dht-common.c:993:dht_attr_cbk] 4dist-master: subvolume rhel5-73-e1 returned -1 (No such file or directory)
[2010-09-15 16:32:06.166315] T [rpc-clnt.c:624:rpc_clnt_reply_init] rpc-clnt: RPC XID: 30133 Program: GlusterFS 3.1, ProgVers: 310, Proc: 1
[2010-09-15 16:32:06.166328] D [dht-common.c:993:dht_attr_cbk] 4dist-master: subvolume centos5-70-e1 returned -1 (No such file or directory)
[2010-09-15 16:32:06.166371] T [rpc-clnt.c:624:rpc_clnt_reply_init] rpc-clnt: RPC XID: 30182 Program: GlusterFS 3.1, ProgVers: 310, Proc: 1
[2010-09-15 16:32:06.166385] D [dht-common.c:993:dht_attr_cbk] 4dist-master: subvolume ub8-71-e1 returned -1 (No such file or directory)
[2010-09-15 16:32:06.166412] T [rpc-clnt.c:624:rpc_clnt_reply_init] rpc-clnt: RPC XID: 30364 Program: GlusterFS 3.1, ProgVers: 310, Proc: 1
[2010-09-15 16:32:06.166423] D [dht-common.c:993:dht_attr_cbk] 4dist-master: subvolume ub10-72-e1 returned -1 (No such file or directory)
[2010-09-15 16:32:06.166435] D [nfs3-helpers.c:2360:nfs3_log_common_res] nfs-nfsv3: XID: c0d4477c, ACCESS: NFS: 2(No such file or directory), POSIX: 2(No such 
file or directory)


At the bricks, the log shows that the server resolution code is where the ENOENT is coming from:
[2010-09-15 16:32:06.165847] T [rpcsvc.c:723:rpcsvc_program_actor] rpc-service: Actor found: GlusterFS-3.1.0 - STAT
[2010-09-15 16:32:06.165866] T [server-resolve.c:246:resolve_path_deep] export1-master: RESOLVE STAT() seeking deep resolution of /s4906
[2010-09-15 16:32:06.165941] D [dict.c:330:dict_get] (-->/home/shehjart/glusterfsd-master//lib/libglusterfs.so.0(call_resume+0xc3e) [0x2abc38dd8e0e] (-->/home/
shehjart/glusterfsd-master//lib/glusterfs/3.1.0git/xlator/performance/io-threads.so(iot_lookup_wrapper+0xf2) [0x2aaaab0ed232] (-->/home/shehjart/glusterfsd-mas
ter//lib/glusterfs/3.1.0git/xlator/features/locks.so(pl_lookup+0x78) [0x2aaaaaed7698]))) dict: @this=(nil) key=glusterfs.entrylk-count
[2010-09-15 16:32:06.165977] D [dict.c:330:dict_get] (-->/home/shehjart/glusterfsd-master//lib/libglusterfs.so.0(call_resume+0xc3e) [0x2abc38dd8e0e] (-->/home/
shehjart/glusterfsd-master//lib/glusterfs/3.1.0git/xlator/performance/io-threads.so(iot_lookup_wrapper+0xf2) [0x2aaaab0ed232] (-->/home/shehjart/glusterfsd-mas
ter//lib/glusterfs/3.1.0git/xlator/features/locks.so(pl_lookup+0x92) [0x2aaaaaed76b2]))) dict: @this=(nil) key=glusterfs.inodelk-count
[2010-09-15 16:32:06.166009] D [dict.c:330:dict_get] (-->/home/shehjart/glusterfsd-master//lib/libglusterfs.so.0(call_resume+0xc3e) [0x2abc38dd8e0e] (-->/home shehjart/glusterfsd-master//lib/glusterfs/3.1.0git/xlator/performance/io-threads.so(iot_lookup_wrapper+0xf2) [0x2aaaab0ed232] (-->/home/shehjart/glusterfsd-ma ter//lib/glusterfs/3.1.0git/xlator/features/locks.so(pl_lookup+0xad) [0x2aaaaaed76cd]))) dict: @this=(nil) key=glusterfs.posixlk-count
[2010-09-15 16:32:06.166061] D [dict.c:330:dict_get] (-->/home/shehjart/glusterfsd-master//lib/libglusterfs.so.0(call_resume+0xc3e) [0x2abc38dd8e0e] (-->/home shehjart/glusterfsd-master//lib/glusterfs/3.1.0git/xlator/performance/io-threads.so(iot_lookup_wrapper+0xf2) [0x2aaaab0ed232] (-->/home/shehjart/glusterfsd-ma ter//lib/glusterfs/3.1.0git/xlator/features/locks.so(pl_lookup+0x78) [0x2aaaaaed7698]))) dict: @this=(nil) key=glusterfs.entrylk-count
[2010-09-15 16:32:06.166093] D [dict.c:330:dict_get] (-->/home/shehjart/glusterfsd-master//lib/libglusterfs.so.0(call_resume+0xc3e) [0x2abc38dd8e0e] (-->/home shehjart/glusterfsd-master//lib/glusterfs/3.1.0git/xlator/performance/io-threads.so(iot_lookup_wrapper+0xf2) [0x2aaaab0ed232] (-->/home/shehjart/glusterfsd-ma ter//lib/glusterfs/3.1.0git/xlator/features/locks.so(pl_lookup+0x92) [0x2aaaaaed76b2]))) dict: @this=(nil) key=glusterfs.inodelk-count
[2010-09-15 16:32:06.166134] D [dict.c:330:dict_get] (-->/home/shehjart/glusterfsd-master//lib/libglusterfs.so.0(call_resume+0xc3e) [0x2abc38dd8e0e] (-->/home shehjart/glusterfsd-master//lib/glusterfs/3.1.0git/xlator/performance/io-threads.so(iot_lookup_wrapper+0xf2) [0x2aaaab0ed232] (-->/home/shehjart/glusterfsd-ma ter//lib/glusterfs/3.1.0git/xlator/features/locks.so(pl_lookup+0xad) [0x2aaaaaed76cd]))) dict: @this=(nil) key=glusterfs.posixlk-count
[2010-09-15 16:32:06.166169] E [server-resolve.c:154:resolve_deep_continue] nfs-4d3r-triple-server: entry simple
[2010-09-15 16:32:06.166180] D [server-resolve.c:166:resolve_deep_continue] nfs-4d3r-triple-server: return value of resolve_*_simple 1
[2010-09-15 16:32:06.166192] D [server3_1-fops.c:1479:server_stat_cbk] nfs-4d3r-triple-server: 30260: STAT /s4906 (0) ==> -1 (No such file or directory)

Comment 2 Shehjar Tikoo 2010-09-16 05:34:46 UTC
Following the two patches submitted for this, latest runs still fail with distribute returning ESTALE to gnfs for a directory:

Relevant log for MKDIR:
[2010-09-16 13:46:27.691407] D [nfs3-helpers.c:2238:nfs3_log_fh_entry_call] nfs-nfsv3: XID: 3eebc1d3, MKDIR: args: FH: hashcount 0, exportid 00000000-0000-0000
-0000-000000000000, gfid 00000000-0000-0000-0000-000000000001, name: s3215
[2010-09-16 13:46:27.691458] T [nfs3.c:2608:nfs3_mkdir] nfs-nfsv3: FH to Volume: 4dist-master
[2010-09-16 13:46:27.691473] T [nfs3-helpers.c:2994:nfs3_fh_resolve_entry_hard] nfs-nfsv3: FH hard resolution: gfid: 00000000-0000-0000-0000-000000000001 , ent
ry: s3215, hashidx: 0
[2010-09-16 13:46:27.691486] T [nfs3-helpers.c:3002:nfs3_fh_resolve_entry_hard] nfs-nfsv3: Entry needs lookup: /s3215
[2010-09-16 13:46:27.691504] T [nfs-fops.c:326:nfs_fop_lookup] nfs: Lookup: /s3215
[2010-09-16 13:46:27.691538] T [rpc-clnt.c:1203:rpc_clnt_record] : Auth Info: pid: 0, uid: 0, gid: 0, owner: 0
[2010-09-16 13:46:27.691572] T [rpc-clnt.c:1103:rpc_clnt_record_build_header] rpc-clnt: Request fraglen 312, payload: 184, rpc hdr: 128
[2010-09-16 13:46:27.691837] T [rpc-clnt.c:624:rpc_clnt_reply_init] rpc-clnt: RPC XID: 13697 Program: GlusterFS 3.1, ProgVers: 310, Proc: 27
[2010-09-16 13:46:27.691859] T [rpc-clnt.c:1203:rpc_clnt_record] : Auth Info: pid: 0, uid: 0, gid: 0, owner: 0
[2010-09-16 13:46:27.691869] T [rpc-clnt.c:1103:rpc_clnt_record_build_header] rpc-clnt: Request fraglen 312, payload: 184, rpc hdr: 128
[2010-09-16 13:46:27.691890] T [rpc-clnt.c:1203:rpc_clnt_record] : Auth Info: pid: 0, uid: 0, gid: 0, owner: 0
[2010-09-16 13:46:27.691900] T [rpc-clnt.c:1103:rpc_clnt_record_build_header] rpc-clnt: Request fraglen 312, payload: 184, rpc hdr: 128
[2010-09-16 13:46:27.691918] T [rpc-clnt.c:1203:rpc_clnt_record] : Auth Info: pid: 0, uid: 0, gid: 0, owner: 0
[2010-09-16 13:46:27.691927] T [rpc-clnt.c:1103:rpc_clnt_record_build_header] rpc-clnt: Request fraglen 312, payload: 184, rpc hdr: 128
[2010-09-16 13:46:27.691944] T [rpc-clnt.c:1203:rpc_clnt_record] : Auth Info: pid: 0, uid: 0, gid: 0, owner: 0
[2010-09-16 13:46:27.691954] T [rpc-clnt.c:1103:rpc_clnt_record_build_header] rpc-clnt: Request fraglen 312, payload: 184, rpc hdr: 128
[2010-09-16 13:46:27.692229] T [rpc-clnt.c:624:rpc_clnt_reply_init] rpc-clnt: RPC XID: 13698 Program: GlusterFS 3.1, ProgVers: 310, Proc: 27
[2010-09-16 13:46:27.692281] T [rpc-clnt.c:624:rpc_clnt_reply_init] rpc-clnt: RPC XID: 13694 Program: GlusterFS 3.1, ProgVers: 310, Proc: 27
[2010-09-16 13:46:27.692302] T [rpc-clnt.c:624:rpc_clnt_reply_init] rpc-clnt: RPC XID: 13726 Program: GlusterFS 3.1, ProgVers: 310, Proc: 27
[2010-09-16 13:46:27.692318] T [rpc-clnt.c:624:rpc_clnt_reply_init] rpc-clnt: RPC XID: 13729 Program: GlusterFS 3.1, ProgVers: 310, Proc: 27
[2010-09-16 13:46:27.692330] T [nfs3-helpers.c:2553:nfs3_fh_resolve_entry_lookup_cbk] nfs-nfsv3: Lookup failed: /s3215: No such file or directory
[2010-09-16 13:46:27.692340] T [nfs.c:410:nfs_user_create] nfs: uid: 0, gid 0, gids: 7
[2010-09-16 13:46:27.692349] T [nfs.c:418:nfs_user_create] nfs: gid: 0
[2010-09-16 13:46:27.692357] T [nfs.c:418:nfs_user_create] nfs: gid: 1
[2010-09-16 13:46:27.692365] T [nfs.c:418:nfs_user_create] nfs: gid: 2
[2010-09-16 13:46:27.692372] T [nfs.c:418:nfs_user_create] nfs: gid: 3
[2010-09-16 13:46:27.692380] T [nfs.c:418:nfs_user_create] nfs: gid: 4
[2010-09-16 13:46:27.692388] T [nfs.c:418:nfs_user_create] nfs: gid: 6
[2010-09-16 13:46:27.692388] T [nfs.c:418:nfs_user_create] nfs: gid: 6
[2010-09-16 13:46:27.692395] T [nfs.c:418:nfs_user_create] nfs: gid: 10
[2010-09-16 13:46:27.692408] T [nfs-fops.c:747:nfs_fop_mkdir] nfs: Mkdir: /s3215
[2010-09-16 13:46:27.692417] T [nfs-fops.c:133:nfs_create_frame] nfs: uid: 0, gid 0, gids: 7
[2010-09-16 13:46:27.692426] T [nfs-fops.c:135:nfs_create_frame] nfs: gid: 0
[2010-09-16 13:46:27.692434] T [nfs-fops.c:135:nfs_create_frame] nfs: gid: 1
[2010-09-16 13:46:27.692441] T [nfs-fops.c:135:nfs_create_frame] nfs: gid: 2
[2010-09-16 13:46:27.692449] T [nfs-fops.c:135:nfs_create_frame] nfs: gid: 3
[2010-09-16 13:46:27.692456] T [nfs-fops.c:135:nfs_create_frame] nfs: gid: 4
[2010-09-16 13:46:27.692464] T [nfs-fops.c:135:nfs_create_frame] nfs: gid: 6
[2010-09-16 13:46:27.692472] T [nfs-fops.c:135:nfs_create_frame] nfs: gid: 10
[2010-09-16 13:46:27.692498] T [rpc-clnt.c:1203:rpc_clnt_record] : Auth Info: pid: 0, uid: 0, gid: 0, owner: 6455
[2010-09-16 13:46:27.692508] T [rpc-clnt.c:1103:rpc_clnt_record_build_header] rpc-clnt: Request fraglen 224, payload: 96, rpc hdr: 128
[2010-09-16 13:46:27.692806] T [rpc-clnt.c:624:rpc_clnt_reply_init] rpc-clnt: RPC XID: 13699 Program: GlusterFS 3.1, ProgVers: 310, Proc: 4
[2010-09-16 13:46:27.692824] T [dht-layout.c:355:dht_layout_merge] 4dist-master: missing disk layout on rhel5-73-e1. err = -1
[2010-09-16 13:46:27.692839] T [rpc-clnt.c:1203:rpc_clnt_record] : Auth Info: pid: 0, uid: 0, gid: 0, owner: 6455
[2010-09-16 13:46:27.692849] T [rpc-clnt.c:1103:rpc_clnt_record_build_header] rpc-clnt: Request fraglen 224, payload: 96, rpc hdr: 128
[2010-09-16 13:46:27.692869] T [rpc-clnt.c:1203:rpc_clnt_record] : Auth Info: pid: 0, uid: 0, gid: 0, owner: 6455
[2010-09-16 13:46:27.692879] T [rpc-clnt.c:1103:rpc_clnt_record_build_header] rpc-clnt: Request fraglen 224, payload: 96, rpc hdr: 128
[2010-09-16 13:46:27.692896] T [rpc-clnt.c:1203:rpc_clnt_record] : Auth Info: pid: 0, uid: 0, gid: 0, owner: 6455
[2010-09-16 13:46:27.692906] T [rpc-clnt.c:1103:rpc_clnt_record_build_header] rpc-clnt: Request fraglen 224, payload: 96, rpc hdr: 128
[2010-09-16 13:46:27.693283] T [rpc-clnt.c:624:rpc_clnt_reply_init] rpc-clnt: RPC XID: 13695 Program: GlusterFS 3.1, ProgVers: 310, Proc: 4
[2010-09-16 13:46:27.693313] T [dht-layout.c:355:dht_layout_merge] 4dist-master: missing disk layout on ub10-72-e1. err = -1
[2010-09-16 13:46:27.693335] T [rpc-clnt.c:624:rpc_clnt_reply_init] rpc-clnt: RPC XID: 13727 Program: GlusterFS 3.1, ProgVers: 310, Proc: 4
[2010-09-16 13:46:27.693355] T [dht-layout.c:355:dht_layout_merge] 4dist-master: missing disk layout on centos5-70-e1. err = -1
[2010-09-16 13:46:27.693373] T [rpc-clnt.c:624:rpc_clnt_reply_init] rpc-clnt: RPC XID: 13730 Program: GlusterFS 3.1, ProgVers: 310, Proc: 4
[2010-09-16 13:46:27.693384] T [dht-layout.c:355:dht_layout_merge] 4dist-master: missing disk layout on ub8-71-e1. err = -1
[2010-09-16 13:46:27.693394] T [dht-selfheal.c:354:dht_selfheal_layout_new_directory] 4dist-master: gave fix: 0 - 1073741822 on ub8-71-e1 for /s3215
15
[2010-09-16 13:46:27.693412] T [dht-selfheal.c:373:dht_selfheal_layout_new_directory] 4dist-master: gave fix: 2147483646 - 3221225468 on rhel5-73-e1 for /s3215
[2010-09-16 13:46:27.693421] T [dht-selfheal.c:373:dht_selfheal_layout_new_directory] 4dist-master: gave fix: 3221225469 - 4294967291 on ub10-72-e1 for /s3215
[2010-09-16 13:46:27.693430] T [dht-selfheal.c:173:dht_selfheal_dir_xattr] 4dist-master: 4 subvolumes missing xattr for /s3215
lume centos5-70-e1 for /s3215
[2010-09-16 13:46:27.693494] T [rpc-clnt.c:1203:rpc_clnt_record] : Auth Info: pid: 0, uid: 0, gid: 0, owner: 6455
[2010-09-16 13:46:27.693505] T [rpc-clnt.c:1103:rpc_clnt_record_build_header] rpc-clnt: Request fraglen 224, payload: 96, rpc hdr: 128
lume rhel5-73-e1 for /s3215
[2010-09-16 13:46:27.693538] T [rpc-clnt.c:1203:rpc_clnt_record] : Auth Info: pid: 0, uid: 0, gid: 0, owner: 6455
[2010-09-16 13:46:27.693547] T [rpc-clnt.c:1103:rpc_clnt_record_build_header] rpc-clnt: Request fraglen 224, payload: 96, rpc hdr: 128
[2010-09-16 13:46:27.693526] T [dht-selfheal.c:124:dht_selfheal_dir_xattr_persubvol] 4dist-master: setting hash range 2147483646 - 3221225468 (t
lume rhel5-73-e1 for /s3215
[2010-09-16 13:46:27.693538] T [rpc-clnt.c:1203:rpc_clnt_record] : Auth Info: pid: 0, uid: 0, gid: 0, owner: 6455
[2010-09-16 13:46:27.693547] T [rpc-clnt.c:1103:rpc_clnt_record_build_header] rpc-clnt: Request fraglen 224, payload: 96, rpc hdr: 128
[2010-09-16 13:46:27.693569] T [dht-selfheal.c:124:dht_selfheal_dir_xattr_persubvol] 4dist-master: setting hash range 3221225469 - 4294967295 (t
lume ub10-72-e1 for /s3215
[2010-09-16 13:46:27.693581] T [rpc-clnt.c:1203:rpc_clnt_record] : Auth Info: pid: 0, uid: 0, gid: 0, owner: 6455
[2010-09-16 13:46:27.693590] T [rpc-clnt.c:1103:rpc_clnt_record_build_header] rpc-clnt: Request fraglen 224, payload: 96, rpc hdr: 128
[2010-09-16 13:46:27.693606] T [dht-selfheal.c:124:dht_selfheal_dir_xattr_persubvol] 4dist-master: setting hash range 0 - 1073741822 (type 0) on
71-e1 for /s32156:27.693581] T [rpc-clnt.c:1203:rpc_clnt_record] : Auth Info: pid: 0, uid: 0, gid: 0, owner: 6455
[2010-09-16 13:46:27.693682] T [rpc-clnt.c:1203:rpc_clnt_record] : Auth Info: pid: 0, uid: 0, gid: 0, owner: 6455
[2010-09-16 13:46:27.693695] T [rpc-clnt.c:1103:rpc_clnt_record_build_header] rpc-clnt: Request fraglen 224, payload: 96, rpc hdr: 128
[2010-09-16 13:46:27.694237] T [rpc-clnt.c:624:rpc_clnt_reply_init] rpc-clnt: RPC XID: 13700 Program: GlusterFS 3.1, ProgVers: 310, Proc: 17
[2010-09-16 13:46:27.694259] T [rpc-clnt.c:624:rpc_clnt_reply_init] rpc-clnt: RPC XID: 13728 Program: GlusterFS 3.1, ProgVers: 310, Proc: 17
[2010-09-16 13:46:27.694276] T [rpc-clnt.c:624:rpc_clnt_reply_init] rpc-clnt: RPC XID: 13696 Program: GlusterFS 3.1, ProgVers: 310, Proc: 17
[2010-09-16 13:46:27.694316] T [rpc-clnt.c:624:rpc_clnt_reply_init] rpc-clnt: RPC XID: 13731 Program: GlusterFS 3.1, ProgVers: 310, Proc: 17
[2010-09-16 13:46:27.694341] D [nfs3-helpers.c:2411:nfs3_log_newfh_res] nfs-nfsv3: XID: 3eebc1d3, MKDIR: NFS: 0(Call completed successfully.), P
ture needs cleaning), FH: hashcount 1, exportid 00000000-0000-0000-0000-000000000000, gfid 281a5f11-8cb3-459d-90dd-f24a713c1d15310, Proc: 17



Later, on a NFSv3 LOOKUP on the directory:

[2010-09-16 13:46:37.500278] D [nfs3-helpers.c:2238:nfs3_log_fh_entry_call] nfs-nfsv3: XID: d0fac1d3, LOOKUP: args: FH: hashcount 0, exportid 00000000-0000-000
0-0000-000000000000, gfid 00000000-0000-0000-0000-000000000001, name: s3215
[2010-09-16 13:46:37.500290] T [nfs3.c:1211:nfs3_lookup] nfs-nfsv3: FH to Volume: 4dist-master
[2010-09-16 13:46:37.500301] T [nfs3-helpers.c:2994:nfs3_fh_resolve_entry_hard] nfs-nfsv3: FH hard resolution: gfid: 00000000-0000-0000-0000-000000000001 , ent
ry: s3215, hashidx: 0
[2010-09-16 13:46:37.500313] T [nfs.c:410:nfs_user_create] nfs: uid: 0, gid 0, gids: 7
[2010-09-16 13:46:37.500322] T [nfs.c:418:nfs_user_create] nfs: gid: 0
[2010-09-16 13:46:37.500330] T [nfs.c:418:nfs_user_create] nfs: gid: 1
[2010-09-16 13:46:37.500337] T [nfs.c:418:nfs_user_create] nfs: gid: 2
[2010-09-16 13:46:37.500345] T [nfs.c:418:nfs_user_create] nfs: gid: 3
[2010-09-16 13:46:37.500352] T [nfs.c:418:nfs_user_create] nfs: gid: 4
[2010-09-16 13:46:37.500359] T [nfs.c:418:nfs_user_create] nfs: gid: 6
[2010-09-16 13:46:37.500367] T [nfs.c:418:nfs_user_create] nfs: gid: 10
[2010-09-16 13:46:37.500375] T [nfs-fops.c:326:nfs_fop_lookup] nfs: Lookup: /s3215
[2010-09-16 13:46:37.500383] T [nfs-fops.c:133:nfs_create_frame] nfs: uid: 0, gid 0, gids: 7
[2010-09-16 13:46:37.500391] T [nfs-fops.c:135:nfs_create_frame] nfs: gid: 0
[2010-09-16 13:46:37.500399] T [nfs-fops.c:135:nfs_create_frame] nfs: gid: 1
[2010-09-16 13:46:37.500406] T [nfs-fops.c:135:nfs_create_frame] nfs: gid: 2
[2010-09-16 13:46:37.500414] T [nfs-fops.c:135:nfs_create_frame] nfs: gid: 3
[2010-09-16 13:46:37.500422] T [nfs-fops.c:135:nfs_create_frame] nfs: gid: 4
[2010-09-16 13:46:37.500429] T [nfs-fops.c:135:nfs_create_frame] nfs: gid: 6
[2010-09-16 13:46:37.500437] T [nfs-fops.c:135:nfs_create_frame] nfs: gid: 10
[2010-09-16 13:46:37.500480] T [rpc-clnt.c:1203:rpc_clnt_record] : Auth Info: pid: 0, uid: 0, gid: 0, owner: 10441
[2010-09-16 13:46:37.500493] T [rpc-clnt.c:1103:rpc_clnt_record_build_header] rpc-clnt: Request fraglen 272, payload: 144, rpc hdr: 128
[2010-09-16 13:46:37.500515] T [rpc-clnt.c:1203:rpc_clnt_record] : Auth Info: pid: 0, uid: 0, gid: 0, owner: 10441
[2010-09-16 13:46:37.500525] T [rpc-clnt.c:1103:rpc_clnt_record_build_header] rpc-clnt: Request fraglen 272, payload: 144, rpc hdr: 128
[2010-09-16 13:46:37.500547] T [rpc-clnt.c:1203:rpc_clnt_record] : Auth Info: pid: 0, uid: 0, gid: 0, owner: 10441
[2010-09-16 13:46:37.500558] T [rpc-clnt.c:1103:rpc_clnt_record_build_header] rpc-clnt: Request fraglen 272, payload: 144, rpc hdr: 128
[2010-09-16 13:46:37.500575] T [rpc-clnt.c:1203:rpc_clnt_record] : Auth Info: pid: 0, uid: 0, gid: 0, owner: 10441
[2010-09-16 13:46:37.500585] T [rpc-clnt.c:1103:rpc_clnt_record_build_header] rpc-clnt: Request fraglen 272, payload: 144, rpc hdr: 128
[2010-09-16 13:46:37.500787] T [rpc-clnt.c:624:rpc_clnt_reply_init] rpc-clnt: RPC XID: 21728 Program: GlusterFS 3.1, ProgVers: 310, Proc: 27
[2010-09-16 13:46:37.500805] D [dht-layout.c:649:dht_layout_dir_mismatch] 4dist-master: /s3215 - disk layout missing
[2010-09-16 13:46:37.500814] D [dht-common.c:276:dht_revalidate_cbk] 4dist-master: mismatching layouts for /s3215
[2010-09-16 13:46:37.501088] T [rpc-clnt.c:624:rpc_clnt_reply_init] rpc-clnt: RPC XID: 21749 Program: GlusterFS 3.1, ProgVers: 310, Proc: 27
[2010-09-16 13:46:37.501118] D [dht-layout.c:649:dht_layout_dir_mismatch] 4dist-master: /s3215 - disk layout missing
[2010-09-16 13:46:37.501129] D [dht-common.c:276:dht_revalidate_cbk] 4dist-master: mismatching layouts for /s3215
[2010-09-16 13:46:37.501163] T [rpc-clnt.c:624:rpc_clnt_reply_init] rpc-clnt: RPC XID: 21702 Program: GlusterFS 3.1, ProgVers: 310, Proc: 27
[2010-09-16 13:46:37.501175] D [dht-layout.c:649:dht_layout_dir_mismatch] 4dist-master: /s3215 - disk layout missing
[2010-09-16 13:46:37.501199] D [dht-common.c:276:dht_revalidate_cbk] 4dist-master: mismatching layouts for /s3215
[2010-09-16 13:46:37.501238] T [rpc-clnt.c:624:rpc_clnt_reply_init] rpc-clnt: RPC XID: 21722 Program: GlusterFS 3.1, ProgVers: 310, Proc: 27
[2010-09-16 13:46:37.501252] D [dht-layout.c:649:dht_layout_dir_mismatch] 4dist-master: /s3215 - disk layout missing
[2010-09-16 13:46:37.501272] D [dht-common.c:276:dht_revalidate_cbk] 4dist-master: mismatching layouts for /s3215
[2010-09-16 13:46:37.501289] D [nfs3-helpers.c:2411:nfs3_log_newfh_res] nfs-nfsv3: XID: d0fac1d3, LOOKUP: NFS: 70(Invalid file handle), POSIX: 116(Stale NFS f le handle), FH: hashcount 0, exportid 00000000-0000-0000-0000-000000000000, gfid 00000000-0000-0000-0000-000000000000

Comment 3 Vijay Bellur 2010-09-16 10:38:47 UTC
PATCH: http://patches.gluster.com/patch/4829 in master (distribute: send proper 'gfid' in calls originated from lookup/mkdir)

Comment 4 Vijay Bellur 2010-09-16 10:51:03 UTC
PATCH: http://patches.gluster.com/patch/4821 in master (server: Check gfid presence using uuid_is_null)

Comment 5 Amar Tumballi 2010-09-21 04:18:25 UTC
*** Bug 1633 has been marked as a duplicate of this bug. ***