Bug 1404905 - DHT : file rename operation is successful but log has error 'key:trusted.glusterfs.dht.linkto error:File exists' , 'setting xattrs on <old_filename> failed (File exists)'
Summary: DHT : file rename operation is successful but log has error 'key:trusted.glus...
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: GlusterFS
Classification: Community
Component: distribute
Version: mainline
Hardware: x86_64
OS: Linux
medium
medium
Target Milestone: ---
Assignee: Mohit Agrawal
QA Contact:
URL:
Whiteboard: dht-rca-unknown, dht-log, dht-qe-3.2,...
Depends On: 1030200 1282318
Blocks:
TreeView+ depends on / blocked
 
Reported: 2016-12-15 03:46 UTC by Mohit Agrawal
Modified: 2017-03-06 17:39 UTC (History)
15 users (show)

Fixed In Version: glusterfs-3.10.0
Doc Type: If docs needed, set a value
Doc Text:
Clone Of: 1282318
Environment:
Last Closed: 2017-03-06 17:39:54 UTC
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:


Attachments (Terms of Use)

Description Mohit Agrawal 2016-12-15 03:46:39 UTC
+++ This bug was initially created as a clone of Bug #1282318 +++

+++ This bug was initially created as a clone of Bug #1030200 +++

Description of problem:
on Distributed volume, file rename operation is completed without fail but brick log has errors like

renaming form f11 to mv11

[2013-11-14 02:31:26.572912] E [posix-helpers.c:809:posix_handle_pair] 0-dht-posix: /rhs/brick4/d2/mvt/def/f11: key:trusted.glusterfs.dht.linkto error:File exists
[2013-11-14 02:31:26.572962] E [posix.c:915:posix_mknod] 0-dht-posix: setting xattrs on /rhs/brick4/d2/mvt/def/f11 failed (File exists)

-- > when rename operation is successful and xattr is pointing to correct location why these Errors

verified on backend. file has trusted.glusterfs.dht.linkto xattr and it is pointing to correct sub-volume.

[root@7-VM3 ~]# ls -l /rhs/brick4/d*/mvt/def/mv11
-rw-rw-r-- 3 503 503 0 Nov 14 07:58 /rhs/brick4/d1/mvt/def/mv11
---------T 3 503 503 0 Nov 14 07:58 /rhs/brick4/d2/mvt/def/mv11


[root@7-VM3 ~]# getfattr -d -m . /rhs/brick4/d2/mvt/def/mv11
getfattr: Removing leading '/' from absolute path names
# file: rhs/brick4/d2/mvt/def/mv11
trusted.gfid=0s5VrPgZBWSc+7MAQOxLMnXQ==
trusted.glusterfs.dht.linkto="dht-client-0"



Version-Release number of selected component (if applicable):
3.4.0.44rhs-1.el6rhs.x86_64

How reproducible:
always reproducible but not giving error for all file rename operation

Steps to Reproduce:
1.rename 100 files(where destination file is not present and destination hash and cached sub-vol is different) and will get error in brick log for few files
2.
3.

Actual results:
brick log

