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

Fri Feb 7 08:25:44 UTC 2020

Still no response? 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, 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.
>>
>> 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
>>>>
>>>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.gluster.org/pipermail/gluster-users/attachments/20200207/6d8185d6/attachment.html>