[Gluster-users] cluster brick logs filling after upgrade from 3.6 to 3.12
Paul Allen
paul at inetz.com
Wed May 23 06:32:03 UTC 2018
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
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.gluster.org/pipermail/gluster-users/attachments/20180523/5077f532/attachment.html>
More information about the Gluster-users
mailing list