[2013-11-14 02:43:38.966275] E [posix-helpers.c:809:posix_handle_pair] 0-dht-posix: /rhs/brick4/d2/ag100/f31: key:trusted.glusterfs.dht.linkto error:File exists
[2013-11-14 02:43:38.966329] E [posix.c:915:posix_mknod] 0-dht-posix: setting xattrs on /rhs/brick4/d2/ag100/f31 failed (File exists)
[2013-11-14 02:43:39.158963] E [posix-helpers.c:809:posix_handle_pair] 0-dht-posix: /rhs/brick4/d2/ag100/f48: key:trusted.glusterfs.dht.linkto error:File exists
[2013-11-14 02:43:39.159024] E [posix.c:915:posix_mknod] 0-dht-posix: setting xattrs on /rhs/brick4/d2/ag100/f48 failed (File exists)
[2013-11-14 02:43:39.369143] E [posix-helpers.c:809:posix_handle_pair] 0-dht-posix: /rhs/brick4/d2/ag100/f67: key:trusted.glusterfs.dht.linkto error:File exists
[2013-11-14 02:43:39.369205] E [posix.c:915:posix_mknod] 0-dht-posix: setting xattrs on /rhs/brick4/d2/ag100/f67 failed (File exists)
[2013-11-14 02:43:39.510074] E [posix-helpers.c:809:posix_handle_pair] 0-dht-posix: /rhs/brick4/d2/ag100/f78: key:trusted.glusterfs.dht.linkto error:File exists
[2013-11-14 02:43:39.510125] E [posix.c:915:posix_mknod] 0-dht-posix: setting xattrs on /rhs/brick4/d2/ag100/f78 failed (File exists)
[2013-11-14 02:43:39.577798] E [posix-helpers.c:809:posix_handle_pair] 0-dht-posix: /rhs/brick4/d2/ag100/f85: key:trusted.glusterfs.dht.linkto error:File exists
[2013-11-14 02:43:39.577914] E [posix.c:915:posix_mknod] 0-dht-posix: setting xattrs on /rhs/brick4/d2/ag100/f85 failed (File exists)
[2013-11-14 02:43:39.644510] E [posix-helpers.c:809:posix_handle_pair] 0-dht-posix: /rhs/brick4/d2/ag100/f91: key:trusted.glusterfs.dht.linkto error:File exists
[2013-11-14 02:43:39.644571] E [posix.c:915:posix_mknod] 0-dht-posix: setting xattrs on /rhs/brick4/d2/ag100/f91 failed (File exists)



Expected results:
log should not have errors; if rename is successful

Additional info:

--- Additional comment from RHEL Product and Program Management on 2013-11-14 01:57:38 EST ---

Since this issue was entered in bugzilla, the release flag has been
set to ? to ensure that it is properly evaluated for this release.

--- Additional comment from Rachana Patel on 2013-11-14 06:28:42 EST ---

sosreport @ http://rhsqe-repo.lab.eng.blr.redhat.com/sosreports/1030309

volume info:-
[root@7-VM3 glusterfs]# gluster v info dht
 
Volume Name: dht
Type: Distribute
Volume ID: 29b35eed-9b1a-443b-914a-e77d9452eb47
Status: Started
Number of Bricks: 4
Transport-type: tcp
Bricks:
Brick1: 10.70.36.132:/rhs/brick4/d1
Brick2: 10.70.36.132:/rhs/brick4/d2
Brick3: 10.70.36.132:/rhs/brick4/d3
Brick4: 10.70.36.132:/rhs/brick4/d4



mount info:-

[root@rhs-client22 dht-nfs]# mount | grep dht
10.70.36.132:/dht on /mnt/dht type fuse.glusterfs (rw,default_permissions,allow_other,max_read=131072)
10.70.36.132:/dht on /mnt/dht-nfs type nfs (rw,addr=10.70.36.132)

--- Additional comment from John Skeoch on 2014-02-26 19:13:56 EST ---

User srangana@redhat.com's account has been closed

--- Additional comment from John Skeoch on 2014-03-30 21:34:50 EDT ---

User vraman@redhat.com's account has been closed

--- Additional comment from Peter Auyeung on 2014-08-25 18:13:26 EDT ---

Add hit this bug in 3.5.2 ubuntu xfs.

[2014-08-25 22:04:39.975617] E [posix-helpers.c:893:posix_handle_pair] 0-sas03-posix: /brick03/gfs/DevMordorHomeSata03//hcamara//custom_interim_reports//lumber_liquidators/weekly_report/lumber_liquidator_weekly_custom_pos.py: key:trusted.glusterfs.dht.linkto error:File exists
[2014-08-25 22:04:39.975634] E [posix.c:1177:posix_mknod] 0-sas03-posix: setting xattrs on /brick03/gfs/DevMordorHomeSata03//hcamara//custom_interim_reports//lumber_liquidators/weekly_report/lumber_liquidator_weekly_custom_pos.py failed (File exists)

