Bug 1479656

Summary: Permission denied errors when appending files after readdir
Product: [Community] GlusterFS Reporter: Poornima G <pgurusid>
Component: libgfapiAssignee: bugs <bugs>
Status: CLOSED CURRENTRELEASE QA Contact: bugs <bugs>
Severity: high Docs Contact:
Priority: unspecified    
Version: 3.11CC: amukherj, anoopcs, bugs, ksandha, rhinduja, rhs-smb
Target Milestone: ---Keywords: Triaged
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: glusterfs-3.11.3 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: 1479655 Environment:
Last Closed: 2017-08-24 14:46:21 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On: 1457713, 1477488, 1479655    
Bug Blocks:    

Description Poornima G 2017-08-09 04:48:15 UTC 
+++ This bug was initially created as a clone of Bug #1479655 +++

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

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

Description of problem:
Running readdir (scan directories only, don't read files or their metadata)  operation and then doing append to files results in permission denied errors on cifs 

Version-Release number of selected component (if applicable):
3.8.4-26

How reproducible:
100%

Steps to Reproduce:
mount the volume using cifs3
1. Create files using small-file tool
2. Run readdir operation on the mount.
3. After completion , run append operation. 

Actual results:
Permission denied errors seen on tool result in failure.

Expected results:
No errors should be observed. 

Additional info:

--- Additional comment from Red Hat Bugzilla Rules Engine on 2017-06-01 03:48:25 EDT ---

This bug is automatically being proposed for the current release of Red Hat Gluster Storage 3 under active development, by setting the release flag 'rhgs‑3.3.0' to '?'. 

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

--- Additional comment from Red Hat Bugzilla Rules Engine on 2017-06-01 03:51:48 EDT ---

This bug report has Keywords: Regression or TestBlocker.

Since no regressions or test blockers are allowed between releases, it is also being identified as a blocker for this release.

Please resolve ASAP.

--- Additional comment from Red Hat Bugzilla Rules Engine on 2017-06-09 03:48:54 EDT ---


--- Additional comment from Poornima G on 2017-06-20 05:18:44 EDT ---

As discussed, the issue wasn't reproduced on setup with 4node samba and 4 clients when ctdb was added. The issue originally was reported with samba cluster but no ctdb which is not a valid setup. Hence deferring it from 3.3.

But would like to retain the BZ and see if there is any other bug that is being exposed only in non CTDB setup as the same was working earlier.

--- Additional comment from Karan Sandha on 2017-06-27 05:06:18 EDT ---

Hi,

I am able to reproduce this on ctdb setup also.

--- Additional comment from Atin Mukherjee on 2017-06-27 14:24:02 EDT ---


--- Additional comment from Karan Sandha on 2017-07-03 09:06:13 EDT ---

Hi Anoop,

I have seen this issue repetitively on Linux and windows clients. Attaching the screen shot of the issue and the logs. 


The issue has started apperaring on delete-renamed operation too. 

Thanks & Regards
Karan Sandha


--- Additional comment from Karan Sandha on 2017-07-03 09:12 EDT ---



--- Additional comment from Anoop C S on 2017-07-06 03:23:07 EDT ---

Hi Karan,

I looked over the from comment #9. It's weird that I am not seeing any 'Permission denied' or related errors in any of the logs(samba/glusterfs-client/brick logs). Since you mentioned it as 100% reproducible, can you please make the following changes to /etc/samba/smb.conf and re-run the tests in hope of getting some useful logs.

* Change 'max log size = 50' --> 'max log size = 0'
* Add 'log level = 7'
* And in [glusterfs-<VOLNAME>] section change 'glusterfs:loglevel = 7' --> 'glusterfs:loglevel = 8'

Additionally, you can also increase the brick log level to DEBUG.

--- Additional comment from Karan Sandha on 2017-07-11 09:13:10 EDT ---

Hi Anoop,
The permission denied issue was seen on application side. as seen in the screenshot. 
[root@gqac006 ~]# qeSyncDropCaches.sh; python /small-files/smallfile/smallfile_cli.py --operation append --threads 8 --file-size 64 --files 2000 --top /gluster-mount  --host-set "`echo $CLIENT | tr ' ' ','`"Dropping cache on 
smallfile version 3.0
                           hosts in test : ['gqac006.sbu.lab.eng.bos.redhat.com', 'gqac025.sbu.lab.eng.bos.redhat.com', 'gqac026.sbu.lab.eng.bos.redhat.com', 'gqac027.sbu.lab.eng.bos.redhat.com']
                   top test directory(s) : ['/gluster-mount']
                               operation : append
                            files/thread : 2000
                                 threads : 8
           record size (KB, 0 = maximum) : 0
                          file size (KB) : 64
                  file size distribution : fixed
                           files per dir : 100
                            dirs per dir : 10
              threads share directories? : N
                         filename prefix : 
                         filename suffix : 
             hash file number into dir.? : N
                     fsync after modify? : N
          pause between files (microsec) : 0
                    finish all requests? : Y
                              stonewall? : Y
                 measure response times? : N
                            verify read? : Y
                                verbose? : False
                          log to stderr? : False
                           ext.attr.size : 0
                          ext.attr.count : 0
               permute host directories? : N
                remote program directory : /small-files/smallfile
               network thread sync. dir. : /gluster-mount/network_shared
starting all threads by creating starting gate file /gluster-mount/network_shared/starting_gate.tmp
host = gqac006.sbu.lab.eng.bos.redhat.com,thr = 00,elapsed = -1499777081.965670,files = 0,records = 0,status = ERR: Permission denied
host = gqac006.sbu.lab.eng.bos.redhat.com,thr = 01,elapsed = -1499777081.976919,files = 0,records = 0,status = ERR: Permission denied
host = gqac006.sbu.lab.eng.bos.redhat.com,thr = 02,elapsed = -1499777081.976804,files = 0,records = 0,status = ERR: Permission denied
host = gqac006.sbu.lab.eng.bos.redhat.com,thr = 03,elapsed = -1499777081.976993,files = 0,records = 0,status = ERR: Permission denied
host = gqac006.sbu.lab.eng.bos.redhat.com,thr = 04,elapsed = -1499777081.977319,files = 0,records = 0,status = ERR: Permission denied
host = gqac006.sbu.lab.eng.bos.redhat.com,thr = 05,elapsed = -1499777081.977191,files = 0,records = 0,status = ERR: Permission denied
host = gqac006.sbu.lab.eng.bos.redhat.com,thr = 06,elapsed = -1499777081.977044,files = 0,records = 0,status = ERR: Permission denied
host = gqac006.sbu.lab.eng.bos.redhat.com,thr = 07,elapsed = -1499777081.977497,files = 0,records = 0,status = ERR: Permission denied
host = gqac025.sbu.lab.eng.bos.redhat.com,thr = 00,elapsed = -1499777083.199119,files = 0,records = 0,status = ERR: Permission denied
host = gqac025.sbu.lab.eng.bos.redhat.com,thr = 01,elapsed = -1499777083.199166,files = 0,records = 0,status = ERR: Permission denied
host = gqac025.sbu.lab.eng.bos.redhat.com,thr = 02,elapsed = -1499777083.199351,files = 0,records = 0,status = ERR: Permission denied
host = gqac025.sbu.lab.eng.bos.redhat.com,thr = 03,elapsed = -1499777083.199384,files = 0,records = 0,status = ERR: Permission denied
host = gqac025.sbu.lab.eng.bos.redhat.com,thr = 04,elapsed = -1499777083.199855,files = 0,records = 0,status = ERR: Permission denied
host = gqac025.sbu.lab.eng.bos.redhat.com,thr = 05,elapsed = -1499777083.200094,files = 0,records = 0,status = ERR: Permission denied
host = gqac025.sbu.lab.eng.bos.redhat.com,thr = 06,elapsed = -1499777083.200609,files = 0,records = 0,status = ERR: Permission denied
host = gqac025.sbu.lab.eng.bos.redhat.com,thr = 07,elapsed = -1499777083.200980,files = 0,records = 0,status = ERR: Permission denied
host = gqac026.sbu.lab.eng.bos.redhat.com,thr = 00,elapsed = -1499777083.377028,files = 0,records = 0,status = ERR: Permission denied
host = gqac026.sbu.lab.eng.bos.redhat.com,thr = 01,elapsed = -1499777083.377371,files = 0,records = 0,status = ERR: Permission denied
host = gqac026.sbu.lab.eng.bos.redhat.com,thr = 02,elapsed = -1499777083.377461,files = 0,records = 0,status = ERR: Permission denied
host = gqac026.sbu.lab.eng.bos.redhat.com,thr = 03,elapsed = -1499777083.377809,files = 0,records = 0,status = ERR: Permission denied
host = gqac026.sbu.lab.eng.bos.redhat.com,thr = 04,elapsed = -1499777083.378299,files = 0,records = 0,status = ERR: Permission denied
host = gqac026.sbu.lab.eng.bos.redhat.com,thr = 05,elapsed = -1499777083.378584,files = 0,records = 0,status = ERR: Permission denied
host = gqac026.sbu.lab.eng.bos.redhat.com,thr = 06,elapsed = -1499777083.379124,files = 0,records = 0,status = ERR: Permission denied
host = gqac026.sbu.lab.eng.bos.redhat.com,thr = 07,elapsed = -1499777083.379233,files = 0,records = 0,status = ERR: Permission denied
host = gqac027.sbu.lab.eng.bos.redhat.com,thr = 00,elapsed = -1499777083.312093,files = 0,records = 0,status = ERR: Permission denied
host = gqac027.sbu.lab.eng.bos.redhat.com,thr = 01,elapsed = -1499777083.312346,files = 0,records = 0,status = ERR: Permission denied
host = gqac027.sbu.lab.eng.bos.redhat.com,thr = 02,elapsed = -1499777083.312302,files = 0,records = 0,status = ERR: Permission denied
host = gqac027.sbu.lab.eng.bos.redhat.com,thr = 03,elapsed = -1499777083.312386,files = 0,records = 0,status = ERR: Permission denied
host = gqac027.sbu.lab.eng.bos.redhat.com,thr = 04,elapsed = -1499777083.312767,files = 0,records = 0,status = ERR: Permission denied
host = gqac027.sbu.lab.eng.bos.redhat.com,thr = 05,elapsed = -1499777083.313294,files = 0,records = 0,status = ERR: Permission denied
host = gqac027.sbu.lab.eng.bos.redhat.com,thr = 06,elapsed = -1499777083.313696,files = 0,records = 0,status = ERR: Permission denied
host = gqac027.sbu.lab.eng.bos.redhat.com,thr = 07,elapsed = -1499777083.313883,files = 0,records = 0,status = ERR: Permission denied
total threads = 32
total files = 0
  0.00% of requested files processed, minimum is  70.00
at least one thread encountered error, test may be incomplete
[root@gqac006 ~]#

--- Additional comment from Worker Ant on 2017-08-02 04:49:27 EDT ---

REVIEW: https://review.gluster.org/17956 (md-cache: Fix use after free) posted (#1) for review on master by Poornima G (pgurusid)

--- Additional comment from Worker Ant on 2017-08-03 08:26:12 EDT ---

REVIEW: https://review.gluster.org/17967 (gfapi: Duplicate the buffer sent in setxattr calls) posted (#1) for review on master by Poornima G (pgurusid)

--- Additional comment from Worker Ant on 2017-08-04 01:12:59 EDT ---

REVIEW: https://review.gluster.org/17967 (gfapi: Duplicate the buffer sent in setxattr calls) posted (#2) for review on master by Poornima G (pgurusid)

--- Additional comment from Worker Ant on 2017-08-04 06:14:43 EDT ---

REVIEW: https://review.gluster.org/17967 (gfapi: Duplicate the buffer sent in setxattr calls) posted (#3) for review on master by Poornima G (pgurusid)

--- Additional comment from Worker Ant on 2017-08-06 08:03:16 EDT ---

REVIEW: https://review.gluster.org/17983 (core: remove memdup() and use gf_memdup() instead) posted (#1) for review on master by Niels de Vos (ndevos)

--- Additional comment from Worker Ant on 2017-08-06 08:36:47 EDT ---

REVIEW: https://review.gluster.org/17983 (core: remove memdup() and use gf_memdup() instead) posted (#2) for review on master by Niels de Vos (ndevos)

--- Additional comment from Worker Ant on 2017-08-07 01:19:33 EDT ---

REVIEW: https://review.gluster.org/17967 (gfapi: Duplicate the buffer sent in setxattr calls) posted (#4) for review on master by Poornima G (pgurusid)

--- Additional comment from Worker Ant on 2017-08-07 05:16:57 EDT ---

REVIEW: https://review.gluster.org/17967 (gfapi: Duplicate the buffer sent in setxattr calls) posted (#5) for review on master by Poornima G (pgurusid)

--- Additional comment from Worker Ant on 2017-08-07 12:28:49 EDT ---

COMMIT: https://review.gluster.org/17967 committed in master by Jeff Darcy (jeff.us) 
------
commit e11296f8e52b7e3b13d21b41d4fa34baea878edf
Author: Poornima G <pgurusid>
Date:   Thu Aug 3 17:43:22 2017 +0530

    gfapi: Duplicate the buffer sent in setxattr calls
    
    Issue:
    The caller of glfs_setxattr sends a buffer to set as the value.
    We create a dict in which the pointer to the value is set.
    Underlying layers like md-cache take a ref on this dict to store
    the value for a longer time. But the moment setxattr is complete,
    the caller of glfs_setxattr can free the value memory.
    
    Solution:
    memcpy the setxattr value to the gluster buffer.
    
    Change-Id: I58753fe702e8b7d0f6c4f058714c65d0ad5d7a0a
    BUG: 1477488
    Signed-off-by: Poornima G <pgurusid>
    Reviewed-on: https://review.gluster.org/17967
    Reviewed-by: soumya k <skoduri>
    Smoke: Gluster Build System <jenkins.org>
    CentOS-regression: Gluster Build System <jenkins.org>
    Reviewed-by: Jeff Darcy <jeff.us>
Comment 1 Worker Ant 2017-08-09 04:50:29 UTC 
REVIEW: https://review.gluster.org/18002 (gfapi: Duplicate the buffer sent in setxattr calls) posted (#1) for review on release-3.11 by Poornima G (pgurusid)
Comment 2 Worker Ant 2017-08-12 13:42:31 UTC 
COMMIT: https://review.gluster.org/18002 committed in release-3.11 by Shyamsundar Ranganathan (srangana) 
------
commit 3fe535afa61fa06c066e511c3c6e269902924296
Author: Poornima G <pgurusid>
Date:   Thu Aug 3 17:43:22 2017 +0530

    gfapi: Duplicate the buffer sent in setxattr calls
    
    Issue:
    The caller of glfs_setxattr sends a buffer to set as the value.
    We create a dict in which the pointer to the value is set.
    Underlying layers like md-cache take a ref on this dict to store
    the value for a longer time. But the moment setxattr is complete,
    the caller of glfs_setxattr can free the value memory.
    
    Solution:
    memcpy the setxattr value to the gluster buffer.
    
    > Reviewed-on: https://review.gluster.org/17967
    > Reviewed-by: soumya k <skoduri>
    > Smoke: Gluster Build System <jenkins.org>
    > CentOS-regression: Gluster Build System <jenkins.org>
    > Reviewed-by: Jeff Darcy <jeff.us>
    > (cherry picked from commit e11296f8e52b7e3b13d21b41d4fa34baea878edf)
    
    Change-Id: I58753fe702e8b7d0f6c4f058714c65d0ad5d7a0a
    BUG: 1479656
    Signed-off-by: Poornima G <pgurusid>
    Reviewed-on: https://review.gluster.org/18002
    Smoke: Gluster Build System <jenkins.org>
    CentOS-regression: Gluster Build System <jenkins.org>
    Reviewed-by: Shyamsundar Ranganathan <srangana>
Comment 3 Shyamsundar 2017-08-24 14:46:21 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.11.3, please open a new bug report.

glusterfs-3.11.3 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/announce/2017-August/000081.html
[2] https://www.gluster.org/pipermail/gluster-users/