summaryrefslogtreecommitdiffstats
path: root/libglusterfs
diff options
context:
space:
mode:
authorVikas Gorur <vikas@gluster.com>2010-04-04 14:11:26 +0000
committerAnand V. Avati <avati@dev.gluster.com>2010-04-04 22:27:04 -0700
commitd90c2f86ca7a8f6660e98da1e48c4798539b7d51 (patch)
tree2c0bab231490147b95d488cb097b8edd56670cea /libglusterfs
parent9c2bfa8a4441d27178f3b843bfa0a77df9f867e5 (diff)
core: Do internal latency measurement of FOPs.
This patch adds a facility by which each translator keeps track of the average latency of a FOP from its point of view. That is, the duration between the translator handing over the call to a lower-level translator and the reply coming back. The latency measurement is off by default, and can be toggled by sending SIGUSR2 to the GlusterFS process. Latency data is printed as part of the process state dump. Signed-off-by: Vikas Gorur <vikas@gluster.com> Signed-off-by: Anand V. Avati <avati@dev.gluster.com> BUG: 268 (Add timing instrumentation code) URL: http://bugs.gluster.com/cgi-bin/bugzilla3/show_bug.cgi?id=268
Diffstat (limited to 'libglusterfs')
-rw-r--r--libglusterfs/src/Makefile.am4
-rw-r--r--libglusterfs/src/glusterfs.h1
-rw-r--r--libglusterfs/src/latency.c191
-rw-r--r--libglusterfs/src/latency.h36
-rw-r--r--libglusterfs/src/stack.h56
-rw-r--r--libglusterfs/src/statedump.c4
-rw-r--r--libglusterfs/src/xlator.h4
7 files changed, 292 insertions, 4 deletions
diff --git a/libglusterfs/src/Makefile.am b/libglusterfs/src/Makefile.am
index 755c2d807ce..82c634dea61 100644
--- a/libglusterfs/src/Makefile.am
+++ b/libglusterfs/src/Makefile.am
@@ -6,9 +6,9 @@ libglusterfs_la_LIBADD = @LEXLIB@
lib_LTLIBRARIES = libglusterfs.la
-libglusterfs_la_SOURCES = dict.c spec.lex.c y.tab.c xlator.c logging.c hashfn.c defaults.c scheduler.c common-utils.c transport.c timer.c inode.c call-stub.c compat.c authenticate.c fd.c compat-errno.c event.c mem-pool.c gf-dirent.c syscall.c iobuf.c globals.c statedump.c stack.c checksum.c md5.c $(CONTRIBDIR)/rbtree/rb.c rbthash.c
+libglusterfs_la_SOURCES = dict.c spec.lex.c y.tab.c xlator.c logging.c hashfn.c defaults.c scheduler.c common-utils.c transport.c timer.c inode.c call-stub.c compat.c authenticate.c fd.c compat-errno.c event.c mem-pool.c gf-dirent.c syscall.c iobuf.c globals.c statedump.c stack.c checksum.c md5.c $(CONTRIBDIR)/rbtree/rb.c rbthash.c latency.c
-noinst_HEADERS = common-utils.h defaults.h dict.h glusterfs.h hashfn.h logging.h protocol.h scheduler.h xlator.h transport.h stack.h timer.h list.h inode.h call-stub.h compat.h authenticate.h fd.h revision.h compat-errno.h event.h mem-pool.h byte-order.h gf-dirent.h locking.h syscall.h iobuf.h globals.h statedump.h checksum.h md5.h $(CONTRIBDIR)/rbtree/rb.h rbthash.h iatt.h
+noinst_HEADERS = common-utils.h defaults.h dict.h glusterfs.h hashfn.h logging.h protocol.h scheduler.h xlator.h transport.h stack.h timer.h list.h inode.h call-stub.h compat.h authenticate.h fd.h revision.h compat-errno.h event.h mem-pool.h byte-order.h gf-dirent.h locking.h syscall.h iobuf.h globals.h statedump.h checksum.h md5.h $(CONTRIBDIR)/rbtree/rb.h rbthash.h iatt.h latency.h
EXTRA_DIST = spec.l spec.y
diff --git a/libglusterfs/src/glusterfs.h b/libglusterfs/src/glusterfs.h
index 4abde409b92..cf87af7d32b 100644
--- a/libglusterfs/src/glusterfs.h
+++ b/libglusterfs/src/glusterfs.h
@@ -260,6 +260,7 @@ struct _glusterfs_ctx {
int xl_count;
uint32_t volfile_checksum;
size_t page_size;
+ unsigned char measure_latency; /* toggle switch for latency measurement */
};
typedef struct _glusterfs_ctx glusterfs_ctx_t;
diff --git a/libglusterfs/src/latency.c b/libglusterfs/src/latency.c
new file mode 100644
index 00000000000..bccc780a26f
--- /dev/null
+++ b/libglusterfs/src/latency.c
@@ -0,0 +1,191 @@
+/*
+ Copyright (c) 2009 Gluster, Inc. <http://www.gluster.com>
+ This file is part of GlusterFS.
+
+ GlusterFS is free software; you can redistribute it and/or modify
+ it under the terms of the GNU General Public License as published
+ by the Free Software Foundation; either version 3 of the License,
+ or (at your option) any later version.
+
+ GlusterFS is distributed in the hope that it will be useful, but
+ WITHOUT ANY WARRANTY; without even the implied warranty of
+ MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
+ General Public License for more details.
+
+ You should have received a copy of the GNU General Public License
+ along with this program. If not, see
+ <http://www.gnu.org/licenses/>.
+*/
+
+
+/*
+ * This file contains functions to support dumping of
+ * latencies of FOPs broken down by subvolumes.
+ */
+
+#include "glusterfs.h"
+#include "stack.h"
+#include "xlator.h"
+#include "common-utils.h"
+#include "statedump.h"
+
+
+void
+gf_set_fop_from_fn_pointer (call_frame_t *frame, struct xlator_fops *fops,
+ struct xlator_mops *mops, void *fn)
+{
+ glusterfs_fop_t fop = -1;
+
+ if (fops->stat == fn)
+ fop = GF_FOP_STAT;
+ else if (fops->readlink == fn)
+ fop = GF_FOP_READLINK;
+ else if (fops->mknod == fn)
+ fop = GF_FOP_MKNOD;
+ else if (fops->mkdir == fn)
+ fop = GF_FOP_MKDIR;
+ else if (fops->unlink == fn)
+ fop = GF_FOP_UNLINK;
+ else if (fops->rmdir == fn)
+ fop = GF_FOP_RMDIR;
+ else if (fops->symlink == fn)
+ fop = GF_FOP_SYMLINK;
+ else if (fops->rename == fn)
+ fop = GF_FOP_RENAME;
+ else if (fops->link == fn)
+ fop = GF_FOP_LINK;
+ else if (fops->truncate == fn)
+ fop = GF_FOP_TRUNCATE;
+ else if (fops->open == fn)
+ fop = GF_FOP_OPEN;
+ else if (fops->readv == fn)
+ fop = GF_FOP_READ;
+ else if (fops->writev == fn)
+ fop = GF_FOP_WRITE;
+ else if (fops->statfs == fn)
+ fop = GF_FOP_STATFS;
+ else if (fops->flush == fn)
+ fop = GF_FOP_FLUSH;
+ else if (fops->fsync == fn)
+ fop = GF_FOP_FSYNC;
+ else if (fops->setxattr == fn)
+ fop = GF_FOP_SETXATTR;
+ else if (fops->getxattr == fn)
+ fop = GF_FOP_GETXATTR;
+ else if (fops->removexattr == fn)
+ fop = GF_FOP_REMOVEXATTR;
+ else if (fops->opendir == fn)
+ fop = GF_FOP_OPENDIR;
+ else if (fops->fsyncdir == fn)
+ fop = GF_FOP_FSYNCDIR;
+ else if (fops->access == fn)
+ fop = GF_FOP_ACCESS;
+ else if (fops->create == fn)
+ fop = GF_FOP_CREATE;
+ else if (fops->ftruncate == fn)
+ fop = GF_FOP_FTRUNCATE;
+ else if (fops->fstat == fn)
+ fop = GF_FOP_FSTAT;
+ else if (fops->lk == fn)
+ fop = GF_FOP_LK;
+ else if (fops->lookup == fn)
+ fop = GF_FOP_LOOKUP;
+ else if (fops->readdir == fn)
+ fop = GF_FOP_READDIR;
+ else if (fops->inodelk == fn)
+ fop = GF_FOP_INODELK;
+ else if (fops->finodelk == fn)
+ fop = GF_FOP_FINODELK;
+ else if (fops->entrylk == fn)
+ fop = GF_FOP_ENTRYLK;
+ else if (fops->fentrylk == fn)
+ fop = GF_FOP_FENTRYLK;
+ else if (fops->checksum == fn)
+ fop = GF_FOP_CHECKSUM;
+ else if (fops->xattrop == fn)
+ fop = GF_FOP_XATTROP;
+ else if (fops->fxattrop == fn)
+ fop = GF_FOP_FXATTROP;
+ else if (fops->fgetxattr == fn)
+ fop = GF_FOP_FGETXATTR;
+ else if (fops->fsetxattr == fn)
+ fop = GF_FOP_FSETXATTR;
+ else if (fops->rchecksum == fn)
+ fop = GF_FOP_RCHECKSUM;
+ else if (fops->setattr == fn)
+ fop = GF_FOP_SETATTR;
+ else if (fops->fsetattr == fn)
+ fop = GF_FOP_FSETATTR;
+ else if (fops->readdirp == fn)
+ fop = GF_FOP_READDIRP;
+ else {
+ if (mops->getspec == fn)
+ fop = GF_MOP_GETSPEC;
+ else if (mops->log == fn)
+ fop = GF_MOP_LOG;
+ else {
+ fop = -1;
+ }
+ }
+
+ frame->op = fop;
+}
+
+
+void
+gf_update_latency (call_frame_t *frame)
+{
+ double elapsed;
+ struct timeval *begin, *end;
+
+ fop_latency_t *lat;
+
+ begin = &frame->begin;
+ end = &frame->end;
+
+ elapsed = (end->tv_sec - begin->tv_sec) * 1e6
+ + (end->tv_usec - begin->tv_usec);
+
+ lat = &frame->this->latencies[frame->op];
+
+ lat->total += elapsed;
+ lat->count++;
+ lat->mean = lat->mean + (elapsed - lat->mean) / lat->count;
+}
+
+
+void
+gf_proc_dump_latency_info (xlator_t *xl)
+{
+ char key_prefix[GF_DUMP_MAX_BUF_LEN];
+ char key[GF_DUMP_MAX_BUF_LEN];
+ int i;
+
+ snprintf (key_prefix, GF_DUMP_MAX_BUF_LEN, "%s.latency", xl->name);
+ gf_proc_dump_add_section (key_prefix);
+
+ for (i = 0; i < GF_FOP_MAXVALUE; i++) {
+ gf_proc_dump_build_key (key, key_prefix, gf_fop_list[i]);
+
+ gf_proc_dump_write (key, "%.03f,%"PRId64",%.03f",
+ xl->latencies[i].mean,
+ xl->latencies[i].count,
+ xl->latencies[i].total);
+ }
+}
+
+
+void
+gf_latency_toggle (int signum)
+{
+ glusterfs_ctx_t *ctx = NULL;
+
+ ctx = get_global_ctx_ptr ();
+
+ if (ctx) {
+ ctx->measure_latency = !ctx->measure_latency;
+ gf_log ("[core]", GF_LOG_NORMAL,
+ "Latency measurement turned %s",
+ ctx->measure_latency ? "on" : "off");
+ }
+}
diff --git a/libglusterfs/src/latency.h b/libglusterfs/src/latency.h
new file mode 100644
index 00000000000..ba7d76cddca
--- /dev/null
+++ b/libglusterfs/src/latency.h
@@ -0,0 +1,36 @@
+/*
+ Copyright (c) 2009 Gluster, Inc. <http://www.gluster.com>
+ This file is part of GlusterFS.
+
+ GlusterFS is free software; you can redistribute it and/or modify
+ it under the terms of the GNU General Public License as published
+ by the Free Software Foundation; either version 3 of the License,
+ or (at your option) any later version.
+
+ GlusterFS is distributed in the hope that it will be useful, but
+ WITHOUT ANY WARRANTY; without even the implied warranty of
+ MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
+ General Public License for more details.
+
+ You should have received a copy of the GNU General Public License
+ along with this program. If not, see
+ <http://www.gnu.org/licenses/>.
+*/
+
+#ifndef __LATENCY_H__
+#define __LATENCY_H__
+
+
+typedef struct fop_latency {
+ uint64_t min; /* min time for the call (microseconds) */
+ uint64_t max; /* max time for the call (microseconds) */
+ double total; /* total time (microseconds) */
+ double std; /* standard deviation */
+ double mean; /* mean (microseconds) */
+ uint64_t count;
+} fop_latency_t;
+
+void
+gf_latency_toggle (int signum);
+
+#endif /* __LATENCY_H__ */
diff --git a/libglusterfs/src/stack.h b/libglusterfs/src/stack.h
index cc059f06873..25925f7a699 100644
--- a/libglusterfs/src/stack.h
+++ b/libglusterfs/src/stack.h
@@ -37,6 +37,8 @@ typedef struct _call_frame_t call_frame_t;
struct _call_pool_t;
typedef struct _call_pool_t call_pool_t;
+#include <sys/time.h>
+
#include "xlator.h"
#include "dict.h"
#include "list.h"
@@ -76,6 +78,10 @@ struct _call_frame_t {
gf_lock_t lock;
void *cookie; /* unique cookie */
gf_boolean_t complete;
+
+ glusterfs_fop_t op;
+ struct timeval begin; /* when this frame was created */
+ struct timeval end; /* when this frame completed */
};
struct _call_stack_t {
@@ -113,6 +119,16 @@ struct _call_stack_t {
} \
} while (0); \
+struct xlator_fops;
+struct xlator_mops;
+
+void
+gf_set_fop_from_fn_pointer (call_frame_t *frame, struct xlator_fops *fops,
+ struct xlator_mops *mops, void *fn);
+
+void
+gf_update_latency (call_frame_t *frame);
+
static inline void
FRAME_DESTROY (call_frame_t *frame)
{
@@ -130,6 +146,13 @@ FRAME_DESTROY (call_frame_t *frame)
static inline void
STACK_DESTROY (call_stack_t *stack)
{
+ glusterfs_ctx_t *ctx = get_global_ctx_ptr ();
+
+ if (ctx && ctx->measure_latency) {
+ gettimeofday (&stack->frames.end, NULL);
+ gf_update_latency (&stack->frames);
+ }
+
LOCK (&stack->pool->lock);
{
list_del_init (&stack->all_frames);
@@ -143,6 +166,10 @@ STACK_DESTROY (call_stack_t *stack)
LOCK_DESTROY (&stack->frames.lock);
while (stack->frames.next) {
+ if (ctx && ctx->measure_latency) {
+ gf_update_latency (stack->frames.next);
+ }
+
FRAME_DESTROY (stack->frames.next);
}
FREE (stack);
@@ -173,7 +200,12 @@ STACK_DESTROY (call_stack_t *stack)
_new->cookie = _new; \
LOCK_INIT (&_new->lock); \
frame->ref_count++; \
- \
+ \
+ if (((xlator_t *) obj)->ctx->measure_latency) { \
+ gettimeofday (&_new->begin, NULL); \
+ gf_set_fop_from_fn_pointer (_new, ((xlator_t *)obj)->fops, ((xlator_t *)obj)->mops, fn); \
+ } \
+ \
old_THIS = THIS; \
THIS = obj; \
fn (_new, obj, params); \
@@ -203,7 +235,12 @@ STACK_DESTROY (call_stack_t *stack)
LOCK_INIT (&_new->lock); \
frame->ref_count++; \
fn##_cbk = rfn; \
- \
+ \
+ if (((xlator_t *) obj)->ctx->measure_latency) { \
+ gettimeofday (&_new->begin, NULL); \
+ gf_set_fop_from_fn_pointer (_new, ((xlator_t *)obj)->fops, ((xlator_t *)obj)->mops, fn); \
+ } \
+ \
old_THIS = THIS; \
THIS = obj; \
fn (_new, obj, params); \
@@ -224,6 +261,11 @@ STACK_DESTROY (call_stack_t *stack)
old_THIS = THIS; \
THIS = _parent->this; \
frame->complete = _gf_true; \
+ \
+ if (((xlator_t *) old_THIS)->ctx->measure_latency) { \
+ gettimeofday (&frame->end, NULL); \
+ } \
+ \
fn (_parent, frame->cookie, _parent->this, params); \
THIS = old_THIS; \
} while (0)
@@ -242,6 +284,11 @@ STACK_DESTROY (call_stack_t *stack)
old_THIS = THIS; \
THIS = _parent->this; \
frame->complete = _gf_true; \
+ \
+ if (((xlator_t *) old_THIS)->ctx->measure_latency) { \
+ gettimeofday (&frame->end, NULL); \
+ } \
+ \
fn (_parent, frame->cookie, _parent->this, params); \
THIS = old_THIS; \
} while (0)
@@ -294,6 +341,7 @@ static inline call_frame_t *
create_frame (xlator_t *xl, call_pool_t *pool)
{
call_stack_t *stack = NULL;
+ glusterfs_ctx_t *ctx = get_global_ctx_ptr ();
if (!xl || !pool) {
return NULL;
@@ -316,6 +364,10 @@ create_frame (xlator_t *xl, call_pool_t *pool)
LOCK_INIT (&stack->frames.lock);
+ if (ctx && ctx->measure_latency) {
+ gettimeofday (&stack->frames.begin, NULL);
+ }
+
return &stack->frames;
}
diff --git a/libglusterfs/src/statedump.c b/libglusterfs/src/statedump.c
index 7f1e3e24196..4e42280068f 100644
--- a/libglusterfs/src/statedump.c
+++ b/libglusterfs/src/statedump.c
@@ -141,6 +141,7 @@ gf_proc_dump_mem_info ()
}
+void gf_proc_dump_latency_info (xlator_t *xl);
void
gf_proc_dump_xlator_info (xlator_t *this_xl)
@@ -150,6 +151,8 @@ gf_proc_dump_xlator_info (xlator_t *this_xl)
return;
while (this_xl) {
+ gf_proc_dump_latency_info (this_xl);
+
if (!this_xl->dumpops) {
this_xl = this_xl->next;
continue;
@@ -160,6 +163,7 @@ gf_proc_dump_xlator_info (xlator_t *this_xl)
this_xl->dumpops->inode(this_xl);
if (this_xl->dumpops->fd)
this_xl->dumpops->fd(this_xl);
+
this_xl = this_xl->next;
}
diff --git a/libglusterfs/src/xlator.h b/libglusterfs/src/xlator.h
index 8cde2ed31c3..993679b2500 100644
--- a/libglusterfs/src/xlator.h
+++ b/libglusterfs/src/xlator.h
@@ -36,6 +36,7 @@
#include "dict.h"
#include "compat.h"
#include "list.h"
+#include "latency.h"
#define FIRST_CHILD(xl) (xl->children->xlator)
@@ -847,6 +848,9 @@ struct _xlator {
int32_t (*init) (xlator_t *this);
event_notify_fn_t notify;
+ /* for latency measurement */
+ fop_latency_t latencies[GF_FOP_MAXVALUE];
+
/* Misc */
glusterfs_ctx_t *ctx;
inode_table_t *itable;