Description of problem: While executing the posix compliance the execution gets stuck for a rename test. Version-Release number of selected component (if applicable): glusterfs-3.7.5-7.el7rhgs.x86_64 nfs-ganesha-2.2.0-11.el7rhgs.x86_64 How reproducible: always Steps to Reproduce: 1. time prove -r /opt/qa/tools/pjd-fstest-20080816/tests/ Actual results: ganesha-gfapi.log [2015-11-25 17:06:20.807343] E [glfs-handleops.c:1789:glfs_h_poll_cache_invalidation] (-->/usr/lib64/ganesha/libfsalgluster.so(GLUSTERFSAL_UP_Thread+0xc3) [0x7f1ee0107ec3] -->/lib64/libgfapi.so.0(glfs_h_poll_upcall+0x190) [0x7f1edfcefb50] -->/lib64/libgfapi.so.0(+0x188bc) [0x7f1edfcef8bc] ) 0-glfs_h_poll_cache_invalidation: invalid argument: object [Invalid argument] [2015-11-25 17:06:20.807358] W [MSGID: 104047] [glfs-handleops.c:1944:pub_glfs_h_poll_upcall] 0-meta-autoload: handle creation of 00000000-0000-0000-0000-000000000000 failed [Invalid argument] [2015-11-25 17:06:21.807691] E [dht-helper.c:598:dht_subvol_get_hashed] (-->/lib64/libglusterfs.so.0(default_lookup+0x5b) [0x7f1edfa3674b] -->/usr/lib64/glusterfs/3.7.5/xlator/cluster/distribute.so(dht_lookup+0xa81) [0x7f1ecf371871] -->/usr/lib64/glusterfs/3.7.5/xlator/cluster/distribute.so(dht_subvol_get_hashed+0x1c8) [0x7f1ecf33b7b8] ) 0-vol2-tier-dht: invalid argument: loc->parent [Invalid argument] [2015-11-25 17:06:21.807825] E [dht-helper.c:598:dht_subvol_get_hashed] (-->/usr/lib64/glusterfs/3.7.5/xlator/cluster/distribute.so(dht_lookup+0xf8c) [0x7f1ecf371d7c] -->/usr/lib64/glusterfs/3.7.5/xlator/cluster/distribute.so(dht_lookup+0xa81) [0x7f1ecf371871] -->/usr/lib64/glusterfs/3.7.5/xlator/cluster/distribute.so(dht_subvol_get_hashed+0x1c8) [0x7f1ecf33b7b8] ) 0-vol2-cold-dht: invalid argument: loc->parent [Invalid argument] [2015-11-25 17:06:21.808312] E [dht-helper.c:598:dht_subvol_get_hashed] (-->/usr/lib64/glusterfs/3.7.5/xlator/cluster/distribute.so(dht_lookup+0xf8c) [0x7f1ecf371d7c] -->/usr/lib64/glusterfs/3.7.5/xlator/cluster/distribute.so(dht_lookup+0xa81) [0x7f1ecf371871] -->/usr/lib64/glusterfs/3.7.5/xlator/cluster/distribute.so(dht_subvol_get_hashed+0x1c8) [0x7f1ecf33b7b8] ) 0-vol2-hot-dht: invalid argument: loc->parent [Invalid argument] [2015-11-25 17:06:21.808598] W [MSGID: 114031] [client-rpc-fops.c:2974:client3_3_lookup_cbk] 0-vol2-client-2: remote operation failed. Path: (null) (00000000-0000-0000-0000-000000000000) [Invalid argument] [2015-11-25 17:06:21.808717] W [MSGID: 114031] [client-rpc-fops.c:2974:client3_3_lookup_cbk] 0-vol2-client-1: remote operation failed. Path: (null) (00000000-0000-0000-0000-000000000000) [Invalid argument] [2015-11-25 17:06:21.808737] W [MSGID: 114031] [client-rpc-fops.c:2974:client3_3_lookup_cbk] 0-vol2-client-0: remote operation failed. Path: (null) (00000000-0000-0000-0000-000000000000) [Invalid argument] The message "W [MSGID: 114031] [client-rpc-fops.c:2974:client3_3_lookup_cbk] 0-vol2-client-5: remote operation failed. Path: (null) (00000000-0000-0000-0000-000000000000) [Invalid argument]" repeated 2 times between [2015-11-25 17:06:19.805201] and [2015-11-25 17:06:21.809094] [2015-11-25 17:06:21.809285] W [MSGID: 114031] [client-rpc-fops.c:2974:client3_3_lookup_cbk] 0-vol2-client-4: remote operation failed. Path: (null) (00000000-0000-0000-0000-000000000000) [Invalid argument] [2015-11-25 17:06:21.809422] W [MSGID: 104011] [glfs-handleops.c:1291:pub_glfs_h_create_from_handle] 0-meta-autoload: inode refresh of 00000000-0000-0000-0000-000000000000 failed: Invalid argument [Invalid argument] [2015-11-25 17:06:21.809507] E [glfs-handleops.c:1789:glfs_h_poll_cache_invalidation] (-->/usr/lib64/ganesha/libfsalgluster.so(GLUSTERFSAL_UP_Thread+0xc3) [0x7f1ee0107ec3] -->/lib64/libgfapi.so.0(glfs_h_poll_upcall+0x190) [0x7f1edfcefb50] -->/lib64/libgfapi.so.0(+0x188bc) [0x7f1edfcef8bc] ) 0-glfs_h_poll_cache_invalidation: invalid argument: object [Invalid argument] [2015-11-25 17:06:21.809578] W [MSGID: 104047] [glfs-handleops.c:1944:pub_glfs_h_poll_upcall] 0-meta-autoload: handle creation of 00000000-0000-0000-0000-000000000000 failed [Invalid argument] Expected results: the posix compliance testsuite should finish successfully without getting stuck Additional info:
Please provide the pkt trace captured and the logs -ganesha/ganesha-gfapi.log, sosreport.
I could consistently reproduce this issue. For some reason, as part tests/rename/10.t , mknod()-> glfs_h_mknod() fails with EEXIST error. In NFS-Ganesha, on receiving this error, does a lookup of the object for which it receives ENOENT. Since it is in inconsistent state, it keeps retrying the fop resulting in hang on the client side.
This seem to be an issue with dht-tier. For every file creation, dht-tier seem to be creating linked files on cold tier first and then actual files on hot-tier. If for any reason actual file creation fails, linked files are not deleted from the cold tier (as can be seen below) # ls -ltr /bricks/xfs_brick/b*/dir_tmp/fstest_3e00dbbaaeb95ee267e1a3b59a821b34/fstest_dc09c43ca69e030460a777fac05f25d7 /bricks/xfs_brick/b2-tier/dir_tmp/fstest_3e00dbbaaeb95ee267e1a3b59a821b34/fstest_dc09c43ca69e030460a777fac05f25d7: total 0 /bricks/xfs_brick/b1-tier/dir_tmp/fstest_3e00dbbaaeb95ee267e1a3b59a821b34/fstest_dc09c43ca69e030460a777fac05f25d7: total 0 /bricks/xfs_brick/b2/dir_tmp/fstest_3e00dbbaaeb95ee267e1a3b59a821b34/fstest_dc09c43ca69e030460a777fac05f25d7: total 0 ---------T 2 root root 0 Dec 7 13:18 fstest_cbf533920c1896845883fb493fce0d06 /bricks/xfs_brick/b1/dir_tmp/fstest_3e00dbbaaeb95ee267e1a3b59a821b34/fstest_dc09c43ca69e030460a777fac05f25d7: total 0 ---------T 2 root root 0 Dec 7 13:18 fstest_cbf533920c1896845883fb493fce0d06 This led to the inconsistent behaviour seen by the nfs-ganesha (mentioned in the above comment). Exclusive file creation with the same file path shall result in ERR_EXISTS error since linked files are present and LOOKUP shall fail with EINVAL error since the actual files are missing. ]# ls fstest_3e00dbbaaeb95ee267e1a3b59a821b34/fstest_dc09c43ca69e030460a777fac05f25d7/fstest_cbf533920c1896845883fb493fce0d06 ls: cannot access fstest_3e00dbbaaeb95ee267e1a3b59a821b34/fstest_dc09c43ca69e030460a777fac05f25d7/fstest_cbf533920c1896845883fb493fce0d06: No such file or directory # mkfifo fstest_3e00dbbaaeb95ee267e1a3b59a821b34/fstest_dc09c43ca69e030460a777fac05f25d7/fstest_cbf533920c1896845883fb493fce0d06 mkfifo: cannot create fifo `fstest_3e00dbbaaeb95ee267e1a3b59a821b34/fstest_dc09c43ca69e030460a777fac05f25d7/fstest_cbf533920c1896845883fb493fce0d06': File exists This seem to be known issue with tiering. Request Rafi/Nithya to mark this bug duplicate (if any present already)
Sounds like the root cause is addressed with bug 1291212? Jiffin, what do you thinks?
@Niels It's not related to BZ1291212
I tested the bug in upstream 3.7.9 and didn't hit the issue on nfsv4 mount. on the server --------------- gluster v info vol Volume Name: vol Type: Tier Volume ID: 6bd03c40-4a6e-4beb-847f-29fba87132fb Status: Started Number of Bricks: 4 Transport-type: tcp Hot Tier : Hot Tier Type : Replicate Number of Bricks: 1 x 2 = 2 Brick1: 10.70.43.7:/brick1/volhh2 Brick2: 10.70.43.58:/brick1/volhh1 Cold Tier: Cold Tier Type : Replicate Number of Bricks: 1 x 2 = 2 Brick3: 10.70.43.58:/brick1/vol Brick4: 10.70.43.7:/brick1/vol Options Reconfigured: performance.readdir-ahead: on nfs.disable: on features.cache-invalidation: on ganesha.enable: on features.ctr-enabled: on cluster.tier-mode: cache nfs-ganesha: enable cluster.enable-shared-storage: enable on the client -------------------------------------- mount 10.70.43.58:/vol on /mnt/nfs/1 type nfs4 (rw,relatime,vers=4.0,rsize=1048576,wsize=1048576,namlen=255,hard,proto=tcp,port=0,timeo=600,retrans=2,sec=sys,clientaddr=10.70.43.92,local_lock=none,addr=10.70.43.58) I only executed rename test suite in posix compliance test output of the test Changing to the specified mountpoint /mnt/nfs/1/run14744 executing posix_compliance start: 22:26:22 real 0m17.735s user 0m1.191s sys 0m3.230s /export//opt/qa/tools/posix-testsuite/tests/rename/00.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/01.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/02.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/03.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/04.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/05.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/06.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/07.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/08.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/09.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/10.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/11.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/12.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/13.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/14.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/15.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/16.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/17.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/18.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/19.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/20.t .. ok All tests successful. Files=21, Tests=479, 17 wallclock secs ( 0.39 usr 0.05 sys + 1.58 cusr 6.58 csys = 8.60 CPU) Result: PASS /export//opt/qa/tools/posix-testsuite/tests/rename/00.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/01.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/02.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/03.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/04.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/05.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/06.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/07.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/08.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/09.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/10.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/11.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/12.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/13.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/14.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/15.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/16.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/17.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/18.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/19.t .. ok /export//opt/qa/tools/posix-testsuite/tests/rename/20.t .. ok All tests successful. Files=21, Tests=479, 17 wallclock secs ( 0.23 usr 0.04 sys + 0.88 cusr 3.17 csys = 4.32 CPU) Result: PASS end: 22:26:41 removed posix compliance directories 1 Total 1 tests were successful Switching over to the previous working directory Removing /mnt/nfs/1//run14744/
This issue was reported long back. After that, quite number of patches went to code base. Based on comment4 and comment11, the issue could have fixed with patch http://review.gluster.org/#/c/12829/ Shashank, Can you please try out this in the latest build ?
As tier is not being actively developed, I'm closing this bug. Feel free to open it if necessary.