Bug 1787086

Summary: All ACLs permission denied
Product: [Community] GlusterFS Reporter: jmilette
Component: access-controlAssignee: bugs <bugs>
Status: CLOSED UPSTREAM QA Contact:
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 7CC: bugs, csaba, jthottan, pasik, sabose
Target Milestone: ---Flags: csaba: needinfo-
Target Release: ---   
Hardware: armv7l   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2020-03-12 13:25:54 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:

Description jmilette 2019-12-30 21:59:06 UTC
Description of problem:


ACLs appear to always return permission denied:


jmilette@cube:~/mnt$ getfacl test
# file: test
# owner: gdm
# group: gdm
user::rwx
user:jmilette:rwx
group::r-x
mask::rwx
other::r-x

jmilette@cube:~/mnt$ ls test
ls: cannot open directory 'test': Permission denied


Glusterfs brick log from mount:


[2019-12-30 21:46:37.187382] I [addr.c:54:compare_addr_and_update] 0-/export/test: allowed = "*", received addr = "192.168.1.14"
[2019-12-30 21:46:37.187428] I [MSGID: 115029] [server-handshake.c:549:server_setvolume] 0-test-server: accepted client from CTX_ID:f0028cce-382c-487b-85d9-2a1b3452661b-GRAPH_ID:0-PID:6198-HOST:cube-PC_NAME:test-client-0-RECON_NO:-0 (version: 7.1) with subvol /export/test 
[2019-12-30 21:46:37.190606] I [rpcsvc.c:866:rpcsvc_handle_rpc_call] 0-rpc-service: spawned a request handler thread for queue 0
[2019-12-30 21:46:37.193741] I [rpcsvc.c:866:rpcsvc_handle_rpc_call] 0-rpc-service: spawned a request handler thread for queue 1
[2019-12-30 21:46:41.231121] I [MSGID: 139001] [posix-acl.c:262:posix_acl_log_permit_denied] 0-test-access-control: client: CTX_ID:f0028cce-382c-487b-85d9-2a1b3452661b-GRAPH_ID:0-PID:6198-HOST:cube-PC_NAME:test-client-0-RECON_NO:-0, gfid: 3b2b30ad-39d8-4078-9f14-c5fae262d89c, req(uid:1000,gid:1000,perm:4,ngrps:10), ctx(uid:0,gid:0,in-groups:0,perm:775,updated-fop:READDIRP, acl:(tag:1,perm:7,id:458754)(tag:4,perm:5,id:1000)(tag:65535,perm:65535,id:4294967295)(tag:16,perm:7,id:4294967295)(tag:32,perm:5,id:4294967295) [Permission denied]
[2019-12-30 21:46:41.231220] E [MSGID: 115056] [server-rpc-fops_v2.c:686:server4_opendir_cbk] 0-test-server: 135: OPENDIR /test (3b2b30ad-39d8-4078-9f14-c5fae262d89c), client: CTX_ID:f0028cce-382c-487b-85d9-2a1b3452661b-GRAPH_ID:0-PID:6198-HOST:cube-PC_NAME:test-client-0-RECON_NO:-0, error-xlator: test-access-control [Permission denied]
[2019-12-30 21:46:42.728556] I [MSGID: 139001] [posix-acl.c:262:posix_acl_log_permit_denied] 0-test-access-control: client: CTX_ID:f0028cce-382c-487b-85d9-2a1b3452661b-GRAPH_ID:0-PID:6198-HOST:cube-PC_NAME:test-client-0-RECON_NO:-0, gfid: 3b2b30ad-39d8-4078-9f14-c5fae262d89c, req(uid:1000,gid:1000,perm:4,ngrps:10), ctx(uid:0,gid:0,in-groups:0,perm:775,updated-fop:LOOKUP, acl:(tag:1,perm:7,id:458754)(tag:4,perm:5,id:1000)(tag:65535,perm:65535,id:4294967295)(tag:16,perm:7,id:4294967295)(tag:32,perm:5,id:4294967295) [Permission denied]
[2019-12-30 21:46:42.728643] E [MSGID: 115056] [server-rpc-fops_v2.c:686:server4_opendir_cbk] 0-test-server: 139: OPENDIR /test (3b2b30ad-39d8-4078-9f14-c5fae262d89c), client: CTX_ID:f0028cce-382c-487b-85d9-2a1b3452661b-GRAPH_ID:0-PID:6198-HOST:cube-PC_NAME:test-client-0-RECON_NO:-0, error-xlator: test-access-control [Permission denied]
[2019-12-30 21:49:05.249906] I [MSGID: 139001] [posix-acl.c:262:posix_acl_log_permit_denied] 0-test-access-control: client: CTX_ID:f0028cce-382c-487b-85d9-2a1b3452661b-GRAPH_ID:0-PID:6198-HOST:cube-PC_NAME:test-client-0-RECON_NO:-0, gfid: e41a0667-9fbc-4817-bfee-2461fe47a91f, req(uid:1000,gid:1000,perm:1,ngrps:10), ctx(uid:124,gid:129,in-groups:0,perm:775,updated-fop:READDIRP, acl:(tag:1,perm:7,id:458754)(tag:4,perm:5,id:1000)(tag:65535,perm:65535,id:4294967295)(tag:16,perm:7,id:4294967295)(tag:32,perm:5,id:4294967295) [Permission denied]
[2019-12-30 21:49:05.250030] E [MSGID: 115050] [server-rpc-fops_v2.c:157:server4_lookup_cbk] 0-test-server: 277: LOOKUP /test/test (e41a0667-9fbc-4817-bfee-2461fe47a91f/test), client: CTX_ID:f0028cce-382c-487b-85d9-2a1b3452661b-GRAPH_ID:0-PID:6198-HOST:cube-PC_NAME:test-client-0-RECON_NO:-0, error-xlator: test-access-control [Permission denied]
[2019-12-30 21:49:05.251190] E [MSGID: 115050] [server-rpc-fops_v2.c:157:server4_lookup_cbk] 0-test-server: 278: LOOKUP /test/test (e41a0667-9fbc-4817-bfee-2461fe47a91f/test), client: CTX_ID:f0028cce-382c-487b-85d9-2a1b3452661b-GRAPH_ID:0-PID:6198-HOST:cube-PC_NAME:test-client-0-RECON_NO:-0, error-xlator: test-access-control [Permission denied]
[2019-12-30 21:49:06.606280] I [MSGID: 139001] [posix-acl.c:262:posix_acl_log_permit_denied] 0-test-access-control: client: CTX_ID:f0028cce-382c-487b-85d9-2a1b3452661b-GRAPH_ID:0-PID:6198-HOST:cube-PC_NAME:test-client-0-RECON_NO:-0, gfid: e41a0667-9fbc-4817-bfee-2461fe47a91f, req(uid:1000,gid:1000,perm:4,ngrps:10), ctx(uid:124,gid:129,in-groups:0,perm:775,updated-fop:READDIRP, acl:(tag:1,perm:7,id:458754)(tag:4,perm:5,id:1000)(tag:65535,perm:65535,id:4294967295)(tag:16,perm:7,id:4294967295)(tag:32,perm:5,id:4294967295) [Permission denied]
[2019-12-30 21:49:06.606370] E [MSGID: 115056] [server-rpc-fops_v2.c:686:server4_opendir_cbk] 0-test-server: 280: OPENDIR /test (e41a0667-9fbc-4817-bfee-2461fe47a91f), client: CTX_ID:f0028cce-382c-487b-85d9-2a1b3452661b-GRAPH_ID:0-PID:6198-HOST:cube-PC_NAME:test-client-0-RECON_NO:-0, error-xlator: test-access-control [Permission denied]
[2019-12-30 21:49:05.251142] I [MSGID: 139001] [posix-acl.c:262:posix_acl_log_permit_denied] 0-test-access-control: client: CTX_ID:f0028cce-382c-487b-85d9-2a1b3452661b-GRAPH_ID:0-PID:6198-HOST:cube-PC_NAME:test-client-0-RECON_NO:-0, gfid: e41a0667-9fbc-4817-bfee-2461fe47a91f, req(uid:1000,gid:1000,perm:1,ngrps:10), ctx(uid:124,gid:129,in-groups:0,perm:775,updated-fop:READDIRP, acl:(tag:1,perm:7,id:458754)(tag:4,perm:5,id:1000)(tag:65535,perm:65535,id:4294967295)(tag:16,perm:7,id:4294967295)(tag:32,perm:5,id:4294967295) [Permission denied]
[2019-12-30 21:54:29.493617] I [MSGID: 139001] [posix-acl.c:262:posix_acl_log_permit_denied] 0-test-access-control: client: CTX_ID:f0028cce-382c-487b-85d9-2a1b3452661b-GRAPH_ID:0-PID:6198-HOST:cube-PC_NAME:test-client-0-RECON_NO:-0, gfid: e41a0667-9fbc-4817-bfee-2461fe47a91f, req(uid:1000,gid:1000,perm:4,ngrps:10), ctx(uid:124,gid:129,in-groups:0,perm:775,updated-fop:LOOKUP, acl:(tag:1,perm:7,id:458754)(tag:4,perm:5,id:1000)(tag:65535,perm:65535,id:4294967295)(tag:16,perm:7,id:4294967295)(tag:32,perm:5,id:4294967295) [Permission denied]
[2019-12-30 21:54:29.493734] E [MSGID: 115056] [server-rpc-fops_v2.c:686:server4_opendir_cbk] 0-test-server: 331: OPENDIR /test (e41a0667-9fbc-4817-bfee-2461fe47a91f), client: CTX_ID:f0028cce-382c-487b-85d9-2a1b3452661b-GRAPH_ID:0-PID:6198-HOST:cube-PC_NAME:test-client-0-RECON_NO:-0, error-xlator: test-access-control [Permission denied]
[2019-12-30 21:54:32.824240] E [MSGID: 115056] [server-rpc-fops_v2.c:686:server4_opendir_cbk] 0-test-server: 335: OPENDIR /test (e41a0667-9fbc-4817-bfee-2461fe47a91f), client: CTX_ID:f0028cce-382c-487b-85d9-2a1b3452661b-GRAPH_ID:0-PID:6198-HOST:cube-PC_NAME:test-client-0-RECON_NO:-0, error-xlator: test-access-control [Permission denied]






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

I've tested versions 4.1 all the way to 7.1, all are affected.  This breaks Samba :(


How reproducible:

Always


Steps to Reproduce:
1.  Create folder/files on ARMv7l, set acls
2.  Attempt to access using above set acls
3.  Access denied

Actual results:

ACLs do not function, and always return "permission denied"

Expected results:

ACLs should function on armv7l

Additional info:

The exact hardware I am using are the ODROID-HC2 boards:  https://ameridroid.com/products/odroid-hc2

Comment 1 jmilette 2019-12-30 22:00:05 UTC
Additional details:

XFS is the backing filesystem, and ACLs work correctly when issued from the nodes directly.

Comment 2 Sahina Bose 2020-01-02 08:02:07 UTC
Can you take a look?

Comment 3 Jiffin 2020-01-03 09:52:34 UTC
req(uid:1000,gid:1000,perm:4,ngrps:10), ctx(uid:0,gid:0,in-groups:0,perm:775  does not look any suspicious apart from when compare value from the getfacl. In getfacl uid/gid belongs to gdm and there is an ingroup value as well. But from the log, it says user/group for "test" is root. Can u please the value directly(getfacl) from the backend instead of mount

Comment 4 jmilette 2020-01-03 14:10:25 UTC
root@gfs-node-01:/export/test# getfacl ./test
# file: test
# owner: 124
# group: 129
user::rwx
user:1000:rwx
group::r-x
mask::rwx
other::r-x

root@gfs-node-01:/export/test# ls -la
total 0
drwxrwxrwx  4 root root  48 Dec 30 16:47 .
drwxr-xr-x  6 root root 104 Dec 30 16:40 ..
drw-------  9 root root 155 Dec 30 16:47 .glusterfs
drwxrwxr-x+ 2  124  129  10 Dec 30 16:47 test


the UID 124 is GDM, as well as GID 129 is also GDM from the PC mounting it:

jmilette@cube:~$ id gdm
uid=124(gdm) gid=129(gdm) groups=129(gdm)

Comment 5 Jiffin 2020-01-07 14:27:30 UTC
can u share the acl for the parent directory as well.

Comment 6 jmilette 2020-01-07 23:52:26 UTC
Sure thing.

the full path of the above file is /export/test/test

This is on the directory.


root@gfs-node-01:/export# getfacl ./test
# file: test
# owner: root
# group: root
user::rwx
group::rwx
other::rwx

Comment 7 Jiffin 2020-01-08 06:47:29 UTC
[2019-12-30 21:46:41.231121] I [MSGID: 139001] [posix-acl.c:262:posix_acl_log_permit_denied] 0-test-access-control: client: CTX_ID:f0028cce-382c-487b-85d9-2a1b3452661b-GRAPH_ID:0-PID:6198-HOST:cube-PC_NAME:test-client-0-RECON_NO:-0, gfid: 3b2b30ad-39d8-4078-9f14-c5fae262d89c, req(uid:1000,gid:1000,perm:4,ngrps:10), ctx(uid:0,gid:0,in-groups:0,perm:775,updated-fop:READDIRP, acl:(tag:1,perm:7,id:458754)(tag:4,perm:5,id:1000)(tag:65535,perm:65535,id:4294967295)(tag:16,perm:7,id:4294967295)(tag:32,perm:5,id:4294967295) [Permission denied]
[2019-12-30 21:46:41.231220] E [MSGID: 115056] [server-rpc-fops_v2.c:686:server4_opendir_cbk] 0-test-server: 135: OPENDIR /test (3b2b30ad-39d8-4078-9f14-c5fae262d89c), client: CTX_ID:f0028cce-382c-487b-85d9-2a1b3452661b-GRAPH_ID:0-PID:6198-HOST:cube-PC_NAME:test-client-0-RECON_NO:-0, error-xlator: test-access-control [Permission denied]
[2019-12-30 21:46:42.728556] I [MSGID: 139001] [posix-acl.c:262:posix_acl_log_permit_denied] 0-test-access-control: client: CTX_ID:f0028cce-382c-487b-85d9-2a1b3452661b-GRAPH_ID:0-PID:6198-HOST:cube-PC_NAME:test-client-0-RECON_NO:-0, gfid: 3b2b30ad-39d8-4078-9f14-c5fae262d89c, req(uid:1000,gid:1000,perm:4,ngrps:10), ctx(uid:0,gid:0,in-groups:0,perm:775,updated-fop:LOOKUP, acl:(tag:1,perm:7,id:458754)(tag:4,perm:5,id:1000)(tag:65535,perm:65535,id:4294967295)(tag:16,perm:7,id:4294967295)(tag:32,perm:5,id:4294967295) [Permission denied]
[2019-12-30 21:46:42.728643] E [MSGID: 115056] [server-rpc-fops_v2.c:686:server4_opendir_cbk] 0-test-server: 139: OPENDIR /test (3b2b30ad-39d8-4078-9f14-c5fae262d89c), client: CTX_ID:f0028cce-382c-487b-85d9-2a1b3452661b-GRAPH_ID:0-PID:6198-HOST:cube-PC_NAME:test-client-0-RECON_NO:-0, error-xlator: test-access-control [Permission denied]
[2019-12-30 21:49:05.249906] I [MSGID: 139001] [posix-acl.c:262:posix_acl_log_permit_denied] 0-test-access-control: client: CTX_ID:f0028cce-382c-487b-85d9-2a1b3452661b-GRAPH_ID:0-PID:6198-HOST:cube-PC_NAME:test-client-0-RECON_NO:-0, gfid: e41a0667-9fbc-4817-bfee-2461fe47a91f, req(uid:1000,gid:1000,perm:1,ngrps:10), ctx(uid:124,gid:129,in-groups:0,perm:775,updated-fop:READDIRP, acl:(tag:1,perm:7,id:458754)(tag:4,perm:5,id:1000)(tag:65535,perm:65535,id:4294967295)(tag:16,perm:7,id:4294967295)(tag:32,perm:5,id:4294967295) [Permission denied]
[2019-12-30 21:49:05.250030] E [MSGID: 115050] [server-rpc-fops_v2.c:157:server4_lookup_cbk] 0-test-server: 277: LOOKUP /test/test (e41a0667-9fbc-4817-bfee-2461fe47a91f/test), client: CTX_ID:f0028cce-382c-487b-85d9-2a1b3452661b-GRAPH_ID:0-PID:6198-HOST:cube-PC_NAME:test-client-0-RECON_NO:-0, error-xlator: test-access-control [Permission denied]
[2019-12-30 21:49:05.251190] E [MSGID: 115050] [server-rpc-fops_v2.c:157:server4_lookup_cbk] 0-test-server: 278: LOOKUP /test/test (e41a0667-9fbc-4817-bfee-2461fe47a91f/test), client: CTX_ID:f0028cce-382c-487b-85d9-2a1b3452661b-GRAPH_ID:0-PID:6198-HOST:cube-PC_NAME:test-client-0-RECON_NO:-0, error-xlator: test-access-control [Permission denied]


Here the first opendir on parent directory "test" got failed, user was 1000(jmilette I guess), from the logs the on the gluster's brick context (uid:0,gid:0,in-groups:0,perm:775), permission is 0775 but at backend it seems to 777. Hence rejection happened. Am I not sure whether umask is getting to picture here or not. And follow lookup operation is also failed /test/test mostly because of the first failure. Not sure why absolute path is send from fuse even lookup was performed using relative path. My suspicion is because of getfacl worked without any error from fuse mount on the same file.

Comment 8 jmilette 2020-01-09 02:02:21 UTC
Ok - just for clarification's sake, is this something I can fix myself, or is this a glusterfs issue as I originally thought?  In my tests with XFS/EXT4/ZFS acls act normally (i.e. the above scenario is permission granted) so I'm assuming this is still an issue with glusterfs.

Comment 9 Jiffin 2020-01-09 05:46:07 UTC
(In reply to jmilette from comment #8)
> Ok - just for clarification's sake, is this something I can fix myself, or
> is this a glusterfs issue as I originally thought?  In my tests with
> XFS/EXT4/ZFS acls act normally (i.e. the above scenario is permission
> granted) so I'm assuming this is still an issue with glusterfs.

U can try setting permission for user 1000(jmilette) on parent directory and see if it works or not.

What type of client are testing with fuse or smb, accordingly I can raise the needinfo on the maintainer to know why lookup is being performed on absolute path than relative path?

Comment 10 jmilette 2020-01-09 13:32:48 UTC
Ok sounds good - changing the user won't work for my use case unfortunately.  I am testing with fuse.

Comment 11 Jiffin 2020-01-09 13:38:57 UTC
Rasing needinfo on Csaba to please explain whether fuse client resolve relative path into absolute.

Comment 12 Worker Ant 2020-03-03 19:59:24 UTC
REVIEW: https://review.gluster.org/24200 (utime: resolve an issue of permission denied logs) posted (#1) for review on master by Amar Tumballi

Comment 13 Worker Ant 2020-03-11 09:51:05 UTC
REVIEW: https://review.gluster.org/24200 (utime: resolve an issue of permission denied logs) posted (#3) for review on master by Amar Tumballi

Comment 14 Worker Ant 2020-03-12 13:25:54 UTC
This bug is moved to https://github.com/gluster/glusterfs/issues/1015, and will be tracked there from now on. Visit GitHub issues URL for further details