From 35e8ecabd7db36431ea93f523095bc21078ecef8 Mon Sep 17 00:00:00 2001 From: Pranith Kumar K Date: Sun, 13 Nov 2016 16:43:36 +0530 Subject: system/posix-acl: Log reason for EACCES It is becoming increasingly difficult to debug the reason why posix-acl decides to fail a fop with EACCES. This patch prints a big log everytime such a condition occurs giving out the details that may help in finding why the fop is errored out. Change-Id: I2505baaafb5d77ef6c187554ff027df9b20468db BUG: 1394548 Signed-off-by: Pranith Kumar K Reviewed-on: http://review.gluster.org/15837 Smoke: Gluster Build System NetBSD-regression: NetBSD Build System CentOS-regression: Gluster Build System Reviewed-by: Raghavendra Talur --- xlators/system/posix-acl/src/Makefile.am | 3 +- xlators/system/posix-acl/src/posix-acl-messages.h | 56 +++++++++++ xlators/system/posix-acl/src/posix-acl.c | 116 +++++++++++++++++++--- 3 files changed, 160 insertions(+), 15 deletions(-) create mode 100644 xlators/system/posix-acl/src/posix-acl-messages.h (limited to 'xlators/system') diff --git a/xlators/system/posix-acl/src/Makefile.am b/xlators/system/posix-acl/src/Makefile.am index c2214ecf4c9..f57070ce4a4 100644 --- a/xlators/system/posix-acl/src/Makefile.am +++ b/xlators/system/posix-acl/src/Makefile.am @@ -4,7 +4,8 @@ posix_acl_la_LDFLAGS = -module $(GF_XLATOR_DEFAULT_LDFLAGS) posix_acl_la_SOURCES = posix-acl.c posix-acl-xattr.c posix_acl_la_LIBADD = $(top_builddir)/libglusterfs/src/libglusterfs.la -noinst_HEADERS = posix-acl.h posix-acl-xattr.h posix-acl-mem-types.h +noinst_HEADERS = posix-acl.h posix-acl-xattr.h posix-acl-mem-types.h \ + posix-acl-messages.h AM_CPPFLAGS = $(GF_CPPFLAGS) -I$(top_srcdir)/libglusterfs/src \ -I$(top_srcdir)/rpc/xdr/src -I$(top_builddir)/rpc/xdr/src diff --git a/xlators/system/posix-acl/src/posix-acl-messages.h b/xlators/system/posix-acl/src/posix-acl-messages.h new file mode 100644 index 00000000000..ab93d749924 --- /dev/null +++ b/xlators/system/posix-acl/src/posix-acl-messages.h @@ -0,0 +1,56 @@ +/* + Copyright (c) 2016 Red Hat, Inc. + This file is part of GlusterFS. + + This file is licensed to you under your choice of the GNU Lesser + General Public License, version 3 or any later version (LGPLv3 or + later), or the GNU General Public License, version 2 (GPLv2), in all + cases as published by the Free Software Foundation. + */ + +#ifndef _POSIX_ACL_MESSAGES_H_ +#define _POSIX_ACL_MESSAGES_H_ + +#include "glfs-message-id.h" + +/*! \file posix-acl-messages.h + * \brief POSIX-ACL log-message IDs and their descriptions. + */ + +/* NOTE: Rules for message additions + * 1) Each instance of a message is _better_ left with a unique message ID, even + * if the message format is the same. Reasoning is that, if the message + * format needs to change in one instance, the other instances are not + * impacted or the new change does not change the ID of the instance being + * modified. + * 2) Addition of a message, + * - Should increment the GLFS_NUM_MESSAGES + * - Append to the list of messages defined, towards the end + * - Retain macro naming as glfs_msg_X (for redability across developers) + * NOTE: Rules for message format modifications + * 3) Check acorss the code if the message ID macro in question is reused + * anywhere. If reused then then the modifications should ensure correctness + * everywhere, or needs a new message ID as (1) above was not adhered to. If + * not used anywhere, proceed with the required modification. + * NOTE: Rules for message deletion + * 4) Check (3) and if used anywhere else, then cannot be deleted. If not used + * anywhere, then can be deleted, but will leave a hole by design, as + * addition rules specify modification to the end of the list and not filling + * holes. + */ + +#define GLFS_COMP_BASE_POSIX_ACL GLFS_MSGID_COMP_POSIX_ACL +#define GLFS_NUM_MESSAGES 1 +#define GLFS_MSGID_END (GLFS_COMP_BASE_POSIX_ACL + GLFS_NUM_MESSAGES + 1) + +#define glfs_msg_start_x GLFS_COMP_BASE_POSIX_ACL, "Invalid: Start of messages" + +/*! + * @messageid 139001 + * @diagnosis Access to the file/directory for the operation is denied. + * @recommendedaction The log contains details as to why it denied access. + */ +#define POSIX_ACL_MSG_EACCES (GLFS_COMP_BASE_POSIX_ACL + 1) + +#define glfs_msg_end_x GLFS_MSGID_END, "Invalid: End of messages" +#endif /* !_POSIX_ACL_MESSAGES_H_ */ diff --git a/xlators/system/posix-acl/src/posix-acl.c b/xlators/system/posix-acl/src/posix-acl.c index 9d467910339..9b3698618fa 100644 --- a/xlators/system/posix-acl/src/posix-acl.c +++ b/xlators/system/posix-acl/src/posix-acl.c @@ -16,7 +16,7 @@ #include "posix-acl.h" #include "posix-acl-xattr.h" #include "posix-acl-mem-types.h" - +#include "posix-acl-messages.h" #define UINT64(ptr) ((uint64_t)((long)(ptr))) #define PTR(num) ((void *)((long)(num))) @@ -181,6 +181,92 @@ sticky_permits (call_frame_t *frame, inode_t *parent, inode_t *inode) return 0; } +static gf_boolean_t +_does_acl_exist (struct posix_acl *acl) +{ + if (acl && (acl->count > POSIX_ACL_MINIMAL_ACE_COUNT)) + return _gf_true; + return _gf_false; +} + +static void +posix_acl_get_acl_string (call_frame_t *frame, struct posix_acl *acl, + char **acl_str) +{ + int i = 0; + size_t size_acl = 0; + size_t offset = 0; + struct posix_ace *ace = NULL; + char tmp_str[1024] = {0}; +#define NON_GRP_FMT "(tag:%"PRIu16",perm:%"PRIu16",id:%"PRIu32")" +#define GRP_FMT "(tag:%"PRIu16",perm:%"PRIu16",id:%"PRIu32",in-groups:%d)" + + if (!_does_acl_exist (acl)) + goto out; + + ace = acl->entries; + for (i = 0; i < acl->count; i++) { + if (ace->tag != POSIX_ACL_GROUP) { + size_acl += snprintf (tmp_str, sizeof tmp_str, + NON_GRP_FMT, ace->tag, ace->perm, ace->id); + } else { + size_acl += snprintf (tmp_str, sizeof tmp_str, + GRP_FMT, ace->tag, + ace->perm, ace->id, + frame_in_group (frame, ace->id)); + } + + ace++; + } + + *acl_str = GF_CALLOC (1, size_acl + 1, gf_posix_acl_mt_char); + if (!*acl_str) + goto out; + + ace = acl->entries; + for (i = 0; i < acl->count; i++) { + if (ace->tag != POSIX_ACL_GROUP) { + offset += snprintf (*acl_str + offset, + size_acl - offset, + NON_GRP_FMT, ace->tag, ace->perm, ace->id); + } else { + offset += snprintf (*acl_str + offset, + size_acl - offset, + GRP_FMT, ace->tag, ace->perm, ace->id, + frame_in_group (frame, ace->id)); + } + + ace++; + } +out: + return; +} + +static void +posix_acl_log_permit_denied (call_frame_t *frame, inode_t *inode, int want, + struct posix_acl_ctx *ctx, struct posix_acl *acl) +{ + char *acl_str = NULL; + client_t *client = frame->root->client; + + if (!frame || !inode || !ctx) + goto out; + + posix_acl_get_acl_string (frame, acl, &acl_str); + + gf_msg (frame->this->name, GF_LOG_INFO, EACCES, POSIX_ACL_MSG_EACCES, + "client: %s, gfid: %s, req(uid:%d,gid:%d,perm:%d," + "ngrps:%"PRIu16"), ctx(uid:%d,gid:%d,in-groups:%d,perm:%d%d%d," + "updated-fop:%s, acl:%s)", client ? client->client_uid : "-", + uuid_utoa (inode->gfid), frame->root->uid, frame->root->gid, + want, frame->root->ngrps, ctx->uid, ctx->gid, + frame_in_group (frame, ctx->gid), (ctx->perm & S_IRWXU) >> 6, + (ctx->perm & S_IRWXG) >> 3, ctx->perm & S_IRWXO, + gf_fop_string (ctx->fop), acl_str ? acl_str : "-"); +out: + GF_FREE (acl_str); + return; +} static int acl_permits (call_frame_t *frame, inode_t *inode, int want) @@ -211,7 +297,7 @@ acl_permits (call_frame_t *frame, inode_t *inode, int want) ace = acl->entries; - if (acl->count > POSIX_ACL_MINIMAL_ACE_COUNT) + if (_does_acl_exist (acl)) acl_present = 1; for (i = 0; i < acl->count; i++) { @@ -283,6 +369,7 @@ green: goto out; red: verdict = 0; + posix_acl_log_permit_denied (frame, inode, want, ctx, acl); out: if (acl) posix_acl_unref (frame->this, acl); @@ -786,9 +873,9 @@ posix_acl_inherit_file (xlator_t *this, loc_t *loc, dict_t *params, mode_t mode, return retmode; } - int -posix_acl_ctx_update (inode_t *inode, xlator_t *this, struct iatt *buf) +posix_acl_ctx_update (inode_t *inode, xlator_t *this, struct iatt *buf, + glusterfs_fop_t fop) { struct posix_acl_ctx *ctx = NULL; struct posix_acl *acl = NULL; @@ -809,9 +896,10 @@ posix_acl_ctx_update (inode_t *inode, xlator_t *this, struct iatt *buf) ctx->uid = buf->ia_uid; ctx->gid = buf->ia_gid; ctx->perm = st_mode_from_ia (buf->ia_prot, buf->ia_type); + ctx->fop = fop; acl = ctx->acl_access; - if (!acl || !(acl->count > POSIX_ACL_MINIMAL_ACE_COUNT)) + if (!_does_acl_exist (acl)) goto unlock; /* This is an extended ACL (not minimal acl). In case we @@ -853,7 +941,6 @@ unlock: return ret; } - int posix_acl_lookup_cbk (call_frame_t *frame, void *cookie, xlator_t *this, int op_ret, int op_errno, inode_t *inode, @@ -911,7 +998,7 @@ acl_default: } acl_set: - posix_acl_ctx_update (inode, this, buf); + posix_acl_ctx_update (inode, this, buf, GF_FOP_LOOKUP); ret = posix_acl_set (inode, this, acl_access, acl_default); if (ret) @@ -1283,7 +1370,7 @@ posix_acl_mkdir_cbk (call_frame_t *frame, void *cookie, xlator_t *this, if (op_ret != 0) goto unwind; - posix_acl_ctx_update (inode, this, buf); + posix_acl_ctx_update (inode, this, buf, GF_FOP_MKDIR); unwind: STACK_UNWIND_STRICT (mkdir, frame, op_ret, op_errno, inode, buf, @@ -1326,7 +1413,7 @@ posix_acl_mknod_cbk (call_frame_t *frame, void *cookie, xlator_t *this, if (op_ret != 0) goto unwind; - posix_acl_ctx_update (inode, this, buf); + posix_acl_ctx_update (inode, this, buf, GF_FOP_MKNOD); unwind: STACK_UNWIND_STRICT (mknod, frame, op_ret, op_errno, inode, buf, @@ -1369,7 +1456,7 @@ posix_acl_create_cbk (call_frame_t *frame, void *cookie, xlator_t *this, if (op_ret != 0) goto unwind; - posix_acl_ctx_update (inode, this, buf); + posix_acl_ctx_update (inode, this, buf, GF_FOP_CREATE); unwind: STACK_UNWIND_STRICT (create, frame, op_ret, op_errno, fd, inode, buf, @@ -1412,7 +1499,7 @@ posix_acl_symlink_cbk (call_frame_t *frame, void *cookie, xlator_t *this, if (op_ret != 0) goto unwind; - posix_acl_ctx_update (inode, this, buf); + posix_acl_ctx_update (inode, this, buf, GF_FOP_SYMLINK); unwind: STACK_UNWIND_STRICT (symlink, frame, op_ret, op_errno, inode, buf, @@ -1700,7 +1787,8 @@ posix_acl_readdirp_cbk (call_frame_t *frame, void *cookie, xlator_t *this, data->len); acl_set: - posix_acl_ctx_update (entry->inode, this, &entry->d_stat); + posix_acl_ctx_update (entry->inode, this, &entry->d_stat, + GF_FOP_READDIRP); ret = posix_acl_set (entry->inode, this, acl_access, acl_default); @@ -1837,7 +1925,7 @@ posix_acl_setattr_cbk (call_frame_t *frame, void *cookie, xlator_t *this, if (op_ret != 0) goto unwind; - posix_acl_ctx_update (inode, this, postbuf); + posix_acl_ctx_update (inode, this, postbuf, GF_FOP_SETATTR); unwind: STACK_UNWIND_STRICT (setattr, frame, op_ret, op_errno, prebuf, @@ -1883,7 +1971,7 @@ posix_acl_fsetattr_cbk (call_frame_t *frame, void *cookie, xlator_t *this, if (op_ret != 0) goto unwind; - posix_acl_ctx_update (inode, this, postbuf); + posix_acl_ctx_update (inode, this, postbuf, GF_FOP_FSETATTR); unwind: STACK_UNWIND_STRICT (fsetattr, frame, op_ret, op_errno, prebuf, -- cgit