[Gluster-users] remote operation failed [Permission denied] every 10 minutes after upgrading from 5.10 to 7.0

Mon Mar 9 08:41:10 UTC 2020

The release for 7 will happen every month while the release 5 and 6 are
done once in every 2 months.
We are done for February, so the next cycle for 5 and 6 are in April.

On Sat, Mar 7, 2020 at 1:00 PM Artem Russakovskii <archon810 at gmail.com>
wrote:

> Great, I'll be glad to test and confirm once the release with this change
> is out. Would you please confirm when it is by replying here?
>
> Thanks, Amar.
>
> Sincerely,
> Artem
>
> --
> Founder, Android Police <http://www.androidpolice.com>, APK Mirror
> <http://www.apkmirror.com/>, Illogical Robot LLC
> beerpla.net | @ArtemR <http://twitter.com/ArtemR>
>
>
> On Tue, Mar 3, 2020 at 8:25 PM Amar Tumballi <amar at kadalu.io> wrote:
>
>>
>>
>> On Sat, Feb 15, 2020 at 7:27 AM Amar Tumballi <amar at kadalu.io> wrote:
>>
>>>
>>>
>>> On Sat, Feb 15, 2020 at 3:02 AM Artem Russakovskii <archon810 at gmail.com>
>>> wrote:
>>>
>>>> Amar,
>>>>
>>>> From what I can tell, there's no error actually using the referenced
>>>> files, but the log messages all constantly pop up in the log when accessed
>>>> through the web server. The files display OK in the browser.
>>>>
>>>> I also tried renaming/touching them via shell as the user that owns
>>>> them, and that worked fine (with no notices generated).
>>>>
>>>
>>> Thanks for this update.
>>>
>>>
>>>>
>>>> I hope you guys figure it out because I really don't feel comfortable
>>>> upgrading to 6 or 7 from 5 which has been stable.
>>>>
>>>>
>>> Ack! Makes sense, upgrading to a version when you know there is a
>>> regression is not a good thing. We will check this out.
>>>
>>>
>>
>> https://review.gluster.org/#/c/glusterfs/+/24200/ would hopefully fix
>> the issue.
>>
>>
>>> -Amar
>>>
>>>
>>>> Sincerely,
>>>> Artem
>>>>
>>>> --
>>>> Founder, Android Police <http://www.androidpolice.com>, APK Mirror
>>>> <http://www.apkmirror.com/>, Illogical Robot LLC
>>>> beerpla.net | @ArtemR <http://twitter.com/ArtemR>
>>>>
>>>>
>>>> On Wed, Feb 12, 2020 at 11:02 PM Amar Tumballi <amarts at gmail.com>
>>>> wrote:
>>>>
>>>>>
>>>>>
>>>>>
>>>>> On Fri, Feb 7, 2020 at 1:56 PM Artem Russakovskii <archon810 at gmail.com>
>>>>> wrote:
>>>>>
>>>>>> Still no response? Amar?
>>>>>>
>>>>>>
>>>>> Sorry, this got down in my Inbox, and missed responding, and also I
>>>>> got busy with few other engagements. Reply inline.
>>>>>
>>>>> Sincerely,
>>>>>> Artem
>>>>>>
>>>>>> On Tue, Jan 14, 2020 at 12:57 PM Artem Russakovskii <
>>>>>> archon810 at gmail.com> wrote:
>>>>>>
>>>>>>> Hi,
>>>>>>>
>>>>>>> Any updates here please?
>>>>>>>
>>>>>>> Sincerely,
>>>>>>> Artem
>>>>>>>
>>>>>>> --
>>>>>>> Founder, Android Police <http://www.androidpolice.com>, APK Mirror
>>>>>>> <http://www.apkmirror.com/>, Illogical Robot LLC
>>>>>>> beerpla.net | @ArtemR <http://twitter.com/ArtemR>
>>>>>>>
>>>>>>>
>>>>>>> On Mon, Jan 6, 2020 at 4:18 PM Artem Russakovskii <
>>>>>>> archon810 at gmail.com> wrote:
>>>>>>>
>>>>>>>> Thanks Amar,
>>>>>>>>
>>>>>>>> Checking the brick logs, I'm seeing these and numerous other files
>>>>>>>> with Permission denied. The question is why is the permission being denied?
>>>>>>>> Gluster runs as root and the files are owned by wwwrun:www, which it should
>>>>>>>> have full access to.
>>>>>>>>
>>>>>>>> Is there any more documentation on what enabling or disabling this
>>>>>>>> feature accomplishes, why it was added to 7.1 by default (and 7.0 as far as
>>>>>>>> I can tell), and what side effects it may have? Basically, I'd like to
>>>>>>>> understand the problem better instead of simply turning the flag off and
>>>>>>>> fix the underlying issue (or help fix a bug if it's a bug in gluster).
>>>>>>>>
>>>>>>>> ==> bricks/mnt-pylon_block6-dev_SNIP_data.log <==
>>>>>>>>> [2020-01-06 21:39:00.176476] I [MSGID: 115060]
>>>>>>>>> [server-rpc-fops_v2.c:897:server4_setxattr_cbk] 0-dev_SNIP_data-server:
>>>>>>>>> client:
>>>>>>>>> CTX_ID:3e0436a5-cdf8-4d3f-a4e9-fc681fe902d3-GRAPH_ID:2-PID:32069-HOST:pylon-PC_NAME:dev_SNIP_data-client-2-RECON_NO:-0,
>>>>>>>>> error-xlator: dev_SNIP_data-access-control [Permission denied]
>>>>>>>>> [2020-01-06 21:39:00.325329] I [MSGID: 139001]
>>>>>>>>> [posix-acl.c:262:posix_acl_log_permit_denied]
>>>>>>>>> 0-dev_SNIP_data-access-control: client:
>>>>>>>>> CTX_ID:3e0436a5-cdf8-4d3f-a4e9-fc681fe902d3-GRAPH_ID:2-PID:32069-HOST:pylon-PC_NAME:dev_SNIP_data-client-2-RECON_NO:-0,
>>>>>>>>> gfid: e9bd83fd-b16e-44ef-8fde-2ae320ee54d0,
>>>>>>>>> req(uid:491,gid:488,perm:2,ngrps:1),
>>>>>>>>> ctx(uid:30,gid:8,in-groups:0,perm:664,updated-fop:LOOKUP, acl:-)
>>>>>>>>> [Permission denied]
>>>>>>>>> [2020-01-06 21:39:00.325435] I [MSGID: 115060]
>>>>>>>>> [server-rpc-fops.c:937:_gf_server_log_setxattr_failure]
>>>>>>>>> 0-dev_SNIP_data-server: 709342: SETXATTR
>>>>>>>>> /uploads/2019/06/Anker-PowerPort-Atom-10-768x512.jpg
>>>>>>>>> (e9bd83fd-b16e-44ef-8fde-2ae320ee54d0) ==> set-ctime-mdata, client:
>>>>>>>>> CTX_ID:3e0436a5-cdf8-4d3f-a4e9-fc681fe902d3-GRAPH_ID:2-PID:32069-HOST:pylon-PC_NAME:dev_SNIP_data-client-2-RECON_NO:-0,
>>>>>>>>> error-xlator: dev_SNIP_data-access-control
>>>>>>>>> [2020-01-06 21:39:00.325460] I [MSGID: 115060]
>>>>>>>>> [server-rpc-fops_v2.c:897:server4_setxattr_cbk] 0-dev_SNIP_data-server:
>>>>>>>>> client:
>>>>>>>>> CTX_ID:3e0436a5-cdf8-4d3f-a4e9-fc681fe902d3-GRAPH_ID:2-PID:32069-HOST:pylon-PC_NAME:dev_SNIP_data-client-2-RECON_NO:-0,
>>>>>>>>> error-xlator: dev_SNIP_data-access-control [Permission denied]
>>>>>>>>> [2020-01-06 21:39:01.195012] I [MSGID: 139001]
>>>>>>>>> [posix-acl.c:262:posix_acl_log_permit_denied]
>>>>>>>>> 0-dev_SNIP_data-access-control: client:
>>>>>>>>> CTX_ID:3e0436a5-cdf8-4d3f-a4e9-fc681fe902d3-GRAPH_ID:2-PID:32069-HOST:pylon-PC_NAME:dev_SNIP_data-client-2-RECON_NO:-0,
>>>>>>>>> gfid: ff96827e-777b-45fb-a40d-e5089cd024fe,
>>>>>>>>> req(uid:491,gid:488,perm:2,ngrps:1),
>>>>>>>>> ctx(uid:30,gid:8,in-groups:0,perm:664,updated-fop:LOOKUP, acl:-)
>>>>>>>>> [Permission denied]
>>>>>>>>> [2020-01-06 21:39:01.195091] I [MSGID: 115060]
>>>>>>>>> [server-rpc-fops.c:937:_gf_server_log_setxattr_failure]
>>>>>>>>> 0-dev_SNIP_data-server: 709349: SETXATTR
>>>>>>>>> /uploads/2019/06/Anker-PowerPort-Atom-768x512.jpg
>>>>>>>>> (ff96827e-777b-45fb-a40d-e5089cd024fe) ==> set-ctime-mdata, client:
>>>>>>>>> CTX_ID:3e0436a5-cdf8-4d3f-a4e9-fc681fe902d3-GRAPH_ID:2-PID:32069-HOST:pylon-PC_NAME:dev_SNIP_data-client-2-RECON_NO:-0,
>>>>>>>>> error-xlator: dev_SNIP_data-access-control
>>>>>>>>> [2020-01-06 21:39:01.195291] I [MSGID: 115060]
>>>>>>>>> [server-rpc-fops_v2.c:897:server4_setxattr_cbk] 0-dev_SNIP_data-server:
>>>>>>>>> client:
>>>>>>>>> CTX_ID:3e0436a5-cdf8-4d3f-a4e9-fc681fe902d3-GRAPH_ID:2-PID:32069-HOST:pylon-PC_NAME:dev_SNIP_data-client-2-RECON_NO:-0,
>>>>>>>>> error-xlator: dev_SNIP_data-access-control [Permission denied]
>>>>>>>>> [2020-01-06 21:39:04.184502] I [MSGID: 139001]
>>>>>>>>> [posix-acl.c:262:posix_acl_log_permit_denied]
>>>>>>>>> 0-dev_SNIP_data-access-control: client:
>>>>>>>>> CTX_ID:3e0436a5-cdf8-4d3f-a4e9-fc681fe902d3-GRAPH_ID:2-PID:32069-HOST:pylon-PC_NAME:dev_SNIP_data-client-2-RECON_NO:-0,
>>>>>>>>> gfid: 546305c8-7611-4752-9168-215e9eb03938,
>>>>>>>>> req(uid:491,gid:488,perm:2,ngrps:1),
>>>>>>>>> ctx(uid:30,gid:8,in-groups:0,perm:664,updated-fop:LOOKUP, acl:-)
>>>>>>>>> [Permission denied]
>>>>>>>>> [2020-01-06 21:39:04.184554] I [MSGID: 115060]
>>>>>>>>> [server-rpc-fops.c:937:_gf_server_log_setxattr_failure]
>>>>>>>>> 0-dev_SNIP_data-server: 709360: SETXATTR
>>>>>>>>> /uploads/2019/06/Anker-PowerPort-Atom-10-1-768x512.jpg
>>>>>>>>> (546305c8-7611-4752-9168-215e9eb03938) ==> set-ctime-mdata, client:
>>>>>>>>> CTX_ID:3e0436a5-cdf8-4d3f-a4e9-fc681fe902d3-GRAPH_ID:2-PID:32069-HOST:pylon-PC_NAME:dev_SNIP_data-client-2-RECON_NO:-0,
>>>>>>>>> error-xlator: dev_SNIP_data-access-control
>>>>>>>>> [2020-01-06 21:39:04.184576] I [MSGID: 115060]
>>>>>>>>> [server-rpc-fops_v2.c:897:server4_setxattr_cbk] 0-dev_SNIP_data-server:
>>>>>>>>> client:
>>>>>>>>> CTX_ID:3e0436a5-cdf8-4d3f-a4e9-fc681fe902d3-GRAPH_ID:2-PID:32069-HOST:pylon-PC_NAME:dev_SNIP_data-client-2-RECON_NO:-0,
>>>>>>>>> error-xlator: dev_SNIP_data-access-control [Permission denied]
>>>>>>>>>
>>>>>>>>
>>>>>>>> Btw, cluster.op-version is 70000, which is the latest. I always rev
>>>>>>>> it up after upgrading the cluster.
>>>>>>>>
>>>>>>>>
>>>>> I don't have any reports of this error coming for other users, and not
>>>>> able to reproduce locally too.  I am starting to think that this error and
>>>>> the issue Strahil faced after upgrading (saying there was an ACL issue) may
>>>>> be related. Will check and update. Meantime, is there any application error
>>>>> you are seeing? That would also give us some hints to reproduce the issue.
>>>>>
>>>>> -Amar
>>>>>
>>>>>
>>>>>> Sincerely,
>>>>>>>> Artem
>>>>>>>>
>>>>>>>> --
>>>>>>>> Founder, Android Police <http://www.androidpolice.com>, APK Mirror
>>>>>>>> <http://www.apkmirror.com/>, Illogical Robot LLC
>>>>>>>> beerpla.net | @ArtemR <http://twitter.com/ArtemR>
>>>>>>>>
>>>>>>>>
>>>>>>>> On Sat, Dec 28, 2019 at 1:19 AM Amar Tumballi <amarts at gmail.com>
>>>>>>>> wrote:
>>>>>>>>
>>>>>>>>> Answers inline.
>>>>>>>>>
>>>>>>>>> On Wed, Dec 25, 2019 at 2:06 AM Artem Russakovskii <
>>>>>>>>> archon810 at gmail.com> wrote:
>>>>>>>>>
>>>>>>>>>> Hi everyone,
>>>>>>>>>>
>>>>>>>>>> I'm preparing the upgrade for our 5.10 gluster cluster running
>>>>>>>>>> 1x4 replicate volumes to 7.X and decided to upgrade our test cluster first.
>>>>>>>>>>
>>>>>>>>>> As soon as I upgraded to 7.0 (and now 7.1), I started seeing the
>>>>>>>>>> following messages every 10 minutes in the log for one of the volumes:
>>>>>>>>>>
>>>>>>>>>> [2019-12-19 21:27:55.041949] W [MSGID: 114031]
>>>>>>>>>>> [client-rpc-fops_v2.c:850:client4_0_setxattr_cbk] 0-dev_SNIP_data-client-0:
>>>>>>>>>>> remote operation failed [Permission denied]
>>>>>>>>>>> [2019-12-19 21:27:55.042002] W [MSGID: 114031]
>>>>>>>>>>> [client-rpc-fops_v2.c:850:client4_0_setxattr_cbk] 0-dev_SNIP_data-client-2:
>>>>>>>>>>> remote operation failed [Permission denied]
>>>>>>>>>>> [2019-12-19 21:27:55.042013] W [MSGID: 114031]
>>>>>>>>>>> [client-rpc-fops_v2.c:850:client4_0_setxattr_cbk] 0-dev_SNIP_data-client-1:
>>>>>>>>>>> remote operation failed [Permission denied]
>>>>>>>>>>> [2019-12-19 21:27:55.042634] E [MSGID: 148002]
>>>>>>>>>>> [utime.c:146:gf_utime_set_mdata_setxattr_cbk] 0-dev_SNIP_data-utime: dict
>>>>>>>>>>> set of key for set-ctime-mdata failed [Permission denied]
>>>>>>>>>>> The message "W [MSGID: 114031]
>>>>>>>>>>> [client-rpc-fops_v2.c:850:client4_0_setxattr_cbk] 0-dev_SNIP_data-client-0:
>>>>>>>>>>> remote operation failed [Permission denied]" repeated 2 times between
>>>>>>>>>>> [2019-12-19 21:27:55.041949] and [2019-12-19 21:27:55.047300]
>>>>>>>>>>> The message "W [MSGID: 114031]
>>>>>>>>>>> [client-rpc-fops_v2.c:850:client4_0_setxattr_cbk] 0-dev_SNIP_data-client-2:
>>>>>>>>>>> remote operation failed [Permission denied]" repeated 2 times between
>>>>>>>>>>> [2019-12-19 21:27:55.042002] and [2019-12-19 21:27:55.047312]
>>>>>>>>>>> The message "W [MSGID: 114031]
>>>>>>>>>>> [client-rpc-fops_v2.c:850:client4_0_setxattr_cbk] 0-dev_SNIP_data-client-1:
>>>>>>>>>>> remote operation failed [Permission denied]" repeated 2 times between
>>>>>>>>>>> [2019-12-19 21:27:55.042013] and [2019-12-19 21:27:55.047524]
>>>>>>>>>>> The message "E [MSGID: 148002]
>>>>>>>>>>> [utime.c:146:gf_utime_set_mdata_setxattr_cbk] 0-dev_SNIP_data-utime: dict
>>>>>>>>>>> set of key for set-ctime-mdata failed [Permission denied]" repeated 2 times
>>>>>>>>>>> between [2019-12-19 21:27:55.042634] and [2019-12-19 21:27:55.047887]
>>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>> [2019-12-19 21:37:55.541329] W [MSGID: 114031]
>>>>>>>>>>> [client-rpc-fops_v2.c:850:client4_0_setxattr_cbk] 0-dev_SNIP_data-client-2:
>>>>>>>>>>> remote operation failed [Permission denied]
>>>>>>>>>>> [2019-12-19 21:37:55.541644] W [MSGID: 114031]
>>>>>>>>>>> [client-rpc-fops_v2.c:850:client4_0_setxattr_cbk] 0-dev_SNIP_data-client-1:
>>>>>>>>>>> remote operation failed [Permission denied]
>>>>>>>>>>> [2019-12-19 21:37:55.541681] W [MSGID: 114031]
>>>>>>>>>>> [client-rpc-fops_v2.c:850:client4_0_setxattr_cbk] 0-dev_SNIP_data-client-0:
>>>>>>>>>>> remote operation failed [Permission denied]
>>>>>>>>>>> [2019-12-19 21:37:55.542067] E [MSGID: 148002]
>>>>>>>>>>> [utime.c:146:gf_utime_set_mdata_setxattr_cbk] 0-dev_SNIP_data-utime: dict
>>>>>>>>>>> set of key for set-ctime-mdata failed [Permission denied]
>>>>>>>>>>> The message "W [MSGID: 114031]
>>>>>>>>>>> [client-rpc-fops_v2.c:850:client4_0_setxattr_cbk] 0-dev_SNIP_data-client-2:
>>>>>>>>>>> remote operation failed [Permission denied]" repeated 3 times between
>>>>>>>>>>> [2019-12-19 21:37:55.541329] and [2019-12-19 21:37:55.546695]
>>>>>>>>>>> The message "W [MSGID: 114031]
>>>>>>>>>>> [client-rpc-fops_v2.c:850:client4_0_setxattr_cbk] 0-dev_SNIP_data-client-1:
>>>>>>>>>>> remote operation failed [Permission denied]" repeated 3 times between
>>>>>>>>>>> [2019-12-19 21:37:55.541644] and [2019-12-19 21:37:55.546711]
>>>>>>>>>>> The message "W [MSGID: 114031]
>>>>>>>>>>> [client-rpc-fops_v2.c:850:client4_0_setxattr_cbk] 0-dev_SNIP_data-client-0:
>>>>>>>>>>> remote operation failed [Permission denied]" repeated 3 times between
>>>>>>>>>>> [2019-12-19 21:37:55.541681] and [2019-12-19 21:37:55.546761]
>>>>>>>>>>> The message "E [MSGID: 148002]
>>>>>>>>>>> [utime.c:146:gf_utime_set_mdata_setxattr_cbk] 0-dev_SNIP_data-utime: dict
>>>>>>>>>>> set of key for set-ctime-mdata failed [Permission denied]" repeated 3 times
>>>>>>>>>>> between [2019-12-19 21:37:55.542067] and [2019-12-19 21:37:55.547042]
>>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>> etc.
>>>>>>>>>>
>>>>>>>>>> The questions are:
>>>>>>>>>>
>>>>>>>>>>    1. Is it a cause for concern? They weren't there before the
>>>>>>>>>>    upgrade.
>>>>>>>>>>
>>>>>>>>>> Looks like all these logs are related to ctime feature which is
>>>>>>>>> by default enabled in 7.1 (and not in 5.x series)
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>    1. How can I determine what's causing the errors?
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>> Also check the server logs.
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>    1. How can I fix them and prevent them from spamming the logs?
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>> Check op-version of the cluster after upgrade. Disable 'ctime'
>>>>>>>>> option (volume set <vol> ctime off).
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>> Thank you and happy holidays!
>>>>>>>>>>
>>>>>>>>>
>>>>>>>>> +1
>>>>>>>>>
>>>>>>>>> Regards,
>>>>>>>>> Amar
>>>>>>>>> https://kadalu.io
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>> Sincerely,
>>>>>>>>>> Artem
>>>>>>>>>>
>>>>>>>>>> --
>>>>>>>>>> Founder, Android Police <http://www.androidpolice.com>, APK
>>>>>>>>>> Mirror <http://www.apkmirror.com/>, Illogical Robot LLC
>>>>>>>>>> beerpla.net | @ArtemR <http://twitter.com/ArtemR>
>>>>>>>>>> ________
>>>>>>>>>>
>>>>>>>>>> Community Meeting Calendar:
>>>>>>>>>>
>>>>>>>>>> APAC Schedule -
>>>>>>>>>> Every 2nd and 4th Tuesday at 11:30 AM IST
>>>>>>>>>> Bridge: https://bluejeans.com/441850968
>>>>>>>>>>
>>>>>>>>>> NA/EMEA Schedule -
>>>>>>>>>> Every 1st and 3rd Tuesday at 01:00 PM EDT
>>>>>>>>>> Bridge: https://bluejeans.com/441850968
>>>>>>>>>>
>>>>>>>>>> Gluster-users mailing list
>>>>>>>>>> Gluster-users at gluster.org
>>>>>>>>>> https://lists.gluster.org/mailman/listinfo/gluster-users
>>>>>>>>>>
>>>>>>>>> ________
>>>>
>>>> Community Meeting Calendar:
>>>>
>>>> APAC Schedule -
>>>> Every 2nd and 4th Tuesday at 11:30 AM IST
>>>> Bridge: https://bluejeans.com/441850968
>>>>
>>>> NA/EMEA Schedule -
>>>> Every 1st and 3rd Tuesday at 01:00 PM EDT
>>>> Bridge: https://bluejeans.com/441850968
>>>>
>>>> Gluster-users mailing list
>>>> Gluster-users at gluster.org
>>>> https://lists.gluster.org/mailman/listinfo/gluster-users
>>>>
>>>
>>>
>>> --
>>> --
>>> https://kadalu.io
>>> Container Storage made easy!
>>>
>>>
>>
>> --
>> --
>> https://kadalu.io
>> Container Storage made easy!
>>
>> ________
>
>
>
> Community Meeting Calendar:
>
> Schedule -
> Every 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
>

-- 
Regards,
Hari Gowtham.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.gluster.org/pipermail/gluster-users/attachments/20200309/ad6bac64/attachment.html>