[Gluster-users] gluster 6.8: brick logs flooded by Information messages

Tue Apr 21 07:55:49 UTC 2020

well, the log entries still appear, up to tens of millions log entries
in the brick logs. Do they appear simply because the ctime feature is
enabled in v6 by default?

https://docs.gluster.org/en/latest/release-notes/6.0/#7-ctime-feature-is-enabled-by-default

So if the problems solves itself when sooner or later for every
file/dir the ctime-mdata is set, it should be a matter of time, right?

Best regards,
Hubert

Am Sa., 11. Apr. 2020 um 15:38 Uhr schrieb Hu Bert <revirii at googlemail.com>:
>
> as i wrote in the opening post: the previous version was 5.11.
>
> Best regards,
> Hubert
>
> Am Sa., 11. Apr. 2020 um 13:25 Uhr schrieb Strahil Nikolov
> <hunter86_bg at yahoo.com>:
> >
> > On April 11, 2020 2:06:22 PM GMT+03:00, Hu Bert <revirii at googlemail.com> wrote:
> > >Hi Strahil,
> > >
> > >looking into the mount logs i think i see the same (or at least very
> > >similar) log messages:
> > >
> > >[2020-04-11 11:01:21.676613] I [MSGID: 108031]
> > >[afr-common.c:2548:afr_local_discovery_cbk] 0-workdata-replicate-0:
> > >selecting local read_child workdata-client-0
> > >[2020-04-11 11:01:21.791039] W [MSGID: 114031]
> > >[client-rpc-fops_v2.c:851:client4_0_setxattr_cbk] 0-workdata-client-0:
> > >remote operation failed [Permission denied]
> > >[2020-04-11 11:01:21.791099] W [MSGID: 114031]
> > >[client-rpc-fops_v2.c:851:client4_0_setxattr_cbk] 0-workdata-client-1:
> > >remote operation failed [Permission denied]
> > >[2020-04-11 11:01:21.791172] W [MSGID: 114031]
> > >[client-rpc-fops_v2.c:851:client4_0_setxattr_cbk] 0-workdata-client-2:
> > >remote operation failed [Permission denied]
> > >[2020-04-11 11:01:21.791598] E [MSGID: 148002]
> > >[utime.c:146:gf_utime_set_mdata_setxattr_cbk] 0-workdata-utime: dict
> > >set of key for set-ctime-mdata failed [Permission denied]
> > >The message "I [MSGID: 108031]
> > >[afr-common.c:2548:afr_local_discovery_cbk] 0-workdata-replicate-0:
> > >selecting local read_child workdata-client-0" repeated 947 times
> > >between [2020-04-11 11:01:21.676613] and [2020-04-11 11:03:21.405740]
> > >The message "W [MSGID: 114031]
> > >[client-rpc-fops_v2.c:851:client4_0_setxattr_cbk] 0-workdata-client-0:
> > >remote operation failed [Permission denied]" repeated 3947 times
> > >between [2020-04-11 11:01:21.791039] and [2020-04-11 11:03:21.443929]
> > >The message "W [MSGID: 114031]
> > >[client-rpc-fops_v2.c:851:client4_0_setxattr_cbk] 0-workdata-client-2:
> > >remote operation failed [Permission denied]" repeated 3947 times
> > >between [2020-04-11 11:01:21.791172] and [2020-04-11 11:03:21.443958]
> > >The message "W [MSGID: 114031]
> > >[client-rpc-fops_v2.c:851:client4_0_setxattr_cbk] 0-workdata-client-1:
> > >remote operation failed [Permission denied]" repeated 3947 times
> > >between [2020-04-11 11:01:21.791099] and [2020-04-11 11:03:21.444008]
> > >The message "E [MSGID: 148002]
> > >[utime.c:146:gf_utime_set_mdata_setxattr_cbk] 0-workdata-utime: dict
> > >set of key for set-ctime-mdata failed [Permission denied]" repeated
> > >3947 times between [2020-04-11 11:01:21.791598] and [2020-04-11
> > >11:03:21.444357]
> > >
> > >Best regards,
> > >Hubert
> > >
> > >Am Sa., 11. Apr. 2020 um 11:11 Uhr schrieb Strahil Nikolov
> > ><hunter86_bg at yahoo.com>:
> > >>
> > >> On April 11, 2020 8:35:41 AM GMT+03:00, Hu Bert
> > ><revirii at googlemail.com> wrote:
> > >> >Hi,
> > >> >
> > >> >this week i upgraded from 5.11 to 6.8. Since that the brick logs get
> > >> >flooded by such messages:
> > >> >
> > >> >[2020-04-11 05:22:48.774688] I [MSGID: 139001]
> > >> >[posix-acl.c:263:posix_acl_log_permit_denied]
> > >> >0-workdata-access-control: client:
> > >>
> > >>CTX_ID:a1b55e2b-af03-484a-9be0-9314fec4bb61-GRAPH_ID:0-PID:8204-HOST:gluster1-PC_NAME:workdata-client-0-RECON_NO:-0,
> > >> >gfid: 25f487a5-2973-407c-87d2-74979c16c5ab,
> > >> >req(uid:33,gid:33,perm:2,ngrps:1),
> > >> >ctx(uid:109,gid:114,in-groups:0,perm:644,updated-fop:LOOKUP, acl:-)
> > >> >[Permission denied]
> > >> >[2020-04-11 05:22:48.774768] I [MSGID: 115060]
> > >> >[server-rpc-fops.c:938:_gf_server_log_setxattr_failure]
> > >> >0-workdata-server: 60517534: SETXATTR
> > >> >/images/383/200/38320023/800x800f.jpg
> > >> >(25f487a5-2973-407c-87d2-74979c16c5ab) ==> set-ctime-mdata, client:
> > >>
> > >>CTX_ID:a1b55e2b-af03-484a-9be0-9314fec4bb61-GRAPH_ID:0-PID:8204-HOST:gluster1-PC_NAME:workdata-client-0-RECON_NO:-0,
> > >> >error-xlator: workdata-access-control
> > >> >
> > >> >The file in the filesystem:
> > >> >
> > >> >-rw-r--r--  1 tomcat8 tomcat8 283K Jun 13  2019 800x800f.jpg
> > >> >
> > >> >So this file exists for 9 months now. The log messages appear for
> > >> >files and directories. And there are over 9.5 million log entries in
> > >> >the last 10 hours.
> > >> >
> > >> >Is this behaviour normal for 6.8? Will it disappear? Anyone an idea
> > >> >what is happening here?
> > >> >
> > >> >
> > >> >Regards,
> > >> >Hubert
> > >> >________
> > >> >
> > >> >
> > >> >
> > >> >Community Meeting Calendar:
> > >> >
> > >> >Schedule -
> > >> >Every 2nd and 4th Tuesday at 14:30 IST / 09:00 UTC
> > >> >Bridge: https://bluejeans.com/441850968
> > >> >
> > >> >Gluster-users mailing list
> > >> >Gluster-users at gluster.org
> > >> >https://lists.gluster.org/mailman/listinfo/gluster-users
> > >>
> > >> Hi Hubert,
> > >> Not  normal at  all.
> > >> It looks  like  my ACL problem.
> > >> The  workaround for me is to copy the file/dir and replace it:
> > >> cp -a  orig new
> > >> mv orig  old && mv new orig
> > >>
> > >> @Amar,  is  the 'https://review.gluster.org/#/c/glusterfs/+/24264/'
> > >in 6.8  ?
> > >> The output seems just like mine.
> > >>
> > >> Best Regards,
> > >> Strahil Nikolov
> >
> > For me the ACL issue hit me when I migrated  from  6.5  to 6.6 .
> > For me 6.5 & 7.0  were OK,  while  anything above was a problem.
> >
> > What was  your version prior the upgrade ?
> >
> > Best Regards,
> > Strahil Nikolov