FAQ Search Today's Posts Mark Forums Read
» Video Reviews

» Linux Archive

Linux-archive is a website aiming to archive linux email lists and to make them easily accessible for linux users/developers.


» Sponsor

» Partners

» Sponsor

Go Back   Linux Archive > Redhat > Cluster Development

 
 
LinkBack Thread Tools
 
Old 11-04-2011, 02:19 PM
Steven Whitehouse
 
Default GFS2: glock statistics gathering (RFC)

Hi,

This is a work-in-progress at the moment, though I hope that it
is not too far from the final form. The intent here is to add
some code to gather some important and useful stats to help
track what is going on within the filesystem.

The stats are divided into two sets: those relating to the
super block and those relating to an individual glock. The
super block stats are done on a per cpu basis in order to
try and reduce the overhead of gathering them. They are also
further divided by glock type.

In the case of both the super block and glock statistics,
the same information is gathered in each case. The super
block statistics are used to provide default values for
most of the glock statistics, so that newly created glocks
should have, as far as possible a sensible starting point.

The statistics are divided into three pairs of mean and
variance, plus two counters. The mean/variance pairs are
smoothed exponential estimates and the algorithm used is
one which will be very familiar to those used to calculation
of round trip times in network code.

The three pairs of mean/variance measure the following
things:

1. DLM lock time (non-blocking requests)
2. DLM lock time (blocking requests)
3. Inter-request time (again to the DLM)

A non-blocking request is one which will complete right
away, whatever the state of the DLM lock in question. That
currently means any requests when (a) the current state of
the lock is exclusive (b) the requested state is either null
or unlocked or (c) the "try lock" flag is set. A blocking
request covers all the other lock requests.

There are two counters. The first is there primarily to show
how many lock requests have been made, and thus how much data
has gone into the mean/variance calculations. The other counter
is counting queueing of holders at the top layer of the glock
code. Hopefully that number will be a lot larger than the number
of dlm lock requests issued.

So why gather these statistics? There are several reasons
we'd like to get a better idea of these timings:

1. To be able to better set the glock "min hold time"
2. To spot performance issues more easily
3. To improve the algorithm for selecting resource groups for
allocation (to base it on lock wait time, rather than blindly
using a "try lock")

I'm hoping to settle on a suitable minimum set of statistics
which can give us the maximum amount of information for the
minimum amount of overhead, both in computational terms and
storage terms.

The stats take up 64 bytes per glock. Thats quite a lot, but
there is scope for reducing the size of the glock. One thing
I spotted was the ascii name field, used only once the first
time we get a DLM lock. The patch removes that, saving 32
bytes (by the time padding was included) per glock.

There is potential for a greater saving in the future, since
some of the existing time based fields could be removed in
favour of using the new stats. That will be left for
future patches though.

So some questions to ponder:

- Is this adding too much overhead?
- Do we need so much detail?
- Is there anything that has been missed out?

Obviously one concern is accuracy. Until the filesystem has
had a workload running on it for a while, the stats will not
be a true representation of what is going on in the system.
That is the reason for having the counters, so that we can see
how much data has been included.

Due to the smoothing action of the updates, a step change in
some input quantity being sampled will only fully be taken
into account after 8 samples (or 4 for the variance) and this
needs to be carefully considered when interpreting the
results.

Knowing both the time it takes a lock request to complete and
the average time between lock requests for a glock means we
can compute the total percentage of the time for which the
node is able to use a glock vs. time that the rest of the
cluster has its share. That will be very useful when setting
the lock min hold time.

The other point to remember is that all times are in
nanoseconds. Great care has been taken to ensure that we
measure exactly the quantities that we want, as accurately
as possible. There are always inaccuracies in any
measuring system, but I hope this is as accurate as we
can reasonably make it.

Anyway, here it is... let me know what you think,

Steve.

diff --git a/fs/gfs2/glock.c b/fs/gfs2/glock.c
index 88e8a23..267e748 100644
--- a/fs/gfs2/glock.c
+++ b/fs/gfs2/glock.c
@@ -29,6 +29,7 @@
#include <linux/rcupdate.h>
#include <linux/rculist_bl.h>
#include <linux/bit_spinlock.h>
+#include <linux/percpu.h>

