Re: remote operation failed [Permission denied] every 10 minutes after upgrading from 5.10 to 7.0

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 

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@xxxxxxxxx> 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, APK Mirror, Illogical Robot LLC


On Tue, Mar 3, 2020 at 8:25 PM Amar Tumballi <amar@xxxxxxxxx> wrote:


On Sat, Feb 15, 2020 at 7:27 AM Amar Tumballi <amar@xxxxxxxxx> wrote:


On Sat, Feb 15, 2020 at 3:02 AM Artem Russakovskii <archon810@xxxxxxxxx> 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, APK Mirror, Illogical Robot LLC


On Wed, Feb 12, 2020 at 11:02 PM Amar Tumballi <amarts@xxxxxxxxx> wrote:



On Fri, Feb 7, 2020 at 1:56 PM Artem Russakovskii <archon810@xxxxxxxxx> 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@xxxxxxxxx> wrote:
Hi,

Any updates here please?

Sincerely,
Artem

--
Founder, Android Police, APK Mirror, Illogical Robot LLC


On Mon, Jan 6, 2020 at 4:18 PM Artem Russakovskii <archon810@xxxxxxxxx> 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, APK Mirror, Illogical Robot LLC


On Sat, Dec 28, 2019 at 1:19 AM Amar Tumballi <amarts@xxxxxxxxx> wrote:
Answers inline.

On Wed, Dec 25, 2019 at 2:06 AM Artem Russakovskii <archon810@xxxxxxxxx> 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

 

Sincerely,
Artem

--
Founder, Android Police, APK Mirror, Illogical Robot LLC
________

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@xxxxxxxxxxx
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@xxxxxxxxxxx
https://lists.gluster.org/mailman/listinfo/gluster-users


--
--
Container Storage made easy!



--
--
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@xxxxxxxxxxx
https://lists.gluster.org/mailman/listinfo/gluster-users


--
Regards,
Hari Gowtham.
________



Community Meeting Calendar:

Schedule -
Every Tuesday at 14:30 IST / 09:00 UTC
Bridge: https://bluejeans.com/441850968

Gluster-users mailing list
Gluster-users@xxxxxxxxxxx
https://lists.gluster.org/mailman/listinfo/gluster-users
[Index of Archives]     [Gluster Development]     [Linux Filesytems Development]     [Linux ARM Kernel]     [Linux ARM]     [Linux Omap]     [Fedora ARM]     [IETF Annouce]     [Bugtraq]     [Linux OMAP]     [Linux MIPS]     [eCos]     [Asterisk Internet PBX]     [Linux API]

  Powered by Linux