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

Sat Feb 15 01:57:15 UTC 2020

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.

-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!
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.gluster.org/pipermail/gluster-users/attachments/20200215/8beaacc7/attachment.html>