--- Additional comment from Peter Auyeung on 2014-08-27 18:49:08 EDT ---

Would like bug be fix in 3.5.3?

I keep getting random Error messages like these in 3.5.2:

2014-08-27 21:56:33.580521] E [posix-helpers.c:893:posix_handle_pair] 0-sas03-posix: /brick03/gfs/DevMordorHomeSata03//hcamara//custom_interim_reports//ospgroup/womanwithin/weekly_report/mtd/survey_questionstest.txt: key:trusted.glusterfs.dht.linkto error:File exists
&yellow .2014-08-27 21:56:33.580538] E [posix.c:1177:posix_mknod] 0-sas03-posix: setting xattrs on /brick03/gfs/DevMordorHomeSata03//hcamara//custom_interim_reports//ospgroup/womanwithin/weekly_report/mtd/survey_questionstest.txt failed (File exists)

Thanks
Peter

--- Additional comment from  on 2014-09-18 02:52:39 EDT ---

Seeing this issue on "glusterfs 3.6.0.28 built on Sep  3 2014 10:13:12" . 

Following is the case executed:
===============================
1. Create 1 x 2 replicate volume. 

2. From 2 clients create 1 fuse and 1 nfs mount on each client with " -o direct-io-mode=yes" option

3. 
From 1st client fuse mount execute the following:
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
echo abc > abc-ln

while true; do ln abc-ln abc; mv -f abc-ln abc; echo 3>/proc/sys/vm/drop_caches; cat abc; ln abc abc-ln; mv -f abc abc-ln; echo 3>/proc/sys/vm/drop_caches; cat abc-ln; done

From 1st client nfs mount execute the following:
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
while true; do find . | xargs stat ; done

From 2nd client fuse mount execute the following:
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
while true; do find . | xargs stat ; done

From 2nd client nfs mount execute the following:
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
while true; do ls -liR ; done

4. add 2 more bricks to the volume to make it 2x2 dis-replicate volume

In the newly added brick logs saw the messages :
[2014-09-18 04:09:02.055008] E [posix-helpers.c:948:posix_handle_pair] 0-vol1-posix: /rhs/device0/b3/abc-ln: key:trusted.glusterfs.dht.linkto flags: 1 length:17 error:File exists
[2014-09-18 04:09:02.055035] E [posix.c:1181:posix_mknod] 0-vol1-posix: setting xattrs on /rhs/device0/b3/abc-ln failed (File exists)

root@rhs-client13 [Sep-18-2014- 6:51:05] >grep "posix_handle_pair" /var/log/glusterfs/bricks/rhs-device0-b3.log | wc
 420414 5044968 74623494
root@rhs-client13 [Sep-18-2014- 6:51:38] >grep "posix_mknod" /var/log/glusterfs/bricks/rhs-device0-b3.log | wc
 420414 5044968 55704864
root@rhs-client13 [Sep-18-2014- 6:51:58] >

--- Additional comment from Red Hat Bugzilla Rules Engine on 2015-11-16 00:33:00 EST ---

This bug is automatically being proposed for the current z-stream release of Red Hat Gluster Storage 3 by setting the release flag 'rhgs‑3.1.z' to '?'. 

If this bug should be proposed for a different release, please manually change the proposed release flag.

--- Additional comment from Nithya Balachandran on 2016-05-03 05:05:24 EDT ---



--- Additional comment from Nithya Balachandran on 2016-06-24 02:26:38 EDT ---

No RCA yet. To be retested against the latest build.

--- Additional comment from Raghavendra G on 2016-07-05 02:13:38 EDT ---

The fix we thought is to move the log in posix_mknod to DEBUG level