#include "gfs2.h"
#include "incore.h"
@@ -537,6 +538,11 @@ __acquires(&gl->gl_spin)
do_error(gl, 0); /* Fail queued try locks */
}
gl->gl_req = target;
+ set_bit(GLF_BLOCKING, &gl->gl_flags);
+ if ((gl->gl_req == LM_ST_UNLOCKED) ||
+ *** (gl->gl_state == LM_ST_EXCLUSIVE) ||
+ *** (lck_flags & (LM_FLAG_TRY|LM_FLAG_TRY_1CB)))
+ clear_bit(GLF_BLOCKING, &gl->gl_flags);
spin_unlock(&gl->gl_spin);
if (glops->go_xmote_th)
glops->go_xmote_th(gl);
@@ -738,6 +744,7 @@ int gfs2_glock_get(struct gfs2_sbd *sdp, u64 number,
return -ENOMEM;

atomic_inc(&sdp->sd_glock_disposal);
+ gl->gl_sbd = sdp;
gl->gl_flags = 0;
gl->gl_name = name;
atomic_set(&gl->gl_ref, 1);
@@ -746,12 +753,17 @@ int gfs2_glock_get(struct gfs2_sbd *sdp, u64 number,
gl->gl_demote_state = LM_ST_EXCLUSIVE;
gl->gl_hash = hash;
gl->gl_ops = glops;
- snprintf(gl->gl_strname, GDLM_STRNAME_BYTES, "%8x%16llx", name.ln_type, (unsigned long long)number);
+ gl->gl_dstamp = ktime_set(0, 0);
+ preempt_disable();
+ /* We use the global stats to estimate the initial per-glock stats */
+ gl->gl_stats = this_cpu_ptr(sdp->sd_lkstats)->lkstats[glops->go_type];
+ preempt_enable();
+ gl->gl_stats.stats[GFS2_LKS_DCOUNT] = 0;
+ gl->gl_stats.stats[GFS2_LKS_QCOUNT] = 0;
memset(&gl->gl_lksb, 0, sizeof(struct dlm_lksb));
gl->gl_lksb.sb_lvbptr = gl->gl_lvb;
gl->gl_tchange = jiffies;
gl->gl_object = NULL;
- gl->gl_sbd = sdp;
gl->gl_hold_time = GL_GLOCK_DFT_HOLD;
INIT_DELAYED_WORK(&gl->gl_work, glock_work_func);
INIT_WORK(&gl->gl_delete, delete_work_func);
@@ -993,6 +1005,8 @@ fail:
}
set_bit(GLF_QUEUED, &gl->gl_flags);
trace_gfs2_glock_queue(gh, 1);
+ gfs2_glstats_inc(gl, GFS2_LKS_QCOUNT);
+ gfs2_sbstats_inc(gl, GFS2_LKS_QCOUNT);
if (likely(insert_pt == NULL)) {
list_add_tail(&gh->gh_list, &gl->gl_holders);
if (unlikely(gh->gh_flags & LM_FLAG_PRIORITY))
@@ -1652,6 +1666,8 @@ static const char *gflags2str(char *buf, const struct gfs2_glock *gl)
*p++ = 'L';
if (gl->gl_object)
*p++ = 'o';
+ if (test_bit(GLF_BLOCKING, gflags))
+ *p++ = 'b';
*p = 0;
return buf;
}
@@ -1708,8 +1724,76 @@ out:
return error;
}

