From ba20df9f1a218177e7c7dcc15a11143183d28243 Mon Sep 17 00:00:00 2001 From: Krishnan Parthasarathi Date: Thu, 29 Sep 2011 16:44:40 +0530 Subject: locks: dump client pid and time of blocking/granting. Change-Id: Icaa919f3009fb70f6af9b95fceaf800f3beca447 BUG: 3662 Reviewed-on: http://review.gluster.com/532 Tested-by: Gluster Build System Reviewed-by: Vijay Bellur --- xlators/features/locks/src/common.c | 5 +++ xlators/features/locks/src/common.h | 1 + xlators/features/locks/src/entrylk.c | 3 ++ xlators/features/locks/src/inodelk.c | 3 ++ xlators/features/locks/src/locks.h | 9 ++++++ xlators/features/locks/src/posix.c | 63 +++++++++++++++++++++++++----------- 6 files changed, 65 insertions(+), 19 deletions(-) diff --git a/xlators/features/locks/src/common.c b/xlators/features/locks/src/common.c index 4e089a0ee36..4b6a810fde8 100644 --- a/xlators/features/locks/src/common.c +++ b/xlators/features/locks/src/common.c @@ -533,6 +533,11 @@ posix_lock_to_flock (posix_lock_t *lock, struct gf_flock *flock) static void __insert_lock (pl_inode_t *pl_inode, posix_lock_t *lock) { + if (lock->blocked) + gettimeofday (&lock->blkd_time, NULL); + else + gettimeofday (&lock->granted_time, NULL); + list_add_tail (&lock->list, &pl_inode->ext_list); return; diff --git a/xlators/features/locks/src/common.h b/xlators/features/locks/src/common.h index dddcd339ba7..d95e287cb94 100644 --- a/xlators/features/locks/src/common.h +++ b/xlators/features/locks/src/common.h @@ -20,6 +20,7 @@ #ifndef __COMMON_H__ #define __COMMON_H__ +#define SET_FLOCK_PID(flock, lock) ((flock)->l_pid = lock->client_pid) posix_lock_t * new_posix_lock (struct gf_flock *flock, void *transport, pid_t client_pid, uint64_t owner, fd_t *fd); diff --git a/xlators/features/locks/src/entrylk.c b/xlators/features/locks/src/entrylk.c index c3f40829b57..886a30b0ef2 100644 --- a/xlators/features/locks/src/entrylk.c +++ b/xlators/features/locks/src/entrylk.c @@ -349,6 +349,7 @@ __lock_name (pl_inode_t *pinode, const char *basename, entrylk_type type, } + gettimeofday (&lock->blkd_time, NULL); list_add_tail (&lock->blocked_locks, &dom->blocked_entrylks); gf_log (this->name, GF_LOG_TRACE, @@ -370,6 +371,7 @@ __lock_name (pl_inode_t *pinode, const char *basename, entrylk_type type, lock->frame = frame; lock->this = this; + gettimeofday (&lock->blkd_time, NULL); list_add_tail (&lock->blocked_locks, &dom->blocked_entrylks); gf_log (this->name, GF_LOG_TRACE, @@ -384,6 +386,7 @@ __lock_name (pl_inode_t *pinode, const char *basename, entrylk_type type, switch (type) { case ENTRYLK_WRLCK: + gettimeofday (&lock->granted_time, NULL); list_add_tail (&lock->domain_list, &dom->entrylk_list); break; diff --git a/xlators/features/locks/src/inodelk.c b/xlators/features/locks/src/inodelk.c index aa2b2855d93..94ecfc265ad 100644 --- a/xlators/features/locks/src/inodelk.c +++ b/xlators/features/locks/src/inodelk.c @@ -208,6 +208,7 @@ __lock_inodelk (xlator_t *this, pl_inode_t *pl_inode, pl_inode_lock_t *lock, if (can_block == 0) goto out; + gettimeofday (&lock->blkd_time, NULL); list_add_tail (&lock->blocked_locks, &dom->blocked_inodelks); gf_log (this->name, GF_LOG_TRACE, @@ -227,6 +228,7 @@ __lock_inodelk (xlator_t *this, pl_inode_t *pl_inode, pl_inode_lock_t *lock, if (can_block == 0) goto out; + gettimeofday (&lock->blkd_time, NULL); list_add_tail (&lock->blocked_locks, &dom->blocked_inodelks); gf_log (this->name, GF_LOG_TRACE, @@ -242,6 +244,7 @@ __lock_inodelk (xlator_t *this, pl_inode_t *pl_inode, pl_inode_lock_t *lock, goto out; } + gettimeofday (&lock->granted_time, NULL); list_add (&lock->list, &dom->inodelk_list); ret = 0; diff --git a/xlators/features/locks/src/locks.h b/xlators/features/locks/src/locks.h index ab70064a9d9..476b9a83cd6 100644 --- a/xlators/features/locks/src/locks.h +++ b/xlators/features/locks/src/locks.h @@ -48,6 +48,9 @@ struct __posix_lock { fd_t *fd; call_frame_t *frame; + struct timeval blkd_time; /*time at which lock was queued into blkd list*/ + struct timeval granted_time; /*time at which lock was queued into active list*/ + /* These two together serve to uniquely identify each process across nodes */ @@ -73,6 +76,9 @@ struct __pl_inode_lock { call_frame_t *frame; + struct timeval blkd_time; /*time at which lock was queued into blkd list*/ + struct timeval granted_time; /*time at which lock was queued into active list*/ + /* These two together serve to uniquely identify each process across nodes */ @@ -111,6 +117,9 @@ struct __entry_lock { const char *basename; entrylk_type type; + struct timeval blkd_time; /*time at which lock was queued into blkd list*/ + struct timeval granted_time; /*time at which lock was queued into active list*/ + void *trans; pid_t client_pid; /* pid of client process */ uint64_t owner; diff --git a/xlators/features/locks/src/posix.c b/xlators/features/locks/src/posix.c index 20f6cdd66d9..62bdf812dee 100644 --- a/xlators/features/locks/src/posix.c +++ b/xlators/features/locks/src/posix.c @@ -1504,7 +1504,8 @@ out: void pl_dump_lock (char *str, int size, struct gf_flock *flock, - uint64_t owner, void *trans) + uint64_t owner, void *trans, time_t *granted_time, + time_t *blkd_time, gf_boolean_t active) { char *type_str = NULL; @@ -1523,13 +1524,22 @@ pl_dump_lock (char *str, int size, struct gf_flock *flock, break; } - snprintf (str, size, "type=%s, start=%llu, len=%llu, pid=%llu, lk-owner=%llu, transport=%p", - type_str, (unsigned long long) flock->l_start, - (unsigned long long) flock->l_len, - (unsigned long long) flock->l_pid, - (unsigned long long) owner, - trans); - + if (active) + snprintf (str, size, "type=%s, start=%llu, len=%llu, pid=%llu, lk-owner=%llu, transport=%p, " + "blocked at %s, granted at %s", + type_str, (unsigned long long) flock->l_start, + (unsigned long long) flock->l_len, + (unsigned long long) flock->l_pid, + (unsigned long long) owner, + trans, ctime (blkd_time), ctime (granted_time)); + else + snprintf (str, size, "type=%s, start=%llu, len=%llu, pid=%llu, lk-owner=%llu, transport=%p, " + "blocked at %s", + type_str, (unsigned long long) flock->l_start, + (unsigned long long) flock->l_len, + (unsigned long long) flock->l_pid, + (unsigned long long) owner, + trans, ctime (blkd_time)); } @@ -1556,12 +1566,15 @@ __dump_entrylks (pl_inode_t *pl_inode) gf_proc_dump_build_key(key, "xlator.feature.locks.lock-dump.domain.entrylk", - "entrylk[%d](ACTIVE)",count ); - snprintf (tmp, 256," %s on %s owner=%llu, transport=%p", + "entrylk[%d](ACTIVE)", count ); + snprintf (tmp, 256," %s on %s pid = %llu, owner=%llu, transport=%p," + " blocked at %s, granted at %s", lock->type == ENTRYLK_RDLCK ? "ENTRYLK_RDLCK" : "ENTRYLK_WRLCK", lock->basename, - (unsigned long long) lock->owner, - lock->trans); + (unsigned long long) lock->client_pid, + (unsigned long long) lock->owner, lock->trans, + ctime (&lock->blkd_time.tv_sec), + ctime (&lock->granted_time.tv_sec)); gf_proc_dump_write(key, tmp); @@ -1572,12 +1585,14 @@ __dump_entrylks (pl_inode_t *pl_inode) gf_proc_dump_build_key(key, "xlator.feature.locks.lock-dump.domain.entrylk", - "entrylk[%d](BLOCKED)",count ); - snprintf (tmp, 256," %s on %s owner=%llu, transport=%p," - " state = Blocked", + "entrylk[%d](BLOCKED)", count ); + snprintf (tmp, 256," %s on %s pid = %llu, owner=%llu, transport=%p," + " blocked at %s", lock->type == ENTRYLK_RDLCK ? "ENTRYLK_RDLCK" : "ENTRYLK_WRLCK", lock->basename, - (unsigned long long) lock->owner, lock->trans); + (unsigned long long) lock->client_pid, + (unsigned long long) lock->owner, lock->trans, + ctime (&lock->blkd_time.tv_sec)); gf_proc_dump_write(key, tmp); @@ -1624,8 +1639,12 @@ __dump_inodelks (pl_inode_t *pl_inode) "xlator.feature.locks.lock-dump.domain.inodelk", "inodelk[%d](ACTIVE)",count ); + SET_FLOCK_PID (&lock->user_flock, lock); pl_dump_lock (tmp, 256, &lock->user_flock, - lock->owner, lock->transport); + lock->owner, lock->transport, + &lock->granted_time.tv_sec, + &lock->blkd_time.tv_sec, + _gf_true); gf_proc_dump_write(key, tmp); count++; @@ -1636,8 +1655,11 @@ __dump_inodelks (pl_inode_t *pl_inode) gf_proc_dump_build_key(key, "xlator.feature.locks.lock-dump.domain.inodelk", "inodelk[%d](BLOCKED)",count ); + SET_FLOCK_PID (&lock->user_flock, lock); pl_dump_lock (tmp, 256, &lock->user_flock, - lock->owner, lock->transport); + lock->owner, lock->transport, + 0, &lock->blkd_time.tv_sec, + _gf_false); gf_proc_dump_write(key, tmp); count++; @@ -1669,13 +1691,16 @@ __dump_posixlks (pl_inode_t *pl_inode) list_for_each_entry (lock, &pl_inode->ext_list, list) { + SET_FLOCK_PID (&lock->user_flock, lock); gf_proc_dump_build_key(key, "xlator.feature.locks.lock-dump.domain.posixlk", "posixlk[%d](%s)", count, lock->blocked ? "BLOCKED" : "ACTIVE"); pl_dump_lock (tmp, 256, &lock->user_flock, - lock->owner, lock->transport); + lock->owner, lock->transport, + &lock->granted_time.tv_sec, &lock->blkd_time.tv_sec, + (lock->blocked)? _gf_false: _gf_true); gf_proc_dump_write(key, tmp); count++; -- cgit