summaryrefslogtreecommitdiffstats
path: root/xlators
diff options
context:
space:
mode:
authorPavan Sondur <pavan@gluster.com>2009-10-28 17:03:37 +0000
committerAnand V. Avati <avati@dev.gluster.com>2009-10-29 00:52:45 -0700
commit03c6fe7f7e51d391beb370d04964af1de9728d28 (patch)
tree4912e8940674e692df8c22872eaee3d93b2bf1c0 /xlators
parent9a62a3747cfcef2db3bc0b630a92f24d9436eeca (diff)
Trace locks in and out with an option in normal log mode.
Signed-off-by: Anand V. Avati <avati@dev.gluster.com> BUG: 306 (Enhance locks to aid debugging) URL: http://bugs.gluster.com/cgi-bin/bugzilla3/show_bug.cgi?id=306
Diffstat (limited to 'xlators')
-rw-r--r--xlators/features/locks/src/common.c225
-rw-r--r--xlators/features/locks/src/common.h33
-rw-r--r--xlators/features/locks/src/locks.h1
-rw-r--r--xlators/features/locks/src/posix.c24
4 files changed, 281 insertions, 2 deletions
diff --git a/xlators/features/locks/src/common.c b/xlators/features/locks/src/common.c
index a2401d4e94d..040b954693d 100644
--- a/xlators/features/locks/src/common.c
+++ b/xlators/features/locks/src/common.c
@@ -118,6 +118,228 @@ __pl_inode_is_empty (pl_inode_t *pl_inode)
}
void
+pl_print_locker (char *str, int size, xlator_t *this, call_frame_t *frame)
+{
+ snprintf (str, size, "Pid=%llu, Transport=%p, Frame=%llu",
+ (unsigned long long) frame->root->pid,
+ (void *)frame->root->trans,
+ (unsigned long long) frame->root->unique);
+}
+
+
+void
+pl_print_lockee (char *str, int size, fd_t *fd, loc_t *loc)
+{
+ inode_t *inode = NULL;
+ char *ipath = NULL;
+ int ret = 0;
+
+ if (fd)
+ inode = fd->inode;
+ if (loc)
+ inode = loc->inode;
+
+ if (!inode) {
+ snprintf (str, size, "<nul>");
+ return;
+ }
+
+ if (loc && loc->path) {
+ ipath = strdup (loc->path);
+ } else {
+ ret = inode_path (inode, NULL, &ipath);
+ if (ret <= 0)
+ ipath = NULL;
+ }
+
+ snprintf (str, size, "ino=%llu, fd=%p, path=%s",
+ (unsigned long long) inode->ino, fd,
+ ipath ? ipath : "<nul>");
+
+ if (ipath)
+ FREE (ipath);
+}
+
+
+void
+pl_print_lock (char *str, int size, int cmd, struct flock *flock)
+{
+ char *cmd_str = NULL;
+ char *type_str = NULL;
+
+ switch (cmd) {
+#if F_GETLK != F_GETLK64
+ case F_GETLK64:
+#endif
+ case F_GETLK:
+ cmd_str = "GETLK";
+ break;
+
+#if F_SETLK != F_SETLK64
+ case F_SETLK64:
+#endif
+ case F_SETLK:
+ cmd_str = "SETLK";
+ break;
+
+#if F_SETLKW != F_SETLKW64
+ case F_SETLKW64:
+#endif
+ case F_SETLKW:
+ cmd_str = "SETLKW";
+ break;
+
+ default:
+ cmd_str = "UNKNOWN";
+ break;
+ }
+
+ switch (flock->l_type) {
+ case F_RDLCK:
+ type_str = "READ";
+ break;
+ case F_WRLCK:
+ type_str = "WRITE";
+ break;
+ case F_UNLCK:
+ type_str = "UNLOCK";
+ break;
+ default:
+ type_str = "UNKNOWN";
+ break;
+ }
+
+ snprintf (str, size, "cmd=%s, type=%s, start=%llu, len=%llu, pid=%llu",
+ cmd_str, type_str, (unsigned long long) flock->l_start,
+ (unsigned long long) flock->l_len,
+ (unsigned long long) flock->l_pid);
+}
+
+
+void
+pl_trace_in (xlator_t *this, call_frame_t *frame, fd_t *fd, loc_t *loc,
+ int cmd, struct flock *flock)
+{
+ posix_locks_private_t *priv = NULL;
+ char pl_locker[256];
+ char pl_lockee[256];
+ char pl_lock[256];
+
+ priv = this->private;
+
+ if (!priv->trace)
+ return;
+
+ pl_print_locker (pl_locker, 256, this, frame);
+ pl_print_lockee (pl_lockee, 256, fd, loc);
+ pl_print_lock (pl_lock, 256, cmd, flock);
+
+ gf_log (this->name, GF_LOG_NORMAL,
+ "[REQUEST] Locker = {%s} Lockee = {%s} Lock = {%s}",
+ pl_locker, pl_lockee, pl_lock);
+}
+
+
+void
+pl_print_verdict (char *str, int size, int op_ret, int op_errno)
+{
+ char *verdict = NULL;
+
+ if (op_ret == 0) {
+ verdict = "GRANTED";
+ } else {
+ switch (op_errno) {
+ case EAGAIN:
+ verdict = "TRYAGAIN";
+ break;
+ default:
+ verdict = strerror (op_errno);
+ }
+ }
+
+ snprintf (str, size, verdict);
+}
+
+
+void
+pl_trace_out (xlator_t *this, call_frame_t *frame, fd_t *fd, loc_t *loc,
+ int cmd, struct flock *flock, int op_ret, int op_errno)
+
+{
+ posix_locks_private_t *priv = NULL;
+ char pl_locker[256];
+ char pl_lockee[256];
+ char pl_lock[256];
+ char verdict[32];
+
+ priv = this->private;
+
+ if (!priv->trace)
+ return;
+
+ pl_print_locker (pl_locker, 256, this, frame);
+ pl_print_lockee (pl_lockee, 256, fd, loc);
+ pl_print_lock (pl_lock, 256, cmd, flock);
+ pl_print_verdict (verdict, 32, op_ret, op_errno);
+
+ gf_log (this->name, GF_LOG_NORMAL,
+ "[%s] Locker = {%s} Lockee = {%s} Lock = {%s}",
+ verdict, pl_locker, pl_lockee, pl_lock);
+}
+
+
+void
+pl_trace_block (xlator_t *this, call_frame_t *frame, fd_t *fd, loc_t *loc,
+ int cmd, struct flock *flock)
+
+{
+ posix_locks_private_t *priv = NULL;
+ char pl_locker[256];
+ char pl_lockee[256];
+ char pl_lock[256];
+
+ priv = this->private;
+
+ if (!priv->trace)
+ return;
+
+ pl_print_locker (pl_locker, 256, this, frame);
+ pl_print_lockee (pl_lockee, 256, fd, loc);
+ pl_print_lock (pl_lock, 256, cmd, flock);
+
+ gf_log (this->name, GF_LOG_NORMAL,
+ "[BLOCKED] Locker = {%s} Lockee = {%s} Lock = {%s}",
+ pl_locker, pl_lockee, pl_lock);
+}
+
+
+void
+pl_trace_flush (xlator_t *this, call_frame_t *frame, fd_t *fd)
+{
+ posix_locks_private_t *priv = NULL;
+ char pl_locker[256];
+ char pl_lockee[256];
+ pl_inode_t *pl_inode = NULL;
+
+ priv = this->private;
+
+ if (!priv->trace)
+ return;
+
+ pl_inode = pl_inode_get (this, fd->inode);
+
+ if (pl_inode && __pl_inode_is_empty (pl_inode))
+ return;
+
+ pl_print_locker (pl_locker, 256, this, frame);
+ pl_print_lockee (pl_lockee, 256, fd, NULL);
+
+ gf_log (this->name, GF_LOG_NORMAL,
+ "[FLUSH] Locker = {%s} Lockee = {%s}",
+ pl_locker, pl_lockee);
+}
+
+void
pl_update_refkeeper (xlator_t *this, inode_t *inode)
{
pl_inode_t *pl_inode = NULL;
@@ -580,6 +802,9 @@ grant_blocked_locks (xlator_t *this, pl_inode_t *pl_inode)
list_for_each_entry_safe (lock, tmp, &granted_list, list) {
list_del_init (&lock->list);
+ pl_trace_out (this, lock->frame, NULL, NULL, F_SETLKW,
+ &lock->user_flock, 0, 0);
+
STACK_UNWIND (lock->frame, 0, 0, &lock->user_flock);
FREE (lock);
diff --git a/xlators/features/locks/src/common.h b/xlators/features/locks/src/common.h
index 4e9b30be211..bdc602f6383 100644
--- a/xlators/features/locks/src/common.h
+++ b/xlators/features/locks/src/common.h
@@ -73,4 +73,37 @@ get_inodelk_count (xlator_t *this, inode_t *inode);
int32_t
get_entrylk_count (xlator_t *this, inode_t *inode);
+void pl_trace_in (xlator_t *this, call_frame_t *frame, fd_t *fd, loc_t *loc,
+ int cmd, struct flock *flock);
+
+void pl_trace_out (xlator_t *this, call_frame_t *frame, fd_t *fd, loc_t *loc,
+ int cmd, struct flock *flock, int op_ret, int op_errno);
+
+void pl_trace_block (xlator_t *this, call_frame_t *frame, fd_t *fd, loc_t *loc,
+ int cmd, struct flock *flock);
+
+void pl_trace_flush (xlator_t *this, call_frame_t *frame, fd_t *fd);
+
+void entrylk_trace_in (xlator_t *this, call_frame_t *frame, const char *volume,
+ fd_t *fd, loc_t *loc, const char *basename,
+ entrylk_cmd cmd, entrylk_type type);
+
+void entrylk_trace_out (xlator_t *this, call_frame_t *frame, const char *volume,
+ fd_t *fd, loc_t *loc, const char *basename,
+ entrylk_cmd cmd, entrylk_type type,
+ int op_ret, int op_errno);
+
+void entrylk_trace_block (xlator_t *this, call_frame_t *frame, const char *volume,
+ fd_t *fd, loc_t *loc, const char *basename,
+ entrylk_cmd cmd, entrylk_type type);
+
+void
+pl_print_verdict (char *str, int size, int op_ret, int op_errno);
+
+void
+pl_print_lockee (char *str, int size, fd_t *fd, loc_t *loc);
+
+void
+pl_print_locker (char *str, int size, xlator_t *this, call_frame_t *frame);
+
#endif /* __COMMON_H__ */
diff --git a/xlators/features/locks/src/locks.h b/xlators/features/locks/src/locks.h
index 0f3ab29b6e9..4738da068c9 100644
--- a/xlators/features/locks/src/locks.h
+++ b/xlators/features/locks/src/locks.h
@@ -138,6 +138,7 @@ typedef struct __pl_fd pl_fd_t;
typedef struct {
gf_boolean_t mandatory; /* if mandatory locking is enabled */
+ gf_boolean_t trace; /* trace lock requests in and out */
} posix_locks_private_t;
typedef struct {
diff --git a/xlators/features/locks/src/posix.c b/xlators/features/locks/src/posix.c
index 3b011317c01..f2371625197 100644
--- a/xlators/features/locks/src/posix.c
+++ b/xlators/features/locks/src/posix.c
@@ -281,6 +281,8 @@ pl_flush (call_frame_t *frame, xlator_t *this,
return 0;
}
+ pl_trace_flush (this, frame, fd);
+
pthread_mutex_lock (&pl_inode->mutex);
{
__delete_locks_of_owner (pl_inode, frame->root->trans,
@@ -643,6 +645,8 @@ pl_lk (call_frame_t *frame, xlator_t *this,
goto unwind;
}
+ pl_trace_in (this, frame, fd, NULL, cmd, flock);
+
switch (cmd) {
#if F_GETLK != F_GETLK64
@@ -675,9 +679,10 @@ pl_lk (call_frame_t *frame, xlator_t *this,
can_block);
if (ret == -1) {
- if (can_block)
+ if (can_block) {
+ pl_trace_block (this, frame, fd, NULL, cmd, flock);
goto out;
-
+ }
gf_log (this->name, GF_LOG_DEBUG, "returning EAGAIN");
op_ret = -1;
op_errno = EAGAIN;
@@ -686,6 +691,7 @@ pl_lk (call_frame_t *frame, xlator_t *this,
}
unwind:
+ pl_trace_out (this, frame, fd, NULL, cmd, flock, op_ret, op_errno);
pl_update_refkeeper (this, fd->inode);
STACK_UNWIND_STRICT (lk, frame, op_ret, op_errno, flock);
out:
@@ -1020,6 +1026,7 @@ init (xlator_t *this)
posix_locks_private_t *priv = NULL;
xlator_list_t *trav = NULL;
data_t *mandatory = NULL;
+ data_t *trace = NULL;
if (!this->children || this->children->next) {
gf_log (this->name, GF_LOG_CRITICAL,
@@ -1056,6 +1063,16 @@ init (xlator_t *this)
}
}
+ trace = dict_get (this->options, "trace");
+ if (trace) {
+ if (gf_string2boolean (trace->data,
+ &priv->trace) == -1) {
+ gf_log (this->name, GF_LOG_ERROR,
+ "'trace' takes on only boolean values.");
+ return -1;
+ }
+ }
+
this->private = priv;
return 0;
}
@@ -1124,5 +1141,8 @@ struct volume_options options[] = {
{ .key = { "mandatory-locks", "mandatory" },
.type = GF_OPTION_TYPE_BOOL
},
+ { .key = { "trace" },
+ .type = GF_OPTION_TYPE_BOOL
+ },
{ .key = {NULL} },
};