+static int gfs2_glstats_seq_show(struct seq_file *seq, void *iter_ptr)
+{
+ struct gfs2_glock *gl = iter_ptr;
+
+ seq_printf(seq, "G: n:%u/%llx rtt:%lld/%lld rttb:%lld/%lld irt:%lld/%lld dcnt: %lld qcnt: %lld
",
+ ** gl->gl_name.ln_type,
+ ** (unsigned long long)gl->gl_name.ln_number,
+ ** (long long)gl->gl_stats.stats[GFS2_LKS_SRTT],
+ ** (long long)gl->gl_stats.stats[GFS2_LKS_SRTTVAR],
+ ** (long long)gl->gl_stats.stats[GFS2_LKS_SRTTB],
+ ** (long long)gl->gl_stats.stats[GFS2_LKS_SRTTVARB],
+ ** (long long)gl->gl_stats.stats[GFS2_LKS_SIRT],
+ ** (long long)gl->gl_stats.stats[GFS2_LKS_SIRTVAR],
+ ** (long long)gl->gl_stats.stats[GFS2_LKS_DCOUNT],
+ ** (long long)gl->gl_stats.stats[GFS2_LKS_QCOUNT]);
+ return 0;
+}
+
+static const char *gfs2_gltype[] = {
+ "type",
+ "reserved",
+ "nondisk",
+ "inode",
+ "rgrp",
+ "meta",
+ "iopen",
+ "flock",
+ "plock",
+ "quota",
+ "journal",
+};
+
+static const char *gfs2_stype[] = {
+ [GFS2_LKS_SRTT] = "srtt",
+ [GFS2_LKS_SRTTVAR] = "srttvar",
+ [GFS2_LKS_SRTTB] = "srttb",
+ [GFS2_LKS_SRTTVARB] = "srttvarb",
+ [GFS2_LKS_SIRT] = "sirt",
+ [GFS2_LKS_SIRTVAR] = "sirtvar",
+ [GFS2_LKS_DCOUNT] = "dlm",
+ [GFS2_LKS_QCOUNT] = "queue",
+};
+
+static int gfs2_sbstats_seq_show(struct seq_file *seq, void *iter_ptr)
+{
+ struct gfs2_glock_iter *gi = seq->private;
+ struct gfs2_sbd *sdp = gi->sdp;
+ unsigned index = gi->hash >> 3;
+ unsigned subindex = gi->hash & 0x07;
+ s64 value;
+ int i;
+
+ if (index == 0 && subindex != 0)
+ return 0;

+ seq_printf(seq, "%-10s %8s:", gfs2_gltype[index],
+ ** (index == 0) ? "cpu": gfs2_stype[subindex]);

+ for_each_possible_cpu(i) {
+*************** const struct gfs2_pcpu_lkstats *lkstats = per_cpu_ptr(sdp->sd_lkstats, i);
+ if (index == 0) {
+ value = i;
+ } else {
+ value = lkstats->lkstats[index - 1].stats[subindex];
+ }
+ seq_printf(seq, " %15lld", (long long)value);
+ }
+ seq_putc(seq, '
');
+ return 0;
+}

int __init gfs2_glock_init(void)
{
@@ -1822,6 +1906,35 @@ static int gfs2_glock_seq_show(struct seq_file *seq, void *iter_ptr)
return dump_glock(seq, iter_ptr);
}

+static void *gfs2_sbstats_seq_start(struct seq_file *seq, loff_t *pos)
+{
+ struct gfs2_glock_iter *gi = seq->private;
+
+ gi->hash = *pos;
+ if (*pos > 87)
+ return NULL;
+ preempt_disable();
+ return SEQ_START_TOKEN;
+}
+
+static void *gfs2_sbstats_seq_next(struct seq_file *seq, void *iter_ptr,
+ ** loff_t *pos)
+{
+ struct gfs2_glock_iter *gi = seq->private;
+ (*pos)++;
+ gi->hash++;
+ if (gi->hash > 87) {
+ preempt_enable();
+ return NULL;
+ }
+ return SEQ_START_TOKEN;
+}
+
+static void gfs2_sbstats_seq_stop(struct seq_file *seq, void *iter_ptr)
+{
+ preempt_enable();
+}
+
static const struct seq_operations gfs2_glock_seq_ops = {
.start = gfs2_glock_seq_start,
.next* = gfs2_glock_seq_next,
@@ -1829,7 +1942,21 @@ static const struct seq_operations gfs2_glock_seq_ops = {
.show* = gfs2_glock_seq_show,
};

-static int gfs2_debugfs_open(struct inode *inode, struct file *file)
+static const struct seq_operations gfs2_glstats_seq_ops = {
+ .start = gfs2_glock_seq_start,
+ .next* = gfs2_glock_seq_next,
+ .stop* = gfs2_glock_seq_stop,
+ .show* = gfs2_glstats_seq_show,
+};
+
+static const struct seq_operations gfs2_sbstats_seq_ops = {
+ .start = gfs2_sbstats_seq_start,
+ .next* = gfs2_sbstats_seq_next,
+ .stop* = gfs2_sbstats_seq_stop,
+ .show* = gfs2_sbstats_seq_show,
+};
+
+static int gfs2_glocks_open(struct inode *inode, struct file *file)
{
int ret = seq_open_private(file, &gfs2_glock_seq_ops,
** sizeof(struct gfs2_glock_iter));
@@ -1841,9 +1968,49 @@ static int gfs2_debugfs_open(struct inode *inode, struct file *file)
return ret;
}

-static const struct file_operations gfs2_debug_fops = {
+static int gfs2_glstats_open(struct inode *inode, struct file *file)
+{
+ int ret = seq_open_private(file, &gfs2_glstats_seq_ops,
+ ** sizeof(struct gfs2_glock_iter));
+ if (ret == 0) {
+ struct seq_file *seq = file->private_data;
+ struct gfs2_glock_iter *gi = seq->private;
+ gi->sdp = inode->i_private;
+ }
+ return ret;
+}
+
+static int gfs2_sbstats_open(struct inode *inode, struct file *file)
+{
+ int ret = seq_open_private(file, &gfs2_sbstats_seq_ops,
+ ** sizeof(struct gfs2_glock_iter));
+ if (ret == 0) {
+ struct seq_file *seq = file->private_data;
+ struct gfs2_glock_iter *gi = seq->private;
+ gi->sdp = inode->i_private;
+ }
+ return ret;
+}
+
+static const struct file_operations gfs2_glocks_fops = {
+ .owner** = THIS_MODULE,
+ .open*** = gfs2_glocks_open,
+ .read*** = seq_read,
+ .llseek* = seq_lseek,
+ .release = seq_release_private,
+};
+
+static const struct file_operations gfs2_glstats_fops = {
.owner** = THIS_MODULE,
- .open*** = gfs2_debugfs_open,
+ .open*** = gfs2_glstats_open,
+ .read*** = seq_read,
+ .llseek* = seq_lseek,
+ .release = seq_release_private,
+};
+
+static const struct file_operations gfs2_sbstats_fops = {
+ .owner** = THIS_MODULE,
+ .open = gfs2_sbstats_open,
.read*** = seq_read,
.llseek* = seq_lseek,
.release = seq_release_private,
@@ -1857,20 +2024,45 @@ int gfs2_create_debugfs_file(struct gfs2_sbd *sdp)
sdp->debugfs_dentry_glocks = debugfs_create_file("glocks",
S_IFREG | S_IRUGO,
sdp->debugfs_dir, sdp,
- &gfs2_debug_fops);
+ &gfs2_glocks_fops);
if (!sdp->debugfs_dentry_glocks)
- return -ENOMEM;
+ goto fail;
+
+ sdp->debugfs_dentry_glstats = debugfs_create_file("glstats",
+ S_IFREG | S_IRUGO,
+ sdp->debugfs_dir, sdp,
+ &gfs2_glstats_fops);
+ if (!sdp->debugfs_dentry_glstats)
+ goto fail;
+
+ sdp->debugfs_dentry_sbstats = debugfs_create_file("sbstats",
+ S_IFREG | S_IRUGO,
+ sdp->debugfs_dir, sdp,
+ &gfs2_sbstats_fops);
+ if (!sdp->debugfs_dentry_sbstats)
+ goto fail;

return 0;
+fail:
+ gfs2_delete_debugfs_file(sdp);
+ return -ENOMEM;
}

void gfs2_delete_debugfs_file(struct gfs2_sbd *sdp)
{
- if (sdp && sdp->debugfs_dir) {
+ if (sdp->debugfs_dir) {
if (sdp->debugfs_dentry_glocks) {
debugfs_remove(sdp->debugfs_dentry_glocks);
sdp->debugfs_dentry_glocks = NULL;
}
+ if (sdp->debugfs_dentry_glstats) {
+ debugfs_remove(sdp->debugfs_dentry_glstats);
+ sdp->debugfs_dentry_glstats = NULL;
+ }
+ if (sdp->debugfs_dentry_sbstats) {
+ debugfs_remove(sdp->debugfs_dentry_sbstats);
+ sdp->debugfs_dentry_sbstats = NULL;
+ }
debugfs_remove(sdp->debugfs_dir);
sdp->debugfs_dir = NULL;
}
diff --git a/fs/gfs2/incore.h b/fs/gfs2/incore.h
index 7389dfd..4c783ba 100644
--- a/fs/gfs2/incore.h
+++ b/fs/gfs2/incore.h
@@ -19,6 +19,8 @@
#include <linux/rculist_bl.h>
#include <linux/completion.h>
#include <linux/rbtree.h>
+#include <linux/ktime.h>
+#include <linux/percpu.h>

#define DIO_WAIT 0x00000010
#define DIO_METADATA 0x00000020
@@ -168,6 +170,21 @@ struct gfs2_glock_operations {
};

enum {
+ GFS2_LKS_SRTT = 0, /* Non blocking smoothed round trip time */
+ GFS2_LKS_SRTTVAR = 1, /* Non blocking smoothed variance */
+ GFS2_LKS_SRTTB = 2, /* Blocking smoothed round trip time */
+ GFS2_LKS_SRTTVARB = 3, /* Blocking smoothed variance */
+ GFS2_LKS_SIRT = 4, /* Smoothed Inter-request time */
+ GFS2_LKS_SIRTVAR = 5, /* Smoothed Inter-request variance */
+ GFS2_LKS_DCOUNT = 6, /* Count of dlm requests */
+ GFS2_LKS_QCOUNT = 7 /* Count of gfs2_holder queues */
+};
+
+struct gfs2_lkstats {
+ s64 stats[8];
+};
+
+enum {
/* States */
HIF_HOLDER = 6,* /* Set for gh that "holds" the glock */
HIF_FIRST = 7,
@@ -201,10 +218,12 @@ enum {
GLF_QUEUED = 12,
GLF_LRU = 13,
GLF_OBJECT = 14, /* Used only for tracing */
+ GLF_BLOCKING = 15,
};

struct gfs2_glock {
struct hlist_bl_node gl_list;
+ struct gfs2_sbd *gl_sbd;
unsigned long gl_flags; /* GLF_... */
struct lm_lockname gl_name;
atomic_t gl_ref;
@@ -224,16 +243,14 @@ struct gfs2_glock {
struct list_head gl_holders;

const struct gfs2_glock_operations *gl_ops;
- char gl_strname[GDLM_STRNAME_BYTES];
+ ktime_t gl_dstamp;
+ struct gfs2_lkstats gl_stats;
struct dlm_lksb gl_lksb;
char gl_lvb[32];
unsigned long gl_tchange;
void *gl_object;

struct list_head gl_lru;
-
- struct gfs2_sbd *gl_sbd;
-
struct list_head gl_ail_list;
atomic_t gl_ail_count;
atomic_t gl_revokes;
@@ -509,8 +526,13 @@ struct lm_lockstruct {
int ls_recover_jid_status;
};

+struct gfs2_pcpu_lkstats {
+ struct gfs2_lkstats lkstats[10];
+};
+
struct gfs2_sbd {
struct super_block *sd_vfs;
+ struct gfs2_pcpu_lkstats __percpu *sd_lkstats;
struct kobject sd_kobj;
unsigned long sd_flags; /* SDF_... */
struct gfs2_sb_host sd_sb;
@@ -673,8 +695,23 @@ struct gfs2_sbd {

unsigned long sd_last_warning;
struct dentry *debugfs_dir;*** /* debugfs directory */
- struct dentry *debugfs_dentry_glocks; /* for debugfs */
+ struct dentry *debugfs_dentry_glocks;
+ struct dentry *debugfs_dentry_glstats;
+ struct dentry *debugfs_dentry_sbstats;
};

+static inline void gfs2_glstats_inc(struct gfs2_glock *gl, int which)
+{
+ gl->gl_stats.stats[which]++;
+}
+
+static inline void gfs2_sbstats_inc(const struct gfs2_glock *gl, int which)
+{
+ const struct gfs2_sbd *sdp = gl->gl_sbd;
+ preempt_disable();
+ this_cpu_ptr(sdp->sd_lkstats)->lkstats[gl->gl_name.ln_type].stats[which]++;
+ preempt_enable();
+}
+
#endif /* __INCORE_DOT_H__ */

diff --git a/fs/gfs2/lock_dlm.c b/fs/gfs2/lock_dlm.c
index 98c80d8..1966e70 100644
--- a/fs/gfs2/lock_dlm.c
+++ b/fs/gfs2/lock_dlm.c
@@ -16,13 +16,105 @@
#include "incore.h"
#include "glock.h"
#include "util.h"
+#include "trace_gfs2.h"

+/**
+ * gfs2_update_stats - Update time based stats
+ * @mv: Pointer to mean/variance structure to update
+ * @sample: New data to include
+ *
+ * @delta is the difference between the current rtt sample and the
+ * running average srtt. We add 1/8 of that to the srtt in order to
+ * update the current srtt estimate. The varience estimate is a bit
+ * more complicated. We subtract the abs value of the @delta from
+ * the current variance estimate and add 1/4 of that to the running
+ * total.
+ *
+ * Note that the index points at the array entry containing the smoothed
+ * mean value, and the variance is always in the following entry
+ *
+ * Reference: TCP/IP Illustrated, vol 2, p. 831,832
+ * All times are in units of integer nanoseconds. Unlike the TCP/IP case,
+ * they are not scaled fixed point.
+ */
+
+static inline void gfs2_update_stats(struct gfs2_lkstats *s, unsigned index,
+ **** s64 sample)
+{
+ s64 delta = sample - s->stats[index];
+******* s->stats[index] += (delta >> 3);
+ index++;
+******* s->stats[index] += ((abs64(delta) - s->stats[index]) >> 2);
+}
+
+/**
+ * gfs2_update_reply_times - Update locking statistics
+ * @gl: The glock to update
+ *
+ * This assumes that gl->gl_dstamp has been set earlier.
+ *
+ * The rtt (lock round trip time) is an estimate of the time
+ * taken to perform a dlm lock request. We update it on each
+ * reply from the dlm.
+ *
+ * The blocking flag is set on the glock for all dlm requests
+ * which may potentially block due to lock requests from other nodes.
+ * DLM requests where the current lock state is exclusive, the
+ * requested state is null (or unlocked) or where the TRY or
+ * TRY_1CB flags are set are classified as non-blocking. All
+ * other DLM requests are counted as (potentially) blocking.
+ */
+static inline void gfs2_update_reply_times(struct gfs2_glock *gl)
+{
+ struct gfs2_pcpu_lkstats *lks;
+ const unsigned gltype = gl->gl_name.ln_type;
+ unsigned index = test_bit(GLF_BLOCKING, &gl->gl_flags) ?
+ GFS2_LKS_SRTTB : GFS2_LKS_SRTT;
+ s64 rtt;
+
+ preempt_disable();
+ rtt = ktime_to_ns(ktime_sub(ktime_get_real(), gl->gl_dstamp));
+ lks = this_cpu_ptr(gl->gl_sbd->sd_lkstats);
+ gfs2_update_stats(&gl->gl_stats, index, rtt); /* Local */
+ gfs2_update_stats(&lks->lkstats[gltype], index, rtt); /* Global */
+ preempt_enable();
+
+ trace_gfs2_glock_lock_time(gl, rtt);
+}
+
+/**
+ * gfs2_update_request_times - Update locking statistics
+ * @gl: The glock to update
+ *
+ * The irt (lock inter-request times) measures the average time
+ * between requests to the dlm. It is updated immediately before
+ * each dlm call.
+ */
+
+static inline void gfs2_update_request_times(struct gfs2_glock *gl)
+{
+******* struct gfs2_pcpu_lkstats *lks;
+******* const unsigned gltype = gl->gl_name.ln_type;
+ ktime_t dstamp;
+ s64 irt;
+
+ preempt_disable();
+ dstamp = gl->gl_dstamp;
+ gl->gl_dstamp = ktime_get_real();
+ irt = ktime_to_ns(ktime_sub(gl->gl_dstamp, dstamp));
+ lks = this_cpu_ptr(gl->gl_sbd->sd_lkstats);
+ gfs2_update_stats(&gl->gl_stats, GFS2_LKS_SIRT, irt); /* Local */
+ gfs2_update_stats(&lks->lkstats[gltype], GFS2_LKS_SIRT, irt); /* Global */
+ preempt_enable();
+}

static void gdlm_ast(void *arg)
{
struct gfs2_glock *gl = arg;
unsigned ret = gl->gl_state;

+ gfs2_update_reply_times(gl);
+
BUG_ON(gl->gl_lksb.sb_flags & DLM_SBF_DEMOTED);

if (gl->gl_lksb.sb_flags & DLM_SBF_VALNOTVALID)
@@ -108,7 +200,7 @@ static int make_mode(const unsigned int lmstate)
static u32 make_flags(const u32 lkid, const unsigned int gfs_flags,
***** const int req)
{
- u32 lkf = 0;
+ u32 lkf = DLM_LKF_VALBLK;

if (gfs_flags & LM_FLAG_TRY)
lkf |= DLM_LKF_NOQUEUE;
@@ -135,26 +227,43 @@ static u32 make_flags(const u32 lkid, const unsigned int gfs_flags,
if (lkid != 0)
lkf |= DLM_LKF_CONVERT;

- lkf |= DLM_LKF_VALBLK;
-
return lkf;
}

+static void gfs2_reverse_hex(char *c, u64 value)
+{
+ while (value) {
+ *c-- = hex_asc[value & 0x0f];
+ value >>= 4;
+ }
+}
+
static int gdlm_lock(struct gfs2_glock *gl, unsigned int req_state,
**** unsigned int flags)
{
struct lm_lockstruct *ls = &gl->gl_sbd->sd_lockstruct;
int req;
u32 lkf;
+ char strname[GDLM_STRNAME_BYTES] = "";

req = make_mode(req_state);
lkf = make_flags(gl->gl_lksb.sb_lkid, flags, req);
-
+ gfs2_glstats_inc(gl, GFS2_LKS_DCOUNT);
+ gfs2_sbstats_inc(gl, GFS2_LKS_DCOUNT);
+ if (gl->gl_lksb.sb_lkid) {
+ gfs2_update_request_times(gl);
+ } else {
+ memset(strname, ' ', GDLM_STRNAME_BYTES - 1);
+ strname[GDLM_STRNAME_BYTES - 1] = '';
+ gfs2_reverse_hex(strname + 7, gl->gl_name.ln_type);
+ gfs2_reverse_hex(strname + 23, gl->gl_name.ln_number);
+ gl->gl_dstamp = ktime_get_real();
+ }
/*
* Submit the actual lock request.
*/

- return dlm_lock(ls->ls_dlm, req, &gl->gl_lksb, lkf, gl->gl_strname,
+ return dlm_lock(ls->ls_dlm, req, &gl->gl_lksb, lkf, strname,
GDLM_STRNAME_BYTES - 1, 0, gdlm_ast, gl, gdlm_bast);
}

@@ -169,6 +278,10 @@ static void gdlm_put_lock(struct gfs2_glock *gl)
return;
}

+ clear_bit(GLF_BLOCKING, &gl->gl_flags);
+ gfs2_glstats_inc(gl, GFS2_LKS_DCOUNT);
+ gfs2_sbstats_inc(gl, GFS2_LKS_DCOUNT);
+ gfs2_update_request_times(gl);
error = dlm_unlock(ls->ls_dlm, gl->gl_lksb.sb_lkid, DLM_LKF_VALBLK,
** NULL, gl);
if (error) {
diff --git a/fs/gfs2/ops_fstype.c b/fs/gfs2/ops_fstype.c
index 4998194..c7c9c1b 100644
--- a/fs/gfs2/ops_fstype.c
+++ b/fs/gfs2/ops_fstype.c
@@ -67,6 +67,12 @@ static struct gfs2_sbd *init_sbd(struct super_block *sb)

sb->s_fs_info = sdp;
sdp->sd_vfs = sb;
+ sdp->sd_lkstats = alloc_percpu(struct gfs2_pcpu_lkstats);
+ if (!sdp->sd_lkstats) {
+ kfree(sdp);
+ return NULL;
+ }
+
set_bit(SDF_NOJOURNALID, &sdp->sd_flags);
gfs2_tune_init(&sdp->sd_tune);

@@ -1212,6 +1218,7 @@ fail_sys:
gfs2_sys_fs_del(sdp);
fail:
gfs2_delete_debugfs_file(sdp);
+ free_percpu(sdp->sd_lkstats);
kfree(sdp);
sb->s_fs_info = NULL;
return error;
@@ -1384,6 +1391,7 @@ static void gfs2_kill_sb(struct super_block *sb)
shrink_dcache_sb(sb);
kill_block_super(sb);
gfs2_delete_debugfs_file(sdp);
+ free_percpu(sdp->sd_lkstats);
kfree(sdp);
}

diff --git a/fs/gfs2/trace_gfs2.h b/fs/gfs2/trace_gfs2.h
index 5d07609..dfa89cd 100644
--- a/fs/gfs2/trace_gfs2.h
+++ b/fs/gfs2/trace_gfs2.h
@@ -11,6 +11,7 @@
#include <linux/dlmconstants.h>
#include <linux/gfs2_ondisk.h>
#include <linux/writeback.h>
+#include <linux/ktime.h>
#include "incore.h"
#include "glock.h"

@@ -43,7 +44,8 @@
{(1UL << GLF_FROZEN), "F" },
{(1UL << GLF_QUEUED), "q" },
{(1UL << GLF_LRU), "L" },
- {(1UL << GLF_OBJECT), "o" })
+ {(1UL << GLF_OBJECT), "o" },
+ {(1UL << GLF_BLOCKING), "b" })

#ifndef NUMPTY
#define NUMPTY
@@ -236,6 +238,62 @@ TRACE_EVENT(gfs2_glock_queue,
* glock_trace_name(__entry->state))
);

+/* DLM sends a reply to GFS2 */
+TRACE_EVENT(gfs2_glock_lock_time,
+
+ TP_PROTO(const struct gfs2_glock *gl, s64 tdiff),
+
+ TP_ARGS(gl, tdiff),
+
+ TP_STRUCT__entry(
+ __field( dev_t, dev )
+ __field( u64, glnum )
+ __field( u32, gltype )
+ __field( int, status )
+ __field( char, flags )
+ __field( s64, tdiff )
+ __field( s64, srtt )
+ __field( s64, srttvar )
+ __field( s64, srttb )
+ __field( s64, srttvarb )
+ __field( s64, sirt )
+ __field( s64, sirtvar )
+ __field( s64, dcount )
+ __field( s64, qcount )
+ ),
+
+ TP_fast_assign(
+ __entry->dev*********** = gl->gl_sbd->sd_vfs->s_dev;
+ __entry->glnum********* = gl->gl_name.ln_number;
+ __entry->gltype******** = gl->gl_name.ln_type;
+ __entry->status = gl->gl_lksb.sb_status;
+ __entry->flags = gl->gl_lksb.sb_flags;
+ __entry->tdiff = tdiff;
+ __entry->srtt = gl->gl_stats.stats[GFS2_LKS_SRTT];
+ __entry->srttvar = gl->gl_stats.stats[GFS2_LKS_SRTTVAR];
+ __entry->srttb = gl->gl_stats.stats[GFS2_LKS_SRTTB];
+ __entry->srttvarb = gl->gl_stats.stats[GFS2_LKS_SRTTVARB];
+ __entry->sirt = gl->gl_stats.stats[GFS2_LKS_SIRT];
+ __entry->sirtvar = gl->gl_stats.stats[GFS2_LKS_SIRTVAR];
+ __entry->dcount = gl->gl_stats.stats[GFS2_LKS_DCOUNT];
+ __entry->qcount = gl->gl_stats.stats[GFS2_LKS_QCOUNT];
+ ),
+
+ TP_printk("%u,%u glock %d:%lld status:%d flags:%02x tdiff:%lld srtt:%lld/%lld srttb:%lld/%lld sirt:%lld/%lld dcnt:%lld qcnt:%lld",
+ * MAJOR(__entry->dev), MINOR(__entry->dev), __entry->gltype,
+ * (unsigned long long)__entry->glnum,
+ * __entry->status, __entry->flags,
+ * (long long)__entry->tdiff,
+ * (long long)__entry->srtt,
+ * (long long)__entry->srttvar,
+ * (long long)__entry->srttb,
+ * (long long)__entry->srttvarb,
+ * (long long)__entry->sirt,
+ * (long long)__entry->sirtvar,
+ * (long long)__entry->dcount,
+ * (long long)__entry->qcount)
+);
+
/* Section 2 - Log/journal
* *
* * Objectives:
 
Old 11-04-2011, 03:31 PM
David Teigland
 
Default GFS2: glock statistics gathering (RFC)

On Fri, Nov 04, 2011 at 03:19:49PM +0000, Steven Whitehouse wrote:
> The three pairs of mean/variance measure the following
> things:
>
> 1. DLM lock time (non-blocking requests)

You don't need to track and save this value, because all results will be
one of three values which can gather once:

short: the dir node and master node are local: 0 network round trip
medium: one is local, one is remote: 1 network round trip
long: both are remote: 2 network round trips

Once you've measured values for short/med/long, then you're done.
The distribution will depend on the usage pattern.

> 2. DLM lock time (blocking requests)

I think what you want to quantify is how much contention a given lock is
under. A time measurement is probably not a great way to get that since
it's a combination of: the value above, how long gfs2 takes to release the
lock (itself a combination of things, including the the tunable itself),
and how many nodes are competing for the lock (depends on workload).

> 3. Inter-request time (again to the DLM)

Time between gfs2 requesting the same lock? That sounds like it might
work ok for measuring contention.

> 1. To be able to better set the glock "min hold time"

Less for a lock with high contention?

> 2. To spot performance issues more easily

Apart from contention, I'm not sure there are many perf issues that dlm
measurements would help with.

> 3. To improve the algorithm for selecting resource groups for
> allocation (to base it on lock wait time, rather than blindly
> using a "try lock")

Don't you grab an rg lock and keep it cached? How would lock times help?

Also, ocfs2 keeps quite a lot of locking stats you might look at.

Dave
 
Old 11-04-2011, 03:57 PM
Steven Whitehouse
 
Default GFS2: glock statistics gathering (RFC)

Hi,

On Fri, 2011-11-04 at 12:31 -0400, David Teigland wrote:
> On Fri, Nov 04, 2011 at 03:19:49PM +0000, Steven Whitehouse wrote:
> > The three pairs of mean/variance measure the following
> > things:
> >
> > 1. DLM lock time (non-blocking requests)
>
> You don't need to track and save this value, because all results will be
> one of three values which can gather once:
>
> short: the dir node and master node are local: 0 network round trip
> medium: one is local, one is remote: 1 network round trip
> long: both are remote: 2 network round trips
>
> Once you've measured values for short/med/long, then you're done.
> The distribution will depend on the usage pattern.
>
The reason for tracking this is to be able to compare it with the
blocking request value to (I hope) get a rough idea of the difference
between the two, which may indicate contention on the lock. So this
is really a "baseline" measurement.

Plus we do need to measure it, since it will vary according to a
number of things, such as what hardware is in use.

> > 2. DLM lock time (blocking requests)
>
> I think what you want to quantify is how much contention a given lock is
> under. A time measurement is probably not a great way to get that since
> it's a combination of: the value above, how long gfs2 takes to release the
> lock (itself a combination of things, including the the tunable itself),
> and how many nodes are competing for the lock (depends on workload).
>
> > 3. Inter-request time (again to the DLM)
>
> Time between gfs2 requesting the same lock? That sounds like it might
> work ok for measuring contention.
>
> > 1. To be able to better set the glock "min hold time"
>
> Less for a lock with high contention?
>
Generally we want more (i.e. to reduce the number of times the lock
gets passed around, and increase the time each node holds it) as
otherwise we make no progress, or very slow progress. This does penalise
interactive loads but increases throughput dramatically on batch loads.

Also, the point is that if we know the average time that it takes to get
a lock, and we know how many locks per second we are requesting, then we
can figure out the total percentage of time we are waiting for locks in
total. If there are N nodes in the cluster and the node is getting the
lock for less than 1/N of the total time, then it could increase its
minimum hold time.

That kind of thing is useful in order to ensure that we continue to make
progress under all circumstances.

> > 2. To spot performance issues more easily
>
> Apart from contention, I'm not sure there are many perf issues that dlm
> measurements would help with.
>
That is the #1 cause of reported performance issues, so top of our list
to work on. The goal is to make it easier to track down the source of
these kinds of problems.

> > 3. To improve the algorithm for selecting resource groups for
> > allocation (to base it on lock wait time, rather than blindly
> > using a "try lock")
>
> Don't you grab an rg lock and keep it cached? How would lock times help?
>
Its only cached while other nodes are not trying to use the same rgrp.
The same issue applies to them as to inode glocks in terms of
contention. When allocating we have a choice to use another rgrp if the
contention is causing a problem (hence the need for some info to base
that choice upon). Unfortunately with deallocation, there is no choice
and we have to use the specific rgrp(s) however contended they might be.

> Also, ocfs2 keeps quite a lot of locking stats you might look at.
>
> Dave
That might be useful depending on what they are gathering,

Steve.
 
Old 11-04-2011, 04:21 PM
David Teigland
 
Default GFS2: glock statistics gathering (RFC)

On Fri, Nov 04, 2011 at 04:57:31PM +0000, Steven Whitehouse wrote:
> Hi,
>
> On Fri, 2011-11-04 at 12:31 -0400, David Teigland wrote:
> > On Fri, Nov 04, 2011 at 03:19:49PM +0000, Steven Whitehouse wrote:
> > > The three pairs of mean/variance measure the following
> > > things:
> > >
> > > 1. DLM lock time (non-blocking requests)
> >
> > You don't need to track and save this value, because all results will be
> > one of three values which can gather once:
> >
> > short: the dir node and master node are local: 0 network round trip
> > medium: one is local, one is remote: 1 network round trip
> > long: both are remote: 2 network round trips
> >
> > Once you've measured values for short/med/long, then you're done.
> > The distribution will depend on the usage pattern.
> >
> The reason for tracking this is to be able to compare it with the
> blocking request value to (I hope) get a rough idea of the difference
> between the two, which may indicate contention on the lock. So this
> is really a "baseline" measurement.
>
> Plus we do need to measure it, since it will vary according to a
> number of things, such as what hardware is in use.

Right, but the baseline shouldn't change once you have it.

> > > 2. To spot performance issues more easily
> >
> > Apart from contention, I'm not sure there are many perf issues that dlm
> > measurements would help with.
> >
> That is the #1 cause of reported performance issues, so top of our list
> to work on. The goal is to make it easier to track down the source of
> these kinds of problems.

I still think that time averages and computations sounds like a difficult
and indirect way of measuring contention... but see how it works.

Dave
 
Old 11-07-2011, 11:06 AM
Steven Whitehouse
 
Default GFS2: glock statistics gathering (RFC)

Hi,

On Fri, 2011-11-04 at 13:21 -0400, David Teigland wrote:
> On Fri, Nov 04, 2011 at 04:57:31PM +0000, Steven Whitehouse wrote:
> > Hi,
> >
> > On Fri, 2011-11-04 at 12:31 -0400, David Teigland wrote:
> > > On Fri, Nov 04, 2011 at 03:19:49PM +0000, Steven Whitehouse wrote:
> > > > The three pairs of mean/variance measure the following
> > > > things:
> > > >
> > > > 1. DLM lock time (non-blocking requests)
> > >
> > > You don't need to track and save this value, because all results will be
> > > one of three values which can gather once:
> > >
> > > short: the dir node and master node are local: 0 network round trip
> > > medium: one is local, one is remote: 1 network round trip
> > > long: both are remote: 2 network round trips
> > >
> > > Once you've measured values for short/med/long, then you're done.
> > > The distribution will depend on the usage pattern.
> > >
> > The reason for tracking this is to be able to compare it with the
> > blocking request value to (I hope) get a rough idea of the difference
> > between the two, which may indicate contention on the lock. So this
> > is really a "baseline" measurement.
> >
> > Plus we do need to measure it, since it will vary according to a
> > number of things, such as what hardware is in use.
>
> Right, but the baseline shouldn't change once you have it.
>
Well, I'm not sure I agree with that. The conditions on the network
might change, and the conditions on a (remote) lock master may change.
We have no way within GFS2 to measure such things directly, so we need a
proxy for them.

> > > > 2. To spot performance issues more easily
> > >
> > > Apart from contention, I'm not sure there are many perf issues that dlm
> > > measurements would help with.
> > >
> > That is the #1 cause of reported performance issues, so top of our list
> > to work on. The goal is to make it easier to track down the source of
> > these kinds of problems.
>
> I still think that time averages and computations sounds like a difficult
> and indirect way of measuring contention... but see how it works.
>
> Dave
>
It is, but what else do we have? There is no way to communicate between
GFS2 nodes except via the DLM. Contention is really a state of all the
nodes collectively, rather than any one node, which makes it tricky to
measure. We could try something using the LVBs, but that is rather
tricky if the nodes are using (largely) read locks and thus we can't
write to the LVB from those nodes.

For a long time we've had the "min hold time" concept which was
introduced to ensure that we continue to make progress, even when
contention occurs. That has been based off a rather rough time since
last state change estimate, with an adjustment for a corner case which
was discovered recently. I'd like to put that calculation on a more
scientific footing, and this seems to be the easiest way to do that.

I've had a look at what OCFS2 collects wrt locking stats. They have a
cumulative total of wait time and a counter for the number of waits
which have occurred. That will give a good collective estimate of time
spent waiting, but it is not suitable for changing the dynamic behaviour
of the filesystem as the time it takes to react to a change in the
system characteristics will vary with time. In other words when just
mounted, the statistic will be very sensitive to new data, but it will
become less so as time goes on.

The exponential averages which I'm proposing in the patch are designed
so that once they have gained enough information (say 12 samples or so)
to reach a steady state, they will change in response to new data in the
same way, however many lock requests have been made.

This is also why such things are used in the networking code. We don't
want the response to change according to how much data has passed over
the socket.

In addition, the patch also keeps track of the variance, so that we know
how accurate the mean is. Something that is vitally important to avoid
drawing incorrect conclusions from the data.

What I am concerned about is whether we could measure other quantities
which would give us a better proxy for whats happening in the cluster as
a whole, and at what point we start running the risk of the stats
slowing things down more than the information they return will speed
things up.

As a general rule, I don't want to collect stats just for the sake of
it. We can use tracepoints to collect data for performance analysis
later, the aim here is to collect data to directly influence the future
operation of the filesystem in an automatic manner, and to be able to
monitor that so we can check that it is really functioning correctly.

I've tried to ensure they are collected in the most efficient way
possible (no divisions or multiplications, aside from bit shifts). All
global stats in per-cpu structures.

Also, another difference from OCFS2, is that this patch will collect
global stats, so we have a good starting point to initialise the
per-glock stats from. Newly-created glocks should thus start with a good
estimate as to their correct stats values, once the fs has been mounted
for a little while,

Steve.
 

Thread Tools




All times are GMT. The time now is 02:47 AM.

VBulletin, Copyright ©2000 - 2014, Jelsoft Enterprises Ltd.
Content Relevant URLs by vBSEO ©2007, Crawlability, Inc.
Copyright 2007 - 2008, www.linux-archive.org