Description of problem: ======================= For a file "courier.pp", if ls is performed for its absolute path it fails as: [root@wingo modules]# ls -lrt /mnt/vol0/a/b/.snaps/snap2/etc.1/selinux/targeted/modules/active/modules/courier.pp ls: cannot access /mnt/vol0/a/b/.snaps/snap2/etc.1/selinux/targeted/modules/active/modules/courier.pp: No such file or directory But when cd to the parent directory of "courier.pp" and did ls, it works as: [root@wingo modules]# cd /mnt/vol0/a/b/.snaps/snap2/etc.1/selinux/targeted/modules/active/modules/ [root@wingo modules]# ls -lrt courier.pp -rw-------. 1 root root 13705 Nov 21 2014 courier.pp [root@wingo modules]# [root@wingo ~]# ls -lrt /mnt/vol0/a/b/.snaps/snap2/etc.1/selinux/targeted/modules/active/modules/ | grep courier.pp -rw-------. 1 root root 13705 Nov 21 2014 courier.pp [root@wingo ~]# Version-Release number of selected component (if applicable): ============================================================= glusterfs-3.6.0.33-1.el6rhs.x86_64 Steps to Reproduce: =================== 1. Create 4 node cluster 2. Create a volume (2x2) 3. Mount the volume on a client (Fuse and NFS) 4. Create Nested directory from fuse mount (a/b) 5. Create Nested directory from nfs mount (c/d) 6. From fuse mount perform following: cd a/b cp -rvf /etc/host* . cp -rvf /etc . cd .. cp -rvf /etc/* . 7. From NFS mount perform following: mkdir -p c/d cd c/d/ cp -rvf /etc/host* . cd .. cp -rvf /etc/* . cd d cp -rvf /etc . 8. Create a snapshot of a volume snap1 9. From fuse mount perform following: cd a/b cp -rvf /etc etc.1 cd .. cp -rvf /etc etc.1 10. From NFS mount perform the following: cd c/d cp -rvf /etc . cp -rvf /etc etc.1 cd .. cp -rvf /etc etc.1 11. Create another snapshot of a volume snap2 12. Enable USS for a volume 13. From the fuse client do ls using absolute path [root@wingo modules]# ls -lrt /mnt/vol0/a/b/.snaps/snap2/etc.1/selinux/targeted/modules/active/modules/courier.pp" 14. From the fuse client do ls from the parent directory of the file [root@wingo modules]# cd /mnt/vol0/a/b/.snaps/snap2/etc.1/selinux/targeted/modules/active/modules/ [root@wingo modules]# ls -lrt courier.pp -rw-------. 1 root root 13705 Nov 21 2014 courier.pp [root@wingo modules]# Note: I have millions file and this I found on one file of 4 files, there could be others too having same issue as logs suggest "inode context null" for different gfids. Actual results: =============== ls using absolute path failed (step 13) and ls from the parent directory worked (step14) Expected results: ================= ls should be successful from absolute path too Additional info: ================ Logs: ===== snapd logs reports: =================== [root@inception ~]# tail -5 /var/log/glusterfs/snaps/vol0/snapd.log [2014-11-21 09:22:12.219777] W [dict.c:1352:dict_get_with_ref] (-->/usr/lib64/libglusterfs.so.0(default_lookup_resume+0x12c) [0x3d6d4273dc] (-->/usr/lib64/glusterfs/3.6.0.33/xlator/features/snapview-server.so(svs_lookup+0x2e3) [0x7fd86c344f23] (-->/usr/lib64/libglusterfs.so.0(dict_get_str_boolean+0x1f) [0x3d6d41acbf]))) 0-dict: dict OR key (entry-point) is NULL [2014-11-21 09:22:12.226374] W [dict.c:1352:dict_get_with_ref] (-->/usr/lib64/libglusterfs.so.0(default_lookup_resume+0x12c) [0x3d6d4273dc] (-->/usr/lib64/glusterfs/3.6.0.33/xlator/features/snapview-server.so(svs_lookup+0x2e3) [0x7fd86c344f23] (-->/usr/lib64/libglusterfs.so.0(dict_get_str_boolean+0x1f) [0x3d6d41acbf]))) 0-dict: dict OR key (entry-point) is NULL [2014-11-21 09:22:12.233003] W [dict.c:1352:dict_get_with_ref] (-->/usr/lib64/libglusterfs.so.0(default_lookup_resume+0x12c) [0x3d6d4273dc] (-->/usr/lib64/glusterfs/3.6.0.33/xlator/features/snapview-server.so(svs_lookup+0x2e3) [0x7fd86c344f23] (-->/usr/lib64/libglusterfs.so.0(dict_get_str_boolean+0x1f) [0x3d6d41acbf]))) 0-dict: dict OR key (entry-point) is NULL [2014-11-21 09:22:12.238769] W [dict.c:1352:dict_get_with_ref] (-->/usr/lib64/libglusterfs.so.0(default_lookup_resume+0x12c) [0x3d6d4273dc] (-->/usr/lib64/glusterfs/3.6.0.33/xlator/features/snapview-server.so(svs_lookup+0x2e3) [0x7fd86c344f23] (-->/usr/lib64/libglusterfs.so.0(dict_get_str_boolean+0x1f) [0x3d6d41acbf]))) 0-dict: dict OR key (entry-point) is NULL [2014-11-21 09:22:12.245301] W [dict.c:1352:dict_get_with_ref] (-->/usr/lib64/libglusterfs.so.0(default_lookup_resume+0x12c) [0x3d6d4273dc] (-->/usr/lib64/glusterfs/3.6.0.33/xlator/features/snapview-server.so(svs_lookup+0x2e3) [0x7fd86c344f23] (-->/usr/lib64/libglusterfs.so.0(dict_get_str_boolean+0x1f) [0x3d6d4[root@inception ~]# snap server logs reports: ========================= [root@inception ~]# tail -10 /var/log/glusterfs/snaps/vol0/snap2-f677b8f8-3e2d-473c-b8ab-c066fe04d55c.log [2014-11-21 07:25:16.469133] E [io-cache.c:564:ioc_open_cbk] 1-2548f1fd02e24894aeceb6f47151fc41-io-cache: inode context is NULL (5f7750b5-f2d7-415d-8e84-81d401906d79) [2014-11-21 07:25:16.472987] E [io-cache.c:564:ioc_open_cbk] 1-2548f1fd02e24894aeceb6f47151fc41-io-cache: inode context is NULL (f647e7e6-195e-4ea8-86bc-cbb534673a82) [2014-11-21 07:25:16.477776] E [io-cache.c:564:ioc_open_cbk] 1-2548f1fd02e24894aeceb6f47151fc41-io-cache: inode context is NULL (43638e18-d05f-4e07-b5d8-7e26b13dda55) [2014-11-21 07:25:16.482695] E [io-cache.c:564:ioc_open_cbk] 1-2548f1fd02e24894aeceb6f47151fc41-io-cache: inode context is NULL (342a65df-b4cc-4e10-ae77-82f5007e1fa0) [2014-11-21 07:25:16.487381] E [io-cache.c:564:ioc_open_cbk] 1-2548f1fd02e24894aeceb6f47151fc41-io-cache: inode context is NULL (592a2a8b-fb11-4859-997b-3d1136cc2098) [2014-11-21 07:25:16.492010] E [io-cache.c:564:ioc_open_cbk] 1-2548f1fd02e24894aeceb6f47151fc41-io-cache: inode context is NULL (bbf8fccc-f8df-4881-8cd2-2b64ac3bfffa) [2014-11-21 07:25:16.496989] E [io-cache.c:564:ioc_open_cbk] 1-2548f1fd02e24894aeceb6f47151fc41-io-cache: inode context is NULL (1967b05a-4553-41ce-9cb1-13ba9f40e530) [2014-11-21 07:25:16.501682] E [io-cache.c:564:ioc_open_cbk] 1-2548f1fd02e24894aeceb6f47151fc41-io-cache: inode context is NULL (49005e1f-43d6-4472-a2c4-da5ef3765022) [2014-11-21 07:26:44.717296] E [snapview-server.c:298:svs_lookup_entry] 0-vol0-snapview-server: failed to do lookup and get the handle for entry courier.pp: (path: <gfid:87b274ab-489d-4bce-9988-a10e7b8c7a1f>/.snaps/snap2/etc.1/selinux/targeted/modules/active/modules/courier.pp:) [2014-11-21 07:26:44.719509] E [snapview-server.c:298:svs_lookup_entry] 0-vol0-snapview-server: failed to do lookup and get the handle for entry courier.pp: (path: <gfid:87b274ab-489d-4bce-9988-a10e7b8c7a1f>/.snaps/snap2/etc.1/selinux/targeted/modules/active/modules/courier.pp:) [root@inception ~]#
From the fuse logs, found this: [2014-11-20 19:52:50.357467] C [inode.c:217:__is_dentry_cyclic] 0-meta-autoload/inode: detected cyclic loop formation during inode linkage. inode (00000000-0000-0000-0000-000000000001) linking under itself as courier.pp [2014-11-20 19:52:50.357553] W [inode.c:911:inode_lookup] (-->/usr/lib64/glusterfs/3.6.0.33/xlator/debug/io-stats.so(io_stats_lookup_cbk+0x113) [0x7f7cb5749e73] (-->/usr/lib64/glusterfs/3.6.0.33/xlator/mount/fuse.so(+0x1ef7d) [0x7f7cb9b01f7d] (-->/usr/lib64/glusterfs/3.6.0.33/xlator/mount/fuse.so(+0x1eb2e) [0x7f7cb9b01b2e]))) 0-fuse: inode not found [2014-11-20 19:53:22.949826] E [snapview-client.c:170:svc_lookup_cbk] 2-vol0-snapview-client: Lookup on normal graph failed with error Stale file handle [2014-11-20 19:53:22.950475] W [inode.c:165:__foreach_ancestor_dentry] 0-fuse: per dentry fn returned 1 [2014-11-20 19:53:22.950501] C [inode.c:217:__is_dentry_cyclic] 0-meta-autoload/inode: detected cyclic loop formation during inode linkage. inode (00000000-0000-0000-0000-000000000001) linking under itself as courier.pp [2014-11-20 19:53:22.950588] W [inode.c:911:inode_lookup] (-->/usr/lib64/glusterfs/3.6.0.33/xlator/debug/io-stats.so(io_stats_lookup_cbk+0x113) [0x7f7cb5749e73] (-->/usr/lib64/glusterfs/3.6.0.33/xlator/mount/fuse.so(+0x1ef7d) [0x7f7cb9b01f7d] (-->/usr/lib64/glusterfs/3.6.0.33/xlator/mount/fuse.so(+0x1eb2e) [0x7f7cb9b01b2e]))) 0-fuse: inode not found [2014-11-20 19:53:22.951496] E [snapview-client.c:170:svc_lookup_cbk] 2-vol0-snapview-client: Lookup on normal graph failed with error Stale file handle [2014-11-20 19:53:22.952011] W [inode.c:165:__foreach_ancestor_dentry] 0-fuse: per dentry fn returned 1 [2014-11-20 19:53:22.952052] C [inode.c:217:__is_dentry_cyclic] 0-meta-autoload/inode: detected cyclic loop formation during inode linkage. inode (00000000-0000-0000-0000-000000000001) linking under itself as courier.pp
I tried to reproduce this issue using the latest downstream code base, and I could not hit it. I'll try this with the latest build and see if it can be reproduced. I'll change the status of the bug accordingly after testing with latest RPMs
Version : gluster --version glusterfs 3.7.0alpha0 built on Apr 28 2015 Works in the current build. Will re-open the bug if the issue is seen again