Hu Bert
2020-Apr-11 13:38 UTC
[Gluster-users] gluster 6.8: brick logs flooded by Information messages
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
Hu Bert
2020-Apr-21 07:55 UTC
[Gluster-users] gluster 6.8: brick logs flooded by Information messages
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