Recently we updated a Gluster replicated setup from 3.6 to 3.12 (stepping
through 3.8 first before going to 3.12).
Afterwards I noticed the brick logs were filling at an alarming rate on the
server we have the NFS service running from:
$ sudo tail -20 /var/log/glusterfs/bricks/export-gluster-shared.log
[2018-05-23 06:22:12.405240] I [MSGID: 139001]
[posix-acl.c:269:posix_acl_log_permit_denied] 0-sharedvol-access-control:
client: mfc-nas1-14785-2018/05/23-06:10:20:243359-sharedvol-client-0-0-0, gfid:
59d4c3da-9943-469e-9694-b14ca348007b, req(uid:33,gid:33,perm:2,ngrps:1),
ctx(uid:1002,gid:100,in-groups:0,perm:664,updated-fop:LOOKUP, acl:-)
[Permission denied]
[2018-05-23 06:22:12.405284] I [MSGID: 139001]
[posix-acl.c:269:posix_acl_log_permit_denied] 0-sharedvol-access-control:
client: mfc-nas1-14785-2018/05/23-06:10:20:243359-sharedvol-client-0-0-0, gfid:
59d4c3da-9943-469e-9694-b14ca348007b, req(uid:33,gid:33,perm:1,ngrps:1),
ctx(uid:1002,gid:100,in-groups:0,perm:664,updated-fop:LOOKUP, acl:-)
[Permission denied]
[2018-05-23 06:22:12.410581] I [MSGID: 139001]
[posix-acl.c:269:posix_acl_log_permit_denied] 0-sharedvol-access-control:
client: mfc-nas1-14785-2018/05/23-06:10:20:243359-sharedvol-client-0-0-0, gfid:
d978d132-0c95-4a67-9bf4-21cfc87746ba, req(uid:33,gid:33,perm:2,ngrps:1),
ctx(uid:1002,gid:100,in-groups:0,perm:664,updated-fop:LOOKUP, acl:-)
[Permission denied]
[2018-05-23 06:22:12.410624] I [MSGID: 139001]
[posix-acl.c:269:posix_acl_log_permit_denied] 0-sharedvol-access-control:
client: mfc-nas1-14785-2018/05/23-06:10:20:243359-sharedvol-client-0-0-0, gfid:
d978d132-0c95-4a67-9bf4-21cfc87746ba, req(uid:33,gid:33,perm:1,ngrps:1),
ctx(uid:1002,gid:100,in-groups:0,perm:664,updated-fop:LOOKUP, acl:-)
[Permission denied]
[2018-05-23 06:22:12.411382] I [MSGID: 139001]
[posix-acl.c:269:posix_acl_log_permit_denied] 0-sharedvol-access-control:
client: mfc-nas1-14785-2018/05/23-06:10:20:243359-sharedvol-client-0-0-0, gfid:
b75fcfce-b0ed-48f7-b927-6d0c805b8c49, req(uid:33,gid:33,perm:2,ngrps:1),
ctx(uid:1002,gid:100,in-groups:0,perm:775,updated-fop:LOOKUP, acl:-)
[Permission denied]
[2018-05-23 06:22:12.412903] I [MSGID: 139001]
[posix-acl.c:269:posix_acl_log_permit_denied] 0-sharedvol-access-control:
client: mfc-nas1-14785-2018/05/23-06:10:20:243359-sharedvol-client-0-0-0, gfid:
f5a73dcd-6ad2-4952-a98e-86c76fc30847, req(uid:33,gid:33,perm:2,ngrps:1),
ctx(uid:1002,gid:100,in-groups:0,perm:775,updated-fop:LOOKUP, acl:-)
[Permission denied]
[2018-05-23 06:22:12.413941] I [MSGID: 139001]
[posix-acl.c:269:posix_acl_log_permit_denied] 0-sharedvol-access-control:
client: mfc-nas1-14785-2018/05/23-06:10:20:243359-sharedvol-client-0-0-0, gfid:
4c7f51fc-fd92-44fc-95a1-b49e177a3545, req(uid:33,gid:33,perm:2,ngrps:1),
ctx(uid:1002,gid:100,in-groups:0,perm:775,updated-fop:LOOKUP, acl:-)
[Permission denied]
[2018-05-23 06:22:12.415360] I [MSGID: 139001]
[posix-acl.c:269:posix_acl_log_permit_denied] 0-sharedvol-access-control:
client: mfc-nas1-14785-2018/05/23-06:10:20:243359-sharedvol-client-0-0-0, gfid:
a0da63c1-a7e6-412a-b6cb-732b8e74a85d, req(uid:33,gid:33,perm:2,ngrps:1),
ctx(uid:1002,gid:100,in-groups:0,perm:664,updated-fop:LOOKUP, acl:-)
[Permission denied]
[2018-05-23 06:22:12.415405] I [MSGID: 139001]
[posix-acl.c:269:posix_acl_log_permit_denied] 0-sharedvol-access-control:
client: mfc-nas1-14785-2018/05/23-06:10:20:243359-sharedvol-client-0-0-0, gfid:
a0da63c1-a7e6-412a-b6cb-732b8e74a85d, req(uid:33,gid:33,perm:1,ngrps:1),
ctx(uid:1002,gid:100,in-groups:0,perm:664,updated-fop:LOOKUP, acl:-)
[Permission denied]
[2018-05-23 06:22:12.418244] I [MSGID: 139001]
[posix-acl.c:269:posix_acl_log_permit_denied] 0-sharedvol-access-control:
client: mfc-nas1-14785-2018/05/23-06:10:20:243359-sharedvol-client-0-0-0, gfid:
dff386f8-d59b-4b94-ad5d-be9a54c65342, req(uid:33,gid:33,perm:2,ngrps:1),
ctx(uid:1002,gid:100,in-groups:0,perm:775,updated-fop:LOOKUP, acl:-)
[Permission denied]
[2018-05-23 06:22:12.419225] I [MSGID: 139001]
[posix-acl.c:269:posix_acl_log_permit_denied] 0-sharedvol-access-control:
client: mfc-nas1-14785-2018/05/23-06:10:20:243359-sharedvol-client-0-0-0, gfid:
c8f8fe1f-42b7-4e3b-a9b2-f9b8917e4d57, req(uid:33,gid:33,perm:2,ngrps:1),
ctx(uid:1002,gid:100,in-groups:0,perm:775,updated-fop:LOOKUP, acl:-)
[Permission denied]
[2018-05-23 06:22:12.420422] I [MSGID: 139001]
[posix-acl.c:269:posix_acl_log_permit_denied] 0-sharedvol-access-control:
client: mfc-nas1-14785-2018/05/23-06:10:20:243359-sharedvol-client-0-0-0, gfid:
a5a913d5-f6de-4437-aa23-6bf430159533, req(uid:33,gid:33,perm:2,ngrps:1),
ctx(uid:1002,gid:100,in-groups:0,perm:775,updated-fop:LOOKUP, acl:-)
[Permission denied]
[2018-05-23 06:22:12.421641] I [MSGID: 139001]
[posix-acl.c:269:posix_acl_log_permit_denied] 0-sharedvol-access-control:
client: mfc-nas1-14785-2018/05/23-06:10:20:243359-sharedvol-client-0-0-0, gfid:
ce203850-6d98-46d8-8789-d5796f09da57, req(uid:33,gid:33,perm:2,ngrps:1),
ctx(uid:1002,gid:100,in-groups:0,perm:775,updated-fop:LOOKUP, acl:-)
[Permission denied]
[2018-05-23 06:22:12.422428] I [MSGID: 139001]
[posix-acl.c:269:posix_acl_log_permit_denied] 0-sharedvol-access-control:
client: mfc-nas1-14785-2018/05/23-06:10:20:243359-sharedvol-client-0-0-0, gfid:
38ed6fb4-fc75-4c7c-bf88-db8db03665b2, req(uid:33,gid:33,perm:2,ngrps:1),
ctx(uid:1002,gid:100,in-groups:0,perm:775,updated-fop:LOOKUP, acl:-)
[Permission denied]
[2018-05-23 06:22:12.539753] I [MSGID: 139001]
[posix-acl.c:269:posix_acl_log_permit_denied] 0-sharedvol-access-control:
client: mfc-nas1-14785-2018/05/23-06:10:20:243359-sharedvol-client-0-0-0, gfid:
ab44763e-3739-4370-aaf7-d0d390e70c5d, req(uid:20000,gid:20000,perm:1,ngrps:1),
ctx(uid:20000,gid:20000,in-groups:1,perm:674,updated-fop:LOOKUP,
acl:(tag:1,perm:6,id:4294967295)(tag:2,perm:7,id:10437)(tag:4,perm:7,id:4294967295)(tag:16,perm:7,id:4294967295)(tag:32,perm:4,id:4294967295)
[Permission denied]
[2018-05-23 06:22:12.947762] I [MSGID: 139001]
[posix-acl.c:269:posix_acl_log_permit_denied] 0-sharedvol-access-control:
client: mfc-nas1-14785-2018/05/23-06:10:20:243359-sharedvol-client-0-0-0, gfid:
839a087e-4997-4140-ac4f-aafbf1bb9e3b, req(uid:33,gid:33,perm:1,ngrps:1),
ctx(uid:33,gid:0,in-groups:0,perm:644,updated-fop:SETATTR, acl:-) [Permission
denied]
The message "I [MSGID: 139001] [posix-acl.c:269:posix_acl_log_permit_denied]
0-sharedvol-access-control: client:
mfc-nas1-14785-2018/05/23-06:10:20:243359-sharedvol-client-0-0-0, gfid:
839a087e-4997-4140-ac4f-aafbf1bb9e3b, req(uid:33,gid:33,perm:1,ngrps:1),
ctx(uid:33,gid:0,in-groups:0,perm:644,updated-fop:SETATTR, acl:-) [Permission
denied]" repeated 2 times between [2018-05-23 06:22:12.947762] and [2018-05-23
06:22:13.145374]
[2018-05-23 06:22:13.200285] I [MSGID: 139001]
[posix-acl.c:269:posix_acl_log_permit_denied] 0-sharedvol-access-control:
client: mfc-nas1-14785-2018/05/23-06:10:20:243359-sharedvol-client-0-0-0, gfid:
bf1b4131-ce67-4ae8-8c54-fab53aed117f, req(uid:33,gid:33,perm:2,ngrps:1),
ctx(uid:0,gid:0,in-groups:0,perm:755,updated-fop:READDIRP, acl:-) [Permission
denied]
[2018-05-23 06:22:13.200342] I [MSGID: 139001]
[posix-acl.c:269:posix_acl_log_permit_denied] 0-sharedvol-access-control:
client: mfc-nas1-14785-2018/05/23-06:10:20:243359-sharedvol-client-0-0-0, gfid:
bf1b4131-ce67-4ae8-8c54-fab53aed117f, req(uid:33,gid:33,perm:2,ngrps:1),
ctx(uid:0,gid:0,in-groups:0,perm:755,updated-fop:READDIRP, acl:-) [Permission
denied]
[2018-05-23 06:22:13.201385] I [MSGID: 139001]
[posix-acl.c:269:posix_acl_log_permit_denied] 0-sharedvol-access-control:
client: mfc-nas1-14785-2018/05/23-06:10:20:243359-sharedvol-client-0-0-0, gfid:
839a087e-4997-4140-ac4f-aafbf1bb9e3b, req(uid:33,gid:33,perm:1,ngrps:1),
ctx(uid:33,gid:0,in-groups:0,perm:644,updated-fop:SETATTR, acl:-) [Permission
denied]
There are not any issues with the actual file access, everything is working as
it should be from the clients which are all mounting to the Gluster NFS process
on the main server. So far I have tried lowering the log level for both the
bricks and the clients to CRITICAL but the messages were still pouring in,
checked to make sure there aren’t any ACL’s set on the files in the first place
(the vast majority of them have no ACL set on them), and even tried restarting
the servers as a desperate attempt to get them working right. We did not have
this problem on 3.6, and we have other 3.12 Gluster setups that are similarly
configured that are not having this issue either. The only difference with
those is we did not go from 3.6 to 3.12, at most we went from 3.8 to 3.10 then
to 3.12. I have another setup running 3.6 still that I need to do an update on
pretty soon here and really don’t want to have this happening on that one as
well.
Here are the NFS settings for the volume in Gluster:
$ sudo gluster volume get sharedvol all | grep nfs
performance.nfs.flush-behind on
performance.nfs.write-behind-window-size1MB
performance.nfs.strict-o-direct off
performance.nfs.strict-write-ordering off
performance.nfs.write-behind on
performance.nfs.read-ahead off
performance.nfs.io-cache off
performance.nfs.quick-read off
performance.nfs.stat-prefetch off
performance.nfs.io-threads off
nfs.enable-ino32 no
nfs.mem-factor 15
nfs.export-dirs on
nfs.export-volumes on
nfs.addr-namelookup off
nfs.dynamic-volumes off
nfs.register-with-portmap on
nfs.outstanding-rpc-limit 16
nfs.port 2049
nfs.rpc-auth-unix on
nfs.rpc-auth-null on
nfs.rpc-auth-allow all
nfs.rpc-auth-reject none
nfs.ports-insecure off
nfs.trusted-sync off
nfs.trusted-write off
nfs.volume-access read-write
nfs.export-dir
nfs.disable off
nfs.nlm on
nfs.acl on
nfs.mount-udp off
nfs.mount-rmtab /var/lib/glusterd/nfs/rmtab
nfs.rpc-statd /sbin/rpc.statd
nfs.server-aux-gids off
nfs.drc off
nfs.drc-size 0x20000
nfs.read-size (1 * 1048576ULL)
nfs.write-size (1 * 1048576ULL)
nfs.readdir-size (1 * 1048576ULL)
nfs.rdirplus on
nfs.exports-auth-enable (null)
nfs.auth-refresh-interval-sec (null)
nfs.auth-cache-ttl-sec (null)
cluster.halo-nfsd-max-latency 5
I’ve tried searching on this but have found virtually no information that comes
even close to this issue aside from this very old bug report for 3.4:
https://bugzilla.redhat.com/show_bug.cgi?id=862908
<https://bugzilla.redhat.com/show_bug.cgi?id=862908>
Any help would be greatly appreciated.
Paul
_______________________________________________
Gluster-users mailing list
Gluster-users@gluster.org
http://lists.gluster.org/mailman/listinfo/gluster-users