--- Additional comment from John Skeoch on 2016-07-31 21:22:51 EDT ---

User sabansal@redhat.com's account has been closed

--- Additional comment from surabhi on 2016-09-19 05:35:36 EDT ---

A 2x2 dis-rep volume , mounted on cifs client and running different fops on client using crefi, following error messages are seen in brick logs:
[2016-09-19 07:06:54.089211] E [MSGID: 113001] [posix-helpers.c:1175:posix_handle_pair] 0-testvol-posix: /mnt/brick/testvol/b2/thread0/level00/hardlink_to_files/57df8e7
3%%YLW8207V72: key:trusted.glusterfs.dht.linktoflags: 1 length:20 [File exists]
[2016-09-19 07:06:54.089256] E [MSGID: 113001] [posix.c:1353:posix_mknod] 0-testvol-posix: setting xattrs on /mnt/brick/testvol/b2/thread0/level00/hardlink_to_files/57d
f8e73%%YLW8207V72 failed
[2016-09-19 07:06:54.145984] E [MSGID: 113001] [posix-helpers.c:1175:posix_handle_pair] 0-testvol-posix: /mnt/brick/testvol/b2/thread0/level00/hardlink_to_files/57df8e7
4%%2BTFGH1HJS: key:trusted.glusterfs.dht.linktoflags: 1 length:20 [File exists]
[2016-09-19 07:06:54.146008] E [MSGID: 113001] [posix.c:1353:posix_mknod] 0-testvol-posix: setting xattrs on /mnt/brick/testvol/b2/thread0/level00/hardlink_to_files/57d
f8e74%%2BTFGH1HJS failed

Comment 1 Worker Ant 2016-12-19 03:52:09 UTC
REVIEW: http://review.gluster.org/16185 (dht : file rename operation is successful but log has error File exists) posted (#1) for review on master by MOHIT AGRAWAL (moagrawa@redhat.com)

Comment 2 Worker Ant 2017-01-10 06:27:54 UTC
COMMIT: http://review.gluster.org/16185 committed in master by Raghavendra G (rgowdapp@redhat.com) 
------
commit 167f417f73d7877e7b5ea5bf72e66964d463d4b6
Author: Mohit Agrawal <moagrawa@redhat.com>
Date:   Mon Dec 19 09:14:44 2016 +0530

    dht : file rename operation is successful but log has error File exists
    
    Problem: file rename operation is successful but log has error
             'key:trusted.glusterfs.dht.linkto error:File exists'
    
    Solution: The error comes in log only when file already has set this xattr
              (trusted.glusterfs.dht.linkto) before run rename operation and
              in that case sys_lsetxattr throws this kind of message.
              To avoid the error message in logs update the condition in
              posix_handle_pair.
    
    BUG: 1404905
    Change-Id: Iafd8cb45f9d7f4fe247e297a6ef0af978a8d0b30
    Signed-off-by: Mohit Agrawal <moagrawa@redhat.com>
    Reviewed-on: http://review.gluster.org/16185
    Smoke: Gluster Build System <jenkins@build.gluster.org>
    NetBSD-regression: NetBSD Build System <jenkins@build.gluster.org>
    CentOS-regression: Gluster Build System <jenkins@build.gluster.org>
    Reviewed-by: Raghavendra G <rgowdapp@redhat.com>

Comment 3 Shyamsundar 2017-03-06 17:39:54 UTC
This bug is getting closed because a release has been made available that should address the reported issue. In case the problem is still not fixed with glusterfs-3.10.0, please open a new bug report.

glusterfs-3.10.0 has been announced on the Gluster mailinglists [1], packages for several distributions should become available in the near future. Keep an eye on the Gluster Users mailinglist [2] and the update infrastructure for your distribution.

[1] http://lists.gluster.org/pipermail/gluster-users/2017-February/030119.html
[2] https://www.gluster.org/pipermail/gluster-users/


Note You need to log in before you can comment on or make changes to this bug.