All of lore.kernel.org
 help / color / mirror / Atom feed
* [PATCH v8 0/5] ceph: add perf metrics support
@ 2020-02-21  7:05 xiubli
  2020-02-21  7:05 ` [PATCH v8 1/5] ceph: add global dentry lease metric support xiubli
                   ` (4 more replies)
  0 siblings, 5 replies; 16+ messages in thread
From: xiubli @ 2020-02-21  7:05 UTC (permalink / raw)
  To: jlayton, idryomov; +Cc: sage, zyan, pdonnell, ceph-devel, Xiubo Li

From: Xiubo Li <xiubli@redhat.com>

Changed in V8:
- address the comments for cap patch from Jeff.

We can get the metrics from the debugfs:

$ cat /sys/kernel/debug/ceph/0c93a60d-5645-4c46-8568-4c8f63db4c7f.client4267/metrics 
item          total       sum_lat(us)     avg_lat(us)
-----------------------------------------------------
read          13          417000          32076
write         42          131205000       3123928
metadata      104         493000          4740

item          total           miss            hit
-------------------------------------------------
d_lease       204             0               918
caps          204             213             368218


Xiubo Li (5):
  ceph: add global dentry lease metric support
  ceph: add caps perf metric for each session
  ceph: add global read latency metric support
  ceph: add global write latency metric support
  ceph: add global metadata perf metric support

 fs/ceph/acl.c                   |   2 +-
 fs/ceph/addr.c                  |  13 ++++
 fs/ceph/caps.c                  |  19 ++++++
 fs/ceph/debugfs.c               |  71 ++++++++++++++++++++--
 fs/ceph/dir.c                   |  21 +++++--
 fs/ceph/file.c                  |  20 +++++++
 fs/ceph/inode.c                 |   4 +-
 fs/ceph/mds_client.c            | 103 +++++++++++++++++++++++++++++++-
 fs/ceph/mds_client.h            |   4 ++
 fs/ceph/metric.h                |  81 +++++++++++++++++++++++++
 fs/ceph/super.h                 |   9 ++-
 fs/ceph/xattr.c                 |   4 +-
 include/linux/ceph/osd_client.h |   1 +
 net/ceph/osd_client.c           |   2 +
 14 files changed, 336 insertions(+), 18 deletions(-)
 create mode 100644 fs/ceph/metric.h

-- 
2.21.0

^ permalink raw reply	[flat|nested] 16+ messages in thread

* [PATCH v8 1/5] ceph: add global dentry lease metric support
  2020-02-21  7:05 [PATCH v8 0/5] ceph: add perf metrics support xiubli
@ 2020-02-21  7:05 ` xiubli
  2020-02-21  7:05 ` [PATCH v8 2/5] ceph: add caps perf metric for each session xiubli
                   ` (3 subsequent siblings)
  4 siblings, 0 replies; 16+ messages in thread
From: xiubli @ 2020-02-21  7:05 UTC (permalink / raw)
  To: jlayton, idryomov; +Cc: sage, zyan, pdonnell, ceph-devel, Xiubo Li

From: Xiubo Li <xiubli@redhat.com>

For the dentry lease we will only count the hit/miss info triggered
from the vfs calls, for the cases like request reply handling and
perodically ceph_trim_dentries() we will ignore them.

Currently only the debugfs is support:

The output will be:

item          total           miss            hit
-------------------------------------------------
d_lease       11              7               141

URL: https://tracker.ceph.com/issues/43215
Signed-off-by: Xiubo Li <xiubli@redhat.com>
---
 fs/ceph/debugfs.c    | 32 ++++++++++++++++++++++++++++----
 fs/ceph/dir.c        | 16 ++++++++++++++--
 fs/ceph/mds_client.c | 37 +++++++++++++++++++++++++++++++++++--
 fs/ceph/mds_client.h |  4 ++++
 fs/ceph/metric.h     | 11 +++++++++++
 fs/ceph/super.h      |  1 +
 6 files changed, 93 insertions(+), 8 deletions(-)
 create mode 100644 fs/ceph/metric.h

diff --git a/fs/ceph/debugfs.c b/fs/ceph/debugfs.c
index 481ac97b4d25..15975ba95d9a 100644
--- a/fs/ceph/debugfs.c
+++ b/fs/ceph/debugfs.c
@@ -124,6 +124,22 @@ static int mdsc_show(struct seq_file *s, void *p)
 	return 0;
 }
 
+static int metric_show(struct seq_file *s, void *p)
+{
+	struct ceph_fs_client *fsc = s->private;
+	struct ceph_mds_client *mdsc = fsc->mdsc;
+
+	seq_printf(s, "item          total           miss            hit\n");
+	seq_printf(s, "-------------------------------------------------\n");
+
+	seq_printf(s, "%-14s%-16lld%-16lld%lld\n", "d_lease",
+		   atomic64_read(&mdsc->metric.total_dentries),
+		   percpu_counter_sum(&mdsc->metric.d_lease_mis),
+		   percpu_counter_sum(&mdsc->metric.d_lease_hit));
+
+	return 0;
+}
+
 static int caps_show_cb(struct inode *inode, struct ceph_cap *cap, void *p)
 {
 	struct seq_file *s = p;
@@ -222,6 +238,7 @@ DEFINE_SHOW_ATTRIBUTE(mdsmap);
 DEFINE_SHOW_ATTRIBUTE(mdsc);
 DEFINE_SHOW_ATTRIBUTE(caps);
 DEFINE_SHOW_ATTRIBUTE(mds_sessions);
+DEFINE_SHOW_ATTRIBUTE(metric);
 
 
 /*
@@ -255,6 +272,7 @@ void ceph_fs_debugfs_cleanup(struct ceph_fs_client *fsc)
 	debugfs_remove(fsc->debugfs_mdsmap);
 	debugfs_remove(fsc->debugfs_mds_sessions);
 	debugfs_remove(fsc->debugfs_caps);
+	debugfs_remove(fsc->debugfs_metric);
 	debugfs_remove(fsc->debugfs_mdsc);
 }
 
@@ -295,11 +313,17 @@ void ceph_fs_debugfs_init(struct ceph_fs_client *fsc)
 						fsc,
 						&mdsc_fops);
 
+	fsc->debugfs_metric = debugfs_create_file("metrics",
+						  0400,
+						  fsc->client->debugfs_dir,
+						  fsc,
+						  &metric_fops);
+
 	fsc->debugfs_caps = debugfs_create_file("caps",
-						   0400,
-						   fsc->client->debugfs_dir,
-						   fsc,
-						   &caps_fops);
+						0400,
+						fsc->client->debugfs_dir,
+						fsc,
+						&caps_fops);
 }
 
 
diff --git a/fs/ceph/dir.c b/fs/ceph/dir.c
index d0cd0aba5843..ff1714fe03aa 100644
--- a/fs/ceph/dir.c
+++ b/fs/ceph/dir.c
@@ -38,6 +38,8 @@ static int __dir_lease_try_check(const struct dentry *dentry);
 static int ceph_d_init(struct dentry *dentry)
 {
 	struct ceph_dentry_info *di;
+	struct ceph_fs_client *fsc = ceph_sb_to_client(dentry->d_sb);
+	struct ceph_mds_client *mdsc = fsc->mdsc;
 
 	di = kmem_cache_zalloc(ceph_dentry_cachep, GFP_KERNEL);
 	if (!di)
@@ -48,6 +50,9 @@ static int ceph_d_init(struct dentry *dentry)
 	di->time = jiffies;
 	dentry->d_fsdata = di;
 	INIT_LIST_HEAD(&di->lease_list);
+
+	atomic64_inc(&mdsc->metric.total_dentries);
+
 	return 0;
 }
 
@@ -1551,6 +1556,7 @@ static int dir_lease_is_valid(struct inode *dir, struct dentry *dentry)
  */
 static int ceph_d_revalidate(struct dentry *dentry, unsigned int flags)
 {
+	struct ceph_mds_client *mdsc;
 	int valid = 0;
 	struct dentry *parent;
 	struct inode *dir, *inode;
@@ -1589,9 +1595,8 @@ static int ceph_d_revalidate(struct dentry *dentry, unsigned int flags)
 		}
 	}
 
+	mdsc = ceph_sb_to_client(dir->i_sb)->mdsc;
 	if (!valid) {
-		struct ceph_mds_client *mdsc =
-			ceph_sb_to_client(dir->i_sb)->mdsc;
 		struct ceph_mds_request *req;
 		int op, err;
 		u32 mask;
@@ -1599,6 +1604,8 @@ static int ceph_d_revalidate(struct dentry *dentry, unsigned int flags)
 		if (flags & LOOKUP_RCU)
 			return -ECHILD;
 
+		percpu_counter_inc(&mdsc->metric.d_lease_mis);
+
 		op = ceph_snap(dir) == CEPH_SNAPDIR ?
 			CEPH_MDS_OP_LOOKUPSNAP : CEPH_MDS_OP_LOOKUP;
 		req = ceph_mdsc_create_request(mdsc, op, USE_ANY_MDS);
@@ -1630,6 +1637,8 @@ static int ceph_d_revalidate(struct dentry *dentry, unsigned int flags)
 			dout("d_revalidate %p lookup result=%d\n",
 			     dentry, err);
 		}
+	} else {
+		percpu_counter_inc(&mdsc->metric.d_lease_hit);
 	}
 
 	dout("d_revalidate %p %s\n", dentry, valid ? "valid" : "invalid");
@@ -1672,9 +1681,12 @@ static int ceph_d_delete(const struct dentry *dentry)
 static void ceph_d_release(struct dentry *dentry)
 {
 	struct ceph_dentry_info *di = ceph_dentry(dentry);
+	struct ceph_fs_client *fsc = ceph_sb_to_client(dentry->d_sb);
 
 	dout("d_release %p\n", dentry);
 
+	atomic64_dec(&fsc->mdsc->metric.total_dentries);
+
 	spin_lock(&dentry->d_lock);
 	__dentry_lease_unlist(di);
 	dentry->d_fsdata = NULL;
diff --git a/fs/ceph/mds_client.c b/fs/ceph/mds_client.c
index 2980e57ca7b9..82060afd5dca 100644
--- a/fs/ceph/mds_client.c
+++ b/fs/ceph/mds_client.c
@@ -4156,10 +4156,31 @@ static void delayed_work(struct work_struct *work)
 	schedule_delayed(mdsc);
 }
 
+static int ceph_mdsc_metric_init(struct ceph_client_metric *metric)
+{
+	int ret;
+
+	if (!metric)
+		return -EINVAL;
+
+	atomic64_set(&metric->total_dentries, 0);
+	ret = percpu_counter_init(&metric->d_lease_hit, 0, GFP_KERNEL);
+	if (ret)
+		return ret;
+	ret = percpu_counter_init(&metric->d_lease_mis, 0, GFP_KERNEL);
+	if (ret) {
+		percpu_counter_destroy(&metric->d_lease_hit);
+		return ret;
+	}
+
+	return 0;
+}
+
 int ceph_mdsc_init(struct ceph_fs_client *fsc)
 
 {
 	struct ceph_mds_client *mdsc;
+	int err;
 
 	mdsc = kzalloc(sizeof(struct ceph_mds_client), GFP_NOFS);
 	if (!mdsc)
@@ -4168,8 +4189,8 @@ int ceph_mdsc_init(struct ceph_fs_client *fsc)
 	mutex_init(&mdsc->mutex);
 	mdsc->mdsmap = kzalloc(sizeof(*mdsc->mdsmap), GFP_NOFS);
 	if (!mdsc->mdsmap) {
-		kfree(mdsc);
-		return -ENOMEM;
+		err = -ENOMEM;
+		goto err_mdsc;
 	}
 
 	fsc->mdsc = mdsc;
@@ -4208,6 +4229,9 @@ int ceph_mdsc_init(struct ceph_fs_client *fsc)
 	init_waitqueue_head(&mdsc->cap_flushing_wq);
 	INIT_WORK(&mdsc->cap_reclaim_work, ceph_cap_reclaim_work);
 	atomic_set(&mdsc->cap_reclaim_pending, 0);
+	err = ceph_mdsc_metric_init(&mdsc->metric);
+	if (err)
+		goto err_mdsmap;
 
 	spin_lock_init(&mdsc->dentry_list_lock);
 	INIT_LIST_HEAD(&mdsc->dentry_leases);
@@ -4226,6 +4250,12 @@ int ceph_mdsc_init(struct ceph_fs_client *fsc)
 	strscpy(mdsc->nodename, utsname()->nodename,
 		sizeof(mdsc->nodename));
 	return 0;
+
+err_mdsmap:
+	kfree(mdsc->mdsmap);
+err_mdsc:
+	kfree(mdsc);
+	return err;
 }
 
 /*
@@ -4483,6 +4513,9 @@ void ceph_mdsc_destroy(struct ceph_fs_client *fsc)
 
 	ceph_mdsc_stop(mdsc);
 
+	percpu_counter_destroy(&mdsc->metric.d_lease_mis);
+	percpu_counter_destroy(&mdsc->metric.d_lease_hit);
+
 	fsc->mdsc = NULL;
 	kfree(mdsc);
 	dout("mdsc_destroy %p done\n", mdsc);
diff --git a/fs/ceph/mds_client.h b/fs/ceph/mds_client.h
index 27a7446e10d3..674fc7725913 100644
--- a/fs/ceph/mds_client.h
+++ b/fs/ceph/mds_client.h
@@ -16,6 +16,8 @@
 #include <linux/ceph/mdsmap.h>
 #include <linux/ceph/auth.h>
 
+#include "metric.h"
+
 /* The first 8 bits are reserved for old ceph releases */
 enum ceph_feature_type {
 	CEPHFS_FEATURE_MIMIC = 8,
@@ -446,6 +448,8 @@ struct ceph_mds_client {
 	struct list_head  dentry_leases;     /* fifo list */
 	struct list_head  dentry_dir_leases; /* lru list */
 
+	struct ceph_client_metric metric;
+
 	spinlock_t		snapid_map_lock;
 	struct rb_root		snapid_map_tree;
 	struct list_head	snapid_map_lru;
diff --git a/fs/ceph/metric.h b/fs/ceph/metric.h
new file mode 100644
index 000000000000..998fe2a643cf
--- /dev/null
+++ b/fs/ceph/metric.h
@@ -0,0 +1,11 @@
+/* SPDX-License-Identifier: GPL-2.0 */
+#ifndef _FS_CEPH_MDS_METRIC_H
+#define _FS_CEPH_MDS_METRIC_H
+
+/* This is the global metrics */
+struct ceph_client_metric {
+	atomic64_t            total_dentries;
+	struct percpu_counter d_lease_hit;
+	struct percpu_counter d_lease_mis;
+};
+#endif /* _FS_CEPH_MDS_METRIC_H */
diff --git a/fs/ceph/super.h b/fs/ceph/super.h
index 37dc1ac8f6c3..ebcf7612eac9 100644
--- a/fs/ceph/super.h
+++ b/fs/ceph/super.h
@@ -125,6 +125,7 @@ struct ceph_fs_client {
 	struct dentry *debugfs_congestion_kb;
 	struct dentry *debugfs_bdi;
 	struct dentry *debugfs_mdsc, *debugfs_mdsmap;
+	struct dentry *debugfs_metric;
 	struct dentry *debugfs_mds_sessions;
 #endif
 
-- 
2.21.0

^ permalink raw reply related	[flat|nested] 16+ messages in thread

* [PATCH v8 2/5] ceph: add caps perf metric for each session
  2020-02-21  7:05 [PATCH v8 0/5] ceph: add perf metrics support xiubli
  2020-02-21  7:05 ` [PATCH v8 1/5] ceph: add global dentry lease metric support xiubli
@ 2020-02-21  7:05 ` xiubli
  2020-02-21 12:00   ` Jeff Layton
  2020-02-21  7:05 ` [PATCH v8 3/5] ceph: add global read latency metric support xiubli
                   ` (2 subsequent siblings)
  4 siblings, 1 reply; 16+ messages in thread
From: xiubli @ 2020-02-21  7:05 UTC (permalink / raw)
  To: jlayton, idryomov; +Cc: sage, zyan, pdonnell, ceph-devel, Xiubo Li

From: Xiubo Li <xiubli@redhat.com>

This will fulfill the cap hit/mis metric stuff per-superblock,
it will count the hit/mis counters based each inode, and if one
inode's 'issued & ~revoking == mask' will mean a hit, or a miss.

item          total           miss            hit
-------------------------------------------------
caps          295             107             4119

URL: https://tracker.ceph.com/issues/43215
Signed-off-by: Xiubo Li <xiubli@redhat.com>
---
 fs/ceph/acl.c        |  2 +-
 fs/ceph/caps.c       | 19 +++++++++++++++++++
 fs/ceph/debugfs.c    | 16 ++++++++++++++++
 fs/ceph/dir.c        |  5 +++--
 fs/ceph/inode.c      |  4 ++--
 fs/ceph/mds_client.c | 26 ++++++++++++++++++++++----
 fs/ceph/metric.h     | 19 +++++++++++++++++++
 fs/ceph/super.h      |  8 +++++---
 fs/ceph/xattr.c      |  4 ++--
 9 files changed, 89 insertions(+), 14 deletions(-)

diff --git a/fs/ceph/acl.c b/fs/ceph/acl.c
index 26be6520d3fb..e0465741c591 100644
--- a/fs/ceph/acl.c
+++ b/fs/ceph/acl.c
@@ -22,7 +22,7 @@ static inline void ceph_set_cached_acl(struct inode *inode,
 	struct ceph_inode_info *ci = ceph_inode(inode);
 
 	spin_lock(&ci->i_ceph_lock);
-	if (__ceph_caps_issued_mask(ci, CEPH_CAP_XATTR_SHARED, 0))
+	if (__ceph_caps_issued_mask_metric(ci, CEPH_CAP_XATTR_SHARED, 0))
 		set_cached_acl(inode, type, acl);
 	else
 		forget_cached_acl(inode, type);
diff --git a/fs/ceph/caps.c b/fs/ceph/caps.c
index d05717397c2a..fe2ae41f2ec1 100644
--- a/fs/ceph/caps.c
+++ b/fs/ceph/caps.c
@@ -920,6 +920,20 @@ int __ceph_caps_issued_mask(struct ceph_inode_info *ci, int mask, int touch)
 	return 0;
 }
 
+int __ceph_caps_issued_mask_metric(struct ceph_inode_info *ci, int mask,
+				   int touch)
+{
+	struct ceph_fs_client *fsc = ceph_sb_to_client(ci->vfs_inode.i_sb);
+	int r;
+
+	r = __ceph_caps_issued_mask(ci, mask, touch);
+	if (r)
+		ceph_update_cap_hit(&fsc->mdsc->metric);
+	else
+		ceph_update_cap_mis(&fsc->mdsc->metric);
+	return r;
+}
+
 /*
  * Return true if mask caps are currently being revoked by an MDS.
  */
@@ -2700,6 +2714,11 @@ static int try_get_cap_refs(struct inode *inode, int need, int want,
 	if (snap_rwsem_locked)
 		up_read(&mdsc->snap_rwsem);
 
+	if (!ret)
+		ceph_update_cap_mis(&mdsc->metric);
+	else if (ret == 1)
+		ceph_update_cap_hit(&mdsc->metric);
+
 	dout("get_cap_refs %p ret %d got %s\n", inode,
 	     ret, ceph_cap_string(*got));
 	return ret;
diff --git a/fs/ceph/debugfs.c b/fs/ceph/debugfs.c
index 15975ba95d9a..c83e52bd9961 100644
--- a/fs/ceph/debugfs.c
+++ b/fs/ceph/debugfs.c
@@ -128,6 +128,7 @@ static int metric_show(struct seq_file *s, void *p)
 {
 	struct ceph_fs_client *fsc = s->private;
 	struct ceph_mds_client *mdsc = fsc->mdsc;
+	int i, nr_caps = 0;
 
 	seq_printf(s, "item          total           miss            hit\n");
 	seq_printf(s, "-------------------------------------------------\n");
@@ -137,6 +138,21 @@ static int metric_show(struct seq_file *s, void *p)
 		   percpu_counter_sum(&mdsc->metric.d_lease_mis),
 		   percpu_counter_sum(&mdsc->metric.d_lease_hit));
 
+	mutex_lock(&mdsc->mutex);
+	for (i = 0; i < mdsc->max_sessions; i++) {
+		struct ceph_mds_session *s;
+
+		s = __ceph_lookup_mds_session(mdsc, i);
+		if (!s)
+			continue;
+		nr_caps += s->s_nr_caps;
+		ceph_put_mds_session(s);
+	}
+	mutex_unlock(&mdsc->mutex);
+	seq_printf(s, "%-14s%-16d%-16lld%lld\n", "caps", nr_caps,
+		   percpu_counter_sum(&mdsc->metric.i_caps_mis),
+		   percpu_counter_sum(&mdsc->metric.i_caps_hit));
+
 	return 0;
 }
 
diff --git a/fs/ceph/dir.c b/fs/ceph/dir.c
index ff1714fe03aa..227949c3deb8 100644
--- a/fs/ceph/dir.c
+++ b/fs/ceph/dir.c
@@ -346,8 +346,9 @@ static int ceph_readdir(struct file *file, struct dir_context *ctx)
 	    !ceph_test_mount_opt(fsc, NOASYNCREADDIR) &&
 	    ceph_snap(inode) != CEPH_SNAPDIR &&
 	    __ceph_dir_is_complete_ordered(ci) &&
-	    __ceph_caps_issued_mask(ci, CEPH_CAP_FILE_SHARED, 1)) {
+	    __ceph_caps_issued_mask_metric(ci, CEPH_CAP_FILE_SHARED, 1)) {
 		int shared_gen = atomic_read(&ci->i_shared_gen);
+
 		spin_unlock(&ci->i_ceph_lock);
 		err = __dcache_readdir(file, ctx, shared_gen);
 		if (err != -EAGAIN)
@@ -764,7 +765,7 @@ static struct dentry *ceph_lookup(struct inode *dir, struct dentry *dentry,
 		    !is_root_ceph_dentry(dir, dentry) &&
 		    ceph_test_mount_opt(fsc, DCACHE) &&
 		    __ceph_dir_is_complete(ci) &&
-		    (__ceph_caps_issued_mask(ci, CEPH_CAP_FILE_SHARED, 1))) {
+		    __ceph_caps_issued_mask_metric(ci, CEPH_CAP_FILE_SHARED, 1)) {
 			spin_unlock(&ci->i_ceph_lock);
 			dout(" dir %p complete, -ENOENT\n", dir);
 			d_add(dentry, NULL);
diff --git a/fs/ceph/inode.c b/fs/ceph/inode.c
index 094b8fc37787..8dc10196e3a1 100644
--- a/fs/ceph/inode.c
+++ b/fs/ceph/inode.c
@@ -2273,8 +2273,8 @@ int __ceph_do_getattr(struct inode *inode, struct page *locked_page,
 
 	dout("do_getattr inode %p mask %s mode 0%o\n",
 	     inode, ceph_cap_string(mask), inode->i_mode);
-	if (!force && ceph_caps_issued_mask(ceph_inode(inode), mask, 1))
-		return 0;
+	if (!force && ceph_caps_issued_mask_metric(ceph_inode(inode), mask, 1))
+			return 0;
 
 	mode = (mask & CEPH_STAT_RSTAT) ? USE_AUTH_MDS : USE_ANY_MDS;
 	req = ceph_mdsc_create_request(mdsc, CEPH_MDS_OP_GETATTR, mode);
diff --git a/fs/ceph/mds_client.c b/fs/ceph/mds_client.c
index 82060afd5dca..cd31bcb4e563 100644
--- a/fs/ceph/mds_client.c
+++ b/fs/ceph/mds_client.c
@@ -4167,13 +4167,29 @@ static int ceph_mdsc_metric_init(struct ceph_client_metric *metric)
 	ret = percpu_counter_init(&metric->d_lease_hit, 0, GFP_KERNEL);
 	if (ret)
 		return ret;
+
 	ret = percpu_counter_init(&metric->d_lease_mis, 0, GFP_KERNEL);
-	if (ret) {
-		percpu_counter_destroy(&metric->d_lease_hit);
-		return ret;
-	}
+	if (ret)
+		goto err_d_lease_mis;
+
+	ret = percpu_counter_init(&metric->i_caps_hit, 0, GFP_KERNEL);
+	if (ret)
+		goto err_i_caps_hit;
+
+	ret = percpu_counter_init(&metric->i_caps_mis, 0, GFP_KERNEL);
+	if (ret)
+		goto err_i_caps_mis;
 
 	return 0;
+
+err_i_caps_mis:
+	percpu_counter_destroy(&metric->i_caps_hit);
+err_i_caps_hit:
+	percpu_counter_destroy(&metric->d_lease_mis);
+err_d_lease_mis:
+	percpu_counter_destroy(&metric->d_lease_hit);
+
+	return ret;
 }
 
 int ceph_mdsc_init(struct ceph_fs_client *fsc)
@@ -4513,6 +4529,8 @@ void ceph_mdsc_destroy(struct ceph_fs_client *fsc)
 
 	ceph_mdsc_stop(mdsc);
 
+	percpu_counter_destroy(&mdsc->metric.i_caps_mis);
+	percpu_counter_destroy(&mdsc->metric.i_caps_hit);
 	percpu_counter_destroy(&mdsc->metric.d_lease_mis);
 	percpu_counter_destroy(&mdsc->metric.d_lease_hit);
 
diff --git a/fs/ceph/metric.h b/fs/ceph/metric.h
index 998fe2a643cf..40eb58f9f43e 100644
--- a/fs/ceph/metric.h
+++ b/fs/ceph/metric.h
@@ -7,5 +7,24 @@ struct ceph_client_metric {
 	atomic64_t            total_dentries;
 	struct percpu_counter d_lease_hit;
 	struct percpu_counter d_lease_mis;
+
+	struct percpu_counter i_caps_hit;
+	struct percpu_counter i_caps_mis;
 };
+
+static inline void ceph_update_cap_hit(struct ceph_client_metric *m)
+{
+	if (!m)
+		return;
+
+	percpu_counter_inc(&m->i_caps_hit);
+}
+
+static inline void ceph_update_cap_mis(struct ceph_client_metric *m)
+{
+	if (!m)
+		return;
+
+	percpu_counter_inc(&m->i_caps_mis);
+}
 #endif /* _FS_CEPH_MDS_METRIC_H */
diff --git a/fs/ceph/super.h b/fs/ceph/super.h
index ebcf7612eac9..4b269dc845bb 100644
--- a/fs/ceph/super.h
+++ b/fs/ceph/super.h
@@ -639,6 +639,8 @@ static inline bool __ceph_is_any_real_caps(struct ceph_inode_info *ci)
 
 extern int __ceph_caps_issued(struct ceph_inode_info *ci, int *implemented);
 extern int __ceph_caps_issued_mask(struct ceph_inode_info *ci, int mask, int t);
+extern int __ceph_caps_issued_mask_metric(struct ceph_inode_info *ci, int mask,
+					  int t);
 extern int __ceph_caps_issued_other(struct ceph_inode_info *ci,
 				    struct ceph_cap *cap);
 
@@ -651,12 +653,12 @@ static inline int ceph_caps_issued(struct ceph_inode_info *ci)
 	return issued;
 }
 
-static inline int ceph_caps_issued_mask(struct ceph_inode_info *ci, int mask,
-					int touch)
+static inline int ceph_caps_issued_mask_metric(struct ceph_inode_info *ci,
+					       int mask, int touch)
 {
 	int r;
 	spin_lock(&ci->i_ceph_lock);
-	r = __ceph_caps_issued_mask(ci, mask, touch);
+	r = __ceph_caps_issued_mask_metric(ci, mask, touch);
 	spin_unlock(&ci->i_ceph_lock);
 	return r;
 }
diff --git a/fs/ceph/xattr.c b/fs/ceph/xattr.c
index 7b8a070a782d..71ee34d160c3 100644
--- a/fs/ceph/xattr.c
+++ b/fs/ceph/xattr.c
@@ -856,7 +856,7 @@ ssize_t __ceph_getxattr(struct inode *inode, const char *name, void *value,
 
 	if (ci->i_xattrs.version == 0 ||
 	    !((req_mask & CEPH_CAP_XATTR_SHARED) ||
-	      __ceph_caps_issued_mask(ci, CEPH_CAP_XATTR_SHARED, 1))) {
+	      __ceph_caps_issued_mask_metric(ci, CEPH_CAP_XATTR_SHARED, 1))) {
 		spin_unlock(&ci->i_ceph_lock);
 
 		/* security module gets xattr while filling trace */
@@ -914,7 +914,7 @@ ssize_t ceph_listxattr(struct dentry *dentry, char *names, size_t size)
 	     ci->i_xattrs.version, ci->i_xattrs.index_version);
 
 	if (ci->i_xattrs.version == 0 ||
-	    !__ceph_caps_issued_mask(ci, CEPH_CAP_XATTR_SHARED, 1)) {
+	    !__ceph_caps_issued_mask_metric(ci, CEPH_CAP_XATTR_SHARED, 1)) {
 		spin_unlock(&ci->i_ceph_lock);
 		err = ceph_do_getattr(inode, CEPH_STAT_CAP_XATTR, true);
 		if (err)
-- 
2.21.0

^ permalink raw reply related	[flat|nested] 16+ messages in thread

* [PATCH v8 3/5] ceph: add global read latency metric support
  2020-02-21  7:05 [PATCH v8 0/5] ceph: add perf metrics support xiubli
  2020-02-21  7:05 ` [PATCH v8 1/5] ceph: add global dentry lease metric support xiubli
  2020-02-21  7:05 ` [PATCH v8 2/5] ceph: add caps perf metric for each session xiubli
@ 2020-02-21  7:05 ` xiubli
  2020-02-21  7:05 ` [PATCH v8 4/5] ceph: add global write " xiubli
  2020-02-21  7:05 ` [PATCH v8 5/5] ceph: add global metadata perf " xiubli
  4 siblings, 0 replies; 16+ messages in thread
From: xiubli @ 2020-02-21  7:05 UTC (permalink / raw)
  To: jlayton, idryomov; +Cc: sage, zyan, pdonnell, ceph-devel, Xiubo Li

From: Xiubo Li <xiubli@redhat.com>

It will calculate the latency for the read osd requests, which only
include the time cousumed by network and the ceph osd.

item          total       sum_lat(us)     avg_lat(us)
-----------------------------------------------------
read          1036        848000          818

URL: https://tracker.ceph.com/issues/43215
Signed-off-by: Xiubo Li <xiubli@redhat.com>
---
 fs/ceph/addr.c                  |  6 ++++++
 fs/ceph/debugfs.c               | 11 +++++++++++
 fs/ceph/file.c                  | 13 +++++++++++++
 fs/ceph/mds_client.c            | 14 ++++++++++++++
 fs/ceph/metric.h                | 20 ++++++++++++++++++++
 include/linux/ceph/osd_client.h |  1 +
 net/ceph/osd_client.c           |  2 ++
 7 files changed, 67 insertions(+)

diff --git a/fs/ceph/addr.c b/fs/ceph/addr.c
index 6f4678d98df7..16573a13ffee 100644
--- a/fs/ceph/addr.c
+++ b/fs/ceph/addr.c
@@ -216,6 +216,8 @@ static int ceph_sync_readpages(struct ceph_fs_client *fsc,
 	if (!rc)
 		rc = ceph_osdc_wait_request(osdc, req);
 
+	ceph_update_read_latency(&fsc->mdsc->metric, req, rc);
+
 	ceph_osdc_put_request(req);
 	dout("readpages result %d\n", rc);
 	return rc;
@@ -299,6 +301,7 @@ static int ceph_readpage(struct file *filp, struct page *page)
 static void finish_read(struct ceph_osd_request *req)
 {
 	struct inode *inode = req->r_inode;
+	struct ceph_fs_client *fsc = ceph_inode_to_client(inode);
 	struct ceph_osd_data *osd_data;
 	int rc = req->r_result <= 0 ? req->r_result : 0;
 	int bytes = req->r_result >= 0 ? req->r_result : 0;
@@ -336,6 +339,9 @@ static void finish_read(struct ceph_osd_request *req)
 		put_page(page);
 		bytes -= PAGE_SIZE;
 	}
+
+	ceph_update_read_latency(&fsc->mdsc->metric, req, rc);
+
 	kfree(osd_data->pages);
 }
 
diff --git a/fs/ceph/debugfs.c b/fs/ceph/debugfs.c
index c83e52bd9961..d814a3a27611 100644
--- a/fs/ceph/debugfs.c
+++ b/fs/ceph/debugfs.c
@@ -129,7 +129,18 @@ static int metric_show(struct seq_file *s, void *p)
 	struct ceph_fs_client *fsc = s->private;
 	struct ceph_mds_client *mdsc = fsc->mdsc;
 	int i, nr_caps = 0;
+	s64 total, sum, avg = 0;
 
+	seq_printf(s, "item          total       sum_lat(us)     avg_lat(us)\n");
+	seq_printf(s, "-----------------------------------------------------\n");
+
+	total = percpu_counter_sum(&mdsc->metric.total_reads);
+	sum = percpu_counter_sum(&mdsc->metric.read_latency_sum);
+	sum = jiffies_to_usecs(sum);
+	avg = total ? sum / total : 0;
+	seq_printf(s, "%-14s%-12lld%-16lld%lld\n", "read", total, sum, avg);
+
+	seq_printf(s, "\n");
 	seq_printf(s, "item          total           miss            hit\n");
 	seq_printf(s, "-------------------------------------------------\n");
 
diff --git a/fs/ceph/file.c b/fs/ceph/file.c
index 7e0190b1f821..d51375c4627e 100644
--- a/fs/ceph/file.c
+++ b/fs/ceph/file.c
@@ -658,6 +658,9 @@ static ssize_t ceph_sync_read(struct kiocb *iocb, struct iov_iter *to,
 		ret = ceph_osdc_start_request(osdc, req, false);
 		if (!ret)
 			ret = ceph_osdc_wait_request(osdc, req);
+
+		ceph_update_read_latency(&fsc->mdsc->metric, req, ret);
+
 		ceph_osdc_put_request(req);
 
 		i_size = i_size_read(inode);
@@ -796,6 +799,8 @@ static void ceph_aio_complete_req(struct ceph_osd_request *req)
 	struct inode *inode = req->r_inode;
 	struct ceph_aio_request *aio_req = req->r_priv;
 	struct ceph_osd_data *osd_data = osd_req_op_extent_osd_data(req, 0);
+	struct ceph_fs_client *fsc = ceph_inode_to_client(inode);
+	struct ceph_client_metric *metric = &fsc->mdsc->metric;
 
 	BUG_ON(osd_data->type != CEPH_OSD_DATA_TYPE_BVECS);
 	BUG_ON(!osd_data->num_bvecs);
@@ -803,6 +808,10 @@ static void ceph_aio_complete_req(struct ceph_osd_request *req)
 	dout("ceph_aio_complete_req %p rc %d bytes %u\n",
 	     inode, rc, osd_data->bvec_pos.iter.bi_size);
 
+	/* r_start_stamp == 0 means the request was not submitted */
+	if (req->r_start_stamp && !aio_req->write)
+		ceph_update_read_latency(metric, req, rc);
+
 	if (rc == -EOLDSNAPC) {
 		struct ceph_aio_work *aio_work;
 		BUG_ON(!aio_req->write);
@@ -931,6 +940,7 @@ ceph_direct_read_write(struct kiocb *iocb, struct iov_iter *iter,
 	struct inode *inode = file_inode(file);
 	struct ceph_inode_info *ci = ceph_inode(inode);
 	struct ceph_fs_client *fsc = ceph_inode_to_client(inode);
+	struct ceph_client_metric *metric = &fsc->mdsc->metric;
 	struct ceph_vino vino;
 	struct ceph_osd_request *req;
 	struct bio_vec *bvecs;
@@ -1047,6 +1057,9 @@ ceph_direct_read_write(struct kiocb *iocb, struct iov_iter *iter,
 		if (!ret)
 			ret = ceph_osdc_wait_request(&fsc->client->osdc, req);
 
+		if (!write)
+			ceph_update_read_latency(metric, req, ret);
+
 		size = i_size_read(inode);
 		if (!write) {
 			if (ret == -ENOENT)
diff --git a/fs/ceph/mds_client.c b/fs/ceph/mds_client.c
index cd31bcb4e563..18f018b3bd53 100644
--- a/fs/ceph/mds_client.c
+++ b/fs/ceph/mds_client.c
@@ -4180,8 +4180,20 @@ static int ceph_mdsc_metric_init(struct ceph_client_metric *metric)
 	if (ret)
 		goto err_i_caps_mis;
 
+	ret = percpu_counter_init(&metric->total_reads, 0, GFP_KERNEL);
+	if (ret)
+		goto err_total_reads;
+
+	ret = percpu_counter_init(&metric->read_latency_sum, 0, GFP_KERNEL);
+	if (ret)
+		goto err_read_latency_sum;
+
 	return 0;
 
+err_read_latency_sum:
+	percpu_counter_destroy(&metric->total_reads);
+err_total_reads:
+	percpu_counter_destroy(&metric->i_caps_mis);
 err_i_caps_mis:
 	percpu_counter_destroy(&metric->i_caps_hit);
 err_i_caps_hit:
@@ -4529,6 +4541,8 @@ void ceph_mdsc_destroy(struct ceph_fs_client *fsc)
 
 	ceph_mdsc_stop(mdsc);
 
+	percpu_counter_destroy(&mdsc->metric.read_latency_sum);
+	percpu_counter_destroy(&mdsc->metric.total_reads);
 	percpu_counter_destroy(&mdsc->metric.i_caps_mis);
 	percpu_counter_destroy(&mdsc->metric.i_caps_hit);
 	percpu_counter_destroy(&mdsc->metric.d_lease_mis);
diff --git a/fs/ceph/metric.h b/fs/ceph/metric.h
index 40eb58f9f43e..86a479da307e 100644
--- a/fs/ceph/metric.h
+++ b/fs/ceph/metric.h
@@ -2,6 +2,8 @@
 #ifndef _FS_CEPH_MDS_METRIC_H
 #define _FS_CEPH_MDS_METRIC_H
 
+#include <linux/ceph/osd_client.h>
+
 /* This is the global metrics */
 struct ceph_client_metric {
 	atomic64_t            total_dentries;
@@ -10,6 +12,9 @@ struct ceph_client_metric {
 
 	struct percpu_counter i_caps_hit;
 	struct percpu_counter i_caps_mis;
+
+	struct percpu_counter total_reads;
+	struct percpu_counter read_latency_sum;
 };
 
 static inline void ceph_update_cap_hit(struct ceph_client_metric *m)
@@ -27,4 +32,19 @@ static inline void ceph_update_cap_mis(struct ceph_client_metric *m)
 
 	percpu_counter_inc(&m->i_caps_mis);
 }
+
+static inline void ceph_update_read_latency(struct ceph_client_metric *m,
+					    struct ceph_osd_request *req,
+					    int rc)
+{
+	if (!m || !req)
+		return;
+
+	if (rc >= 0 || rc == -ENOENT || rc == -ETIMEDOUT) {
+		s64 latency = req->r_end_stamp - req->r_start_stamp;
+
+		percpu_counter_inc(&m->total_reads);
+		percpu_counter_add(&m->read_latency_sum, latency);
+	}
+}
 #endif /* _FS_CEPH_MDS_METRIC_H */
diff --git a/include/linux/ceph/osd_client.h b/include/linux/ceph/osd_client.h
index 9d9f745b98a1..02ff3a302d26 100644
--- a/include/linux/ceph/osd_client.h
+++ b/include/linux/ceph/osd_client.h
@@ -213,6 +213,7 @@ struct ceph_osd_request {
 	/* internal */
 	unsigned long r_stamp;                /* jiffies, send or check time */
 	unsigned long r_start_stamp;          /* jiffies */
+	unsigned long r_end_stamp;            /* jiffies */
 	int r_attempts;
 	u32 r_map_dne_bound;
 
diff --git a/net/ceph/osd_client.c b/net/ceph/osd_client.c
index 8ff2856e2d52..108c9457d629 100644
--- a/net/ceph/osd_client.c
+++ b/net/ceph/osd_client.c
@@ -2389,6 +2389,8 @@ static void finish_request(struct ceph_osd_request *req)
 	WARN_ON(lookup_request_mc(&osdc->map_checks, req->r_tid));
 	dout("%s req %p tid %llu\n", __func__, req, req->r_tid);
 
+	req->r_end_stamp = jiffies;
+
 	if (req->r_osd)
 		unlink_request(req->r_osd, req);
 	atomic_dec(&osdc->num_requests);
-- 
2.21.0

^ permalink raw reply related	[flat|nested] 16+ messages in thread

* [PATCH v8 4/5] ceph: add global write latency metric support
  2020-02-21  7:05 [PATCH v8 0/5] ceph: add perf metrics support xiubli
                   ` (2 preceding siblings ...)
  2020-02-21  7:05 ` [PATCH v8 3/5] ceph: add global read latency metric support xiubli
@ 2020-02-21  7:05 ` xiubli
  2020-02-21  7:05 ` [PATCH v8 5/5] ceph: add global metadata perf " xiubli
  4 siblings, 0 replies; 16+ messages in thread
From: xiubli @ 2020-02-21  7:05 UTC (permalink / raw)
  To: jlayton, idryomov; +Cc: sage, zyan, pdonnell, ceph-devel, Xiubo Li

From: Xiubo Li <xiubli@redhat.com>

It will calculate the latency for the write osd requests, which only
include the time cousumed by network and the ceph osd.

item          total       sum_lat(us)     avg_lat(us)
-----------------------------------------------------
write         1048        8778000         8375

URL: https://tracker.ceph.com/issues/43215
Signed-off-by: Xiubo Li <xiubli@redhat.com>
---
 fs/ceph/addr.c       |  7 +++++++
 fs/ceph/debugfs.c    |  6 ++++++
 fs/ceph/file.c       | 13 ++++++++++---
 fs/ceph/mds_client.c | 14 ++++++++++++++
 fs/ceph/metric.h     | 18 ++++++++++++++++++
 5 files changed, 55 insertions(+), 3 deletions(-)

diff --git a/fs/ceph/addr.c b/fs/ceph/addr.c
index 16573a13ffee..aca2ca592e53 100644
--- a/fs/ceph/addr.c
+++ b/fs/ceph/addr.c
@@ -649,6 +649,8 @@ static int ceph_sync_writepages(struct ceph_fs_client *fsc,
 	if (!rc)
 		rc = ceph_osdc_wait_request(osdc, req);
 
+	ceph_update_write_latency(&fsc->mdsc->metric, req, rc);
+
 	ceph_osdc_put_request(req);
 	if (rc == 0)
 		rc = len;
@@ -800,6 +802,8 @@ static void writepages_finish(struct ceph_osd_request *req)
 		ceph_clear_error_write(ci);
 	}
 
+	ceph_update_write_latency(&fsc->mdsc->metric, req, rc);
+
 	/*
 	 * We lost the cache cap, need to truncate the page before
 	 * it is unlocked, otherwise we'd truncate it later in the
@@ -1858,6 +1862,9 @@ int ceph_uninline_data(struct file *filp, struct page *locked_page)
 	err = ceph_osdc_start_request(&fsc->client->osdc, req, false);
 	if (!err)
 		err = ceph_osdc_wait_request(&fsc->client->osdc, req);
+
+	ceph_update_write_latency(&fsc->mdsc->metric, req, err);
+
 out_put:
 	ceph_osdc_put_request(req);
 	if (err == -ECANCELED)
diff --git a/fs/ceph/debugfs.c b/fs/ceph/debugfs.c
index d814a3a27611..464bfbdb970d 100644
--- a/fs/ceph/debugfs.c
+++ b/fs/ceph/debugfs.c
@@ -140,6 +140,12 @@ static int metric_show(struct seq_file *s, void *p)
 	avg = total ? sum / total : 0;
 	seq_printf(s, "%-14s%-12lld%-16lld%lld\n", "read", total, sum, avg);
 
+	total = percpu_counter_sum(&mdsc->metric.total_writes);
+	sum = percpu_counter_sum(&mdsc->metric.write_latency_sum);
+	sum = jiffies_to_usecs(sum);
+	avg = total ? sum / total : 0;
+	seq_printf(s, "%-14s%-12lld%-16lld%lld\n", "write", total, sum, avg);
+
 	seq_printf(s, "\n");
 	seq_printf(s, "item          total           miss            hit\n");
 	seq_printf(s, "-------------------------------------------------\n");
diff --git a/fs/ceph/file.c b/fs/ceph/file.c
index d51375c4627e..46cac2410493 100644
--- a/fs/ceph/file.c
+++ b/fs/ceph/file.c
@@ -809,8 +809,12 @@ static void ceph_aio_complete_req(struct ceph_osd_request *req)
 	     inode, rc, osd_data->bvec_pos.iter.bi_size);
 
 	/* r_start_stamp == 0 means the request was not submitted */
-	if (req->r_start_stamp && !aio_req->write)
-		ceph_update_read_latency(metric, req, rc);
+	if (req->r_start_stamp) {
+		if (aio_req->write)
+			ceph_update_write_latency(metric, req, rc);
+		else
+			ceph_update_read_latency(metric, req, rc);
+	}
 
 	if (rc == -EOLDSNAPC) {
 		struct ceph_aio_work *aio_work;
@@ -1057,7 +1061,9 @@ ceph_direct_read_write(struct kiocb *iocb, struct iov_iter *iter,
 		if (!ret)
 			ret = ceph_osdc_wait_request(&fsc->client->osdc, req);
 
-		if (!write)
+		if (write)
+			ceph_update_write_latency(metric, req, ret);
+		else
 			ceph_update_read_latency(metric, req, ret);
 
 		size = i_size_read(inode);
@@ -1231,6 +1237,7 @@ ceph_sync_write(struct kiocb *iocb, struct iov_iter *from, loff_t pos,
 		if (!ret)
 			ret = ceph_osdc_wait_request(&fsc->client->osdc, req);
 
+		ceph_update_write_latency(&fsc->mdsc->metric, req, ret);
 out:
 		ceph_osdc_put_request(req);
 		if (ret != 0) {
diff --git a/fs/ceph/mds_client.c b/fs/ceph/mds_client.c
index 18f018b3bd53..0a3447966b26 100644
--- a/fs/ceph/mds_client.c
+++ b/fs/ceph/mds_client.c
@@ -4188,8 +4188,20 @@ static int ceph_mdsc_metric_init(struct ceph_client_metric *metric)
 	if (ret)
 		goto err_read_latency_sum;
 
+	ret = percpu_counter_init(&metric->total_writes, 0, GFP_KERNEL);
+	if (ret)
+		goto err_total_writes;
+
+	ret = percpu_counter_init(&metric->write_latency_sum, 0, GFP_KERNEL);
+	if (ret)
+		goto err_write_latency_sum;
+
 	return 0;
 
+err_write_latency_sum:
+	percpu_counter_destroy(&metric->total_writes);
+err_total_writes:
+	percpu_counter_destroy(&metric->read_latency_sum);
 err_read_latency_sum:
 	percpu_counter_destroy(&metric->total_reads);
 err_total_reads:
@@ -4541,6 +4553,8 @@ void ceph_mdsc_destroy(struct ceph_fs_client *fsc)
 
 	ceph_mdsc_stop(mdsc);
 
+	percpu_counter_destroy(&mdsc->metric.write_latency_sum);
+	percpu_counter_destroy(&mdsc->metric.total_writes);
 	percpu_counter_destroy(&mdsc->metric.read_latency_sum);
 	percpu_counter_destroy(&mdsc->metric.total_reads);
 	percpu_counter_destroy(&mdsc->metric.i_caps_mis);
diff --git a/fs/ceph/metric.h b/fs/ceph/metric.h
index 86a479da307e..a3d342f258e6 100644
--- a/fs/ceph/metric.h
+++ b/fs/ceph/metric.h
@@ -15,6 +15,9 @@ struct ceph_client_metric {
 
 	struct percpu_counter total_reads;
 	struct percpu_counter read_latency_sum;
+
+	struct percpu_counter total_writes;
+	struct percpu_counter write_latency_sum;
 };
 
 static inline void ceph_update_cap_hit(struct ceph_client_metric *m)
@@ -47,4 +50,19 @@ static inline void ceph_update_read_latency(struct ceph_client_metric *m,
 		percpu_counter_add(&m->read_latency_sum, latency);
 	}
 }
+
+static inline void ceph_update_write_latency(struct ceph_client_metric *m,
+					     struct ceph_osd_request *req,
+					     int rc)
+{
+	if (!m || !req)
+		return;
+
+	if (!rc || rc == -ETIMEDOUT) {
+		s64 latency = req->r_end_stamp - req->r_start_stamp;
+
+		percpu_counter_inc(&m->total_writes);
+		percpu_counter_add(&m->write_latency_sum, latency);
+	}
+}
 #endif /* _FS_CEPH_MDS_METRIC_H */
-- 
2.21.0

^ permalink raw reply related	[flat|nested] 16+ messages in thread

* [PATCH v8 5/5] ceph: add global metadata perf metric support
  2020-02-21  7:05 [PATCH v8 0/5] ceph: add perf metrics support xiubli
                   ` (3 preceding siblings ...)
  2020-02-21  7:05 ` [PATCH v8 4/5] ceph: add global write " xiubli
@ 2020-02-21  7:05 ` xiubli
  2020-02-21 12:03   ` Jeff Layton
  4 siblings, 1 reply; 16+ messages in thread
From: xiubli @ 2020-02-21  7:05 UTC (permalink / raw)
  To: jlayton, idryomov; +Cc: sage, zyan, pdonnell, ceph-devel, Xiubo Li

From: Xiubo Li <xiubli@redhat.com>

It will calculate the latency for the metedata requests, which only
include the time cousumed by network and the ceph.

item          total       sum_lat(us)     avg_lat(us)
-----------------------------------------------------
metadata      113         220000          1946

URL: https://tracker.ceph.com/issues/43215
Signed-off-by: Xiubo Li <xiubli@redhat.com>
---
 fs/ceph/debugfs.c    |  6 ++++++
 fs/ceph/mds_client.c | 20 ++++++++++++++++++++
 fs/ceph/metric.h     | 13 +++++++++++++
 3 files changed, 39 insertions(+)

diff --git a/fs/ceph/debugfs.c b/fs/ceph/debugfs.c
index 464bfbdb970d..60f3e307fca1 100644
--- a/fs/ceph/debugfs.c
+++ b/fs/ceph/debugfs.c
@@ -146,6 +146,12 @@ static int metric_show(struct seq_file *s, void *p)
 	avg = total ? sum / total : 0;
 	seq_printf(s, "%-14s%-12lld%-16lld%lld\n", "write", total, sum, avg);
 
+	total = percpu_counter_sum(&mdsc->metric.total_metadatas);
+	sum = percpu_counter_sum(&mdsc->metric.metadata_latency_sum);
+	sum = jiffies_to_usecs(sum);
+	avg = total ? sum / total : 0;
+	seq_printf(s, "%-14s%-12lld%-16lld%lld\n", "metadata", total, sum, avg);
+
 	seq_printf(s, "\n");
 	seq_printf(s, "item          total           miss            hit\n");
 	seq_printf(s, "-------------------------------------------------\n");
diff --git a/fs/ceph/mds_client.c b/fs/ceph/mds_client.c
index 0a3447966b26..3e792eca6af7 100644
--- a/fs/ceph/mds_client.c
+++ b/fs/ceph/mds_client.c
@@ -3017,6 +3017,12 @@ static void handle_reply(struct ceph_mds_session *session, struct ceph_msg *msg)
 
 	/* kick calling process */
 	complete_request(mdsc, req);
+
+	if (!result || result == -ENOENT) {
+		s64 latency = jiffies - req->r_started;
+
+		ceph_update_metadata_latency(&mdsc->metric, latency);
+	}
 out:
 	ceph_mdsc_put_request(req);
 	return;
@@ -4196,8 +4202,20 @@ static int ceph_mdsc_metric_init(struct ceph_client_metric *metric)
 	if (ret)
 		goto err_write_latency_sum;
 
+	ret = percpu_counter_init(&metric->total_metadatas, 0, GFP_KERNEL);
+	if (ret)
+		goto err_total_metadatas;
+
+	ret = percpu_counter_init(&metric->metadata_latency_sum, 0, GFP_KERNEL);
+	if (ret)
+		goto err_metadata_latency_sum;
+
 	return 0;
 
+err_metadata_latency_sum:
+	percpu_counter_destroy(&metric->total_metadatas);
+err_total_metadatas:
+	percpu_counter_destroy(&metric->write_latency_sum);
 err_write_latency_sum:
 	percpu_counter_destroy(&metric->total_writes);
 err_total_writes:
@@ -4553,6 +4571,8 @@ void ceph_mdsc_destroy(struct ceph_fs_client *fsc)
 
 	ceph_mdsc_stop(mdsc);
 
+	percpu_counter_destroy(&mdsc->metric.metadata_latency_sum);
+	percpu_counter_destroy(&mdsc->metric.total_metadatas);
 	percpu_counter_destroy(&mdsc->metric.write_latency_sum);
 	percpu_counter_destroy(&mdsc->metric.total_writes);
 	percpu_counter_destroy(&mdsc->metric.read_latency_sum);
diff --git a/fs/ceph/metric.h b/fs/ceph/metric.h
index a3d342f258e6..4c14b4ac089d 100644
--- a/fs/ceph/metric.h
+++ b/fs/ceph/metric.h
@@ -18,6 +18,9 @@ struct ceph_client_metric {
 
 	struct percpu_counter total_writes;
 	struct percpu_counter write_latency_sum;
+
+	struct percpu_counter total_metadatas;
+	struct percpu_counter metadata_latency_sum;
 };
 
 static inline void ceph_update_cap_hit(struct ceph_client_metric *m)
@@ -65,4 +68,14 @@ static inline void ceph_update_write_latency(struct ceph_client_metric *m,
 		percpu_counter_add(&m->write_latency_sum, latency);
 	}
 }
+
+static inline void ceph_update_metadata_latency(struct ceph_client_metric *m,
+						s64 latency)
+{
+	if (!m)
+		return;
+
+	percpu_counter_inc(&m->total_metadatas);
+	percpu_counter_add(&m->metadata_latency_sum, latency);
+}
 #endif /* _FS_CEPH_MDS_METRIC_H */
-- 
2.21.0

^ permalink raw reply related	[flat|nested] 16+ messages in thread

* Re: [PATCH v8 2/5] ceph: add caps perf metric for each session
  2020-02-21  7:05 ` [PATCH v8 2/5] ceph: add caps perf metric for each session xiubli
@ 2020-02-21 12:00   ` Jeff Layton
  2020-02-22  1:51     ` Xiubo Li
  0 siblings, 1 reply; 16+ messages in thread
From: Jeff Layton @ 2020-02-21 12:00 UTC (permalink / raw)
  To: xiubli, idryomov; +Cc: sage, zyan, pdonnell, ceph-devel

On Fri, 2020-02-21 at 02:05 -0500, xiubli@redhat.com wrote:
> From: Xiubo Li <xiubli@redhat.com>
> 
> This will fulfill the cap hit/mis metric stuff per-superblock,
> it will count the hit/mis counters based each inode, and if one
> inode's 'issued & ~revoking == mask' will mean a hit, or a miss.
> 
> item          total           miss            hit
> -------------------------------------------------
> caps          295             107             4119
> 
> URL: https://tracker.ceph.com/issues/43215
> Signed-off-by: Xiubo Li <xiubli@redhat.com>
> ---
>  fs/ceph/acl.c        |  2 +-
>  fs/ceph/caps.c       | 19 +++++++++++++++++++
>  fs/ceph/debugfs.c    | 16 ++++++++++++++++
>  fs/ceph/dir.c        |  5 +++--
>  fs/ceph/inode.c      |  4 ++--
>  fs/ceph/mds_client.c | 26 ++++++++++++++++++++++----
>  fs/ceph/metric.h     | 19 +++++++++++++++++++
>  fs/ceph/super.h      |  8 +++++---
>  fs/ceph/xattr.c      |  4 ++--
>  9 files changed, 89 insertions(+), 14 deletions(-)
> 
> diff --git a/fs/ceph/acl.c b/fs/ceph/acl.c
> index 26be6520d3fb..e0465741c591 100644
> --- a/fs/ceph/acl.c
> +++ b/fs/ceph/acl.c
> @@ -22,7 +22,7 @@ static inline void ceph_set_cached_acl(struct inode *inode,
>  	struct ceph_inode_info *ci = ceph_inode(inode);
>  
>  	spin_lock(&ci->i_ceph_lock);
> -	if (__ceph_caps_issued_mask(ci, CEPH_CAP_XATTR_SHARED, 0))
> +	if (__ceph_caps_issued_mask_metric(ci, CEPH_CAP_XATTR_SHARED, 0))
>  		set_cached_acl(inode, type, acl);
>  	else
>  		forget_cached_acl(inode, type);

nit: calling __ceph_caps_issued_mask_metric means that you have an extra
branch. One to set/forget acl and one to update the counter.

This would be (very slightly) more efficient if you just put the cap
hit/miss calls inside the existing if block above. IOW, you could just
do:

if (__ceph_caps_issued_mask(ci, CEPH_CAP_XATTR_SHARED, 0)) {
	set_cached_acl(inode, type, acl);
	ceph_update_cap_hit(&fsc->mdsc->metric);
} else {
	forget_cached_acl(inode, type);
	ceph_update_cap_mis(&fsc->mdsc->metric);
}

> diff --git a/fs/ceph/caps.c b/fs/ceph/caps.c
> index d05717397c2a..fe2ae41f2ec1 100644
> --- a/fs/ceph/caps.c
> +++ b/fs/ceph/caps.c
> @@ -920,6 +920,20 @@ int __ceph_caps_issued_mask(struct ceph_inode_info *ci, int mask, int touch)
>  	return 0;
>  }
>  
> +int __ceph_caps_issued_mask_metric(struct ceph_inode_info *ci, int mask,
> +				   int touch)
> +{
> +	struct ceph_fs_client *fsc = ceph_sb_to_client(ci->vfs_inode.i_sb);
> +	int r;
> +
> +	r = __ceph_caps_issued_mask(ci, mask, touch);
> +	if (r)
> +		ceph_update_cap_hit(&fsc->mdsc->metric);
> +	else
> +		ceph_update_cap_mis(&fsc->mdsc->metric);
> +	return r;
> +}
> +
>  /*
>   * Return true if mask caps are currently being revoked by an MDS.
>   */
> @@ -2700,6 +2714,11 @@ static int try_get_cap_refs(struct inode *inode, int need, int want,
>  	if (snap_rwsem_locked)
>  		up_read(&mdsc->snap_rwsem);
>  
> +	if (!ret)
> +		ceph_update_cap_mis(&mdsc->metric);
> +	else if (ret == 1)
> +		ceph_update_cap_hit(&mdsc->metric);
> +
>  	dout("get_cap_refs %p ret %d got %s\n", inode,
>  	     ret, ceph_cap_string(*got));
>  	return ret;
> diff --git a/fs/ceph/debugfs.c b/fs/ceph/debugfs.c
> index 15975ba95d9a..c83e52bd9961 100644
> --- a/fs/ceph/debugfs.c
> +++ b/fs/ceph/debugfs.c
> @@ -128,6 +128,7 @@ static int metric_show(struct seq_file *s, void *p)
>  {
>  	struct ceph_fs_client *fsc = s->private;
>  	struct ceph_mds_client *mdsc = fsc->mdsc;
> +	int i, nr_caps = 0;
>  
>  	seq_printf(s, "item          total           miss            hit\n");
>  	seq_printf(s, "-------------------------------------------------\n");
> @@ -137,6 +138,21 @@ static int metric_show(struct seq_file *s, void *p)
>  		   percpu_counter_sum(&mdsc->metric.d_lease_mis),
>  		   percpu_counter_sum(&mdsc->metric.d_lease_hit));
>  
> +	mutex_lock(&mdsc->mutex);
> +	for (i = 0; i < mdsc->max_sessions; i++) {
> +		struct ceph_mds_session *s;
> +
> +		s = __ceph_lookup_mds_session(mdsc, i);
> +		if (!s)
> +			continue;
> +		nr_caps += s->s_nr_caps;
> +		ceph_put_mds_session(s);
> +	}
> +	mutex_unlock(&mdsc->mutex);
> +	seq_printf(s, "%-14s%-16d%-16lld%lld\n", "caps", nr_caps,
> +		   percpu_counter_sum(&mdsc->metric.i_caps_mis),
> +		   percpu_counter_sum(&mdsc->metric.i_caps_hit));
> +
>  	return 0;
>  }
>  
> diff --git a/fs/ceph/dir.c b/fs/ceph/dir.c
> index ff1714fe03aa..227949c3deb8 100644
> --- a/fs/ceph/dir.c
> +++ b/fs/ceph/dir.c
> @@ -346,8 +346,9 @@ static int ceph_readdir(struct file *file, struct dir_context *ctx)
>  	    !ceph_test_mount_opt(fsc, NOASYNCREADDIR) &&
>  	    ceph_snap(inode) != CEPH_SNAPDIR &&
>  	    __ceph_dir_is_complete_ordered(ci) &&
> -	    __ceph_caps_issued_mask(ci, CEPH_CAP_FILE_SHARED, 1)) {
> +	    __ceph_caps_issued_mask_metric(ci, CEPH_CAP_FILE_SHARED, 1)) {

These could also just be cap_hit/mis calls inside the existing if
blocks.

>  		int shared_gen = atomic_read(&ci->i_shared_gen);
> +
>  		spin_unlock(&ci->i_ceph_lock);
>  		err = __dcache_readdir(file, ctx, shared_gen);
>  		if (err != -EAGAIN)
> @@ -764,7 +765,7 @@ static struct dentry *ceph_lookup(struct inode *dir, struct dentry *dentry,
>  		    !is_root_ceph_dentry(dir, dentry) &&
>  		    ceph_test_mount_opt(fsc, DCACHE) &&
>  		    __ceph_dir_is_complete(ci) &&
> -		    (__ceph_caps_issued_mask(ci, CEPH_CAP_FILE_SHARED, 1))) {
> +		    __ceph_caps_issued_mask_metric(ci, CEPH_CAP_FILE_SHARED, 1)) {

...and here

>  			spin_unlock(&ci->i_ceph_lock);
>  			dout(" dir %p complete, -ENOENT\n", dir);
>  			d_add(dentry, NULL);
> diff --git a/fs/ceph/inode.c b/fs/ceph/inode.c
> index 094b8fc37787..8dc10196e3a1 100644
> --- a/fs/ceph/inode.c
> +++ b/fs/ceph/inode.c
> @@ -2273,8 +2273,8 @@ int __ceph_do_getattr(struct inode *inode, struct page *locked_page,
>  
>  	dout("do_getattr inode %p mask %s mode 0%o\n",
>  	     inode, ceph_cap_string(mask), inode->i_mode);
> -	if (!force && ceph_caps_issued_mask(ceph_inode(inode), mask, 1))
> -		return 0;
> +	if (!force && ceph_caps_issued_mask_metric(ceph_inode(inode), mask, 1))
> +			return 0;
>  
>  	mode = (mask & CEPH_STAT_RSTAT) ? USE_AUTH_MDS : USE_ANY_MDS;
>  	req = ceph_mdsc_create_request(mdsc, CEPH_MDS_OP_GETATTR, mode);
> diff --git a/fs/ceph/mds_client.c b/fs/ceph/mds_client.c
> index 82060afd5dca..cd31bcb4e563 100644
> --- a/fs/ceph/mds_client.c
> +++ b/fs/ceph/mds_client.c
> @@ -4167,13 +4167,29 @@ static int ceph_mdsc_metric_init(struct ceph_client_metric *metric)
>  	ret = percpu_counter_init(&metric->d_lease_hit, 0, GFP_KERNEL);
>  	if (ret)
>  		return ret;
> +
>  	ret = percpu_counter_init(&metric->d_lease_mis, 0, GFP_KERNEL);
> -	if (ret) {
> -		percpu_counter_destroy(&metric->d_lease_hit);
> -		return ret;
> -	}
> +	if (ret)
> +		goto err_d_lease_mis;
> +
> +	ret = percpu_counter_init(&metric->i_caps_hit, 0, GFP_KERNEL);
> +	if (ret)
> +		goto err_i_caps_hit;
> +
> +	ret = percpu_counter_init(&metric->i_caps_mis, 0, GFP_KERNEL);
> +	if (ret)
> +		goto err_i_caps_mis;
>  
>  	return 0;
> +
> +err_i_caps_mis:
> +	percpu_counter_destroy(&metric->i_caps_hit);
> +err_i_caps_hit:
> +	percpu_counter_destroy(&metric->d_lease_mis);
> +err_d_lease_mis:
> +	percpu_counter_destroy(&metric->d_lease_hit);
> +
> +	return ret;
>  }
>  
>  int ceph_mdsc_init(struct ceph_fs_client *fsc)
> @@ -4513,6 +4529,8 @@ void ceph_mdsc_destroy(struct ceph_fs_client *fsc)
>  
>  	ceph_mdsc_stop(mdsc);
>  
> +	percpu_counter_destroy(&mdsc->metric.i_caps_mis);
> +	percpu_counter_destroy(&mdsc->metric.i_caps_hit);
>  	percpu_counter_destroy(&mdsc->metric.d_lease_mis);
>  	percpu_counter_destroy(&mdsc->metric.d_lease_hit);
>  
> diff --git a/fs/ceph/metric.h b/fs/ceph/metric.h
> index 998fe2a643cf..40eb58f9f43e 100644
> --- a/fs/ceph/metric.h
> +++ b/fs/ceph/metric.h
> @@ -7,5 +7,24 @@ struct ceph_client_metric {
>  	atomic64_t            total_dentries;
>  	struct percpu_counter d_lease_hit;
>  	struct percpu_counter d_lease_mis;
> +
> +	struct percpu_counter i_caps_hit;
> +	struct percpu_counter i_caps_mis;
>  };
> +
> +static inline void ceph_update_cap_hit(struct ceph_client_metric *m)
> +{
> +	if (!m)
> +		return;
> +

When are these ever NULL?

> +	percpu_counter_inc(&m->i_caps_hit);
> +}
> +
> +static inline void ceph_update_cap_mis(struct ceph_client_metric *m)
> +{
> +	if (!m)
> +		return;
> +
> +	percpu_counter_inc(&m->i_caps_mis);
> +}
>  #endif /* _FS_CEPH_MDS_METRIC_H */
> diff --git a/fs/ceph/super.h b/fs/ceph/super.h
> index ebcf7612eac9..4b269dc845bb 100644
> --- a/fs/ceph/super.h
> +++ b/fs/ceph/super.h
> @@ -639,6 +639,8 @@ static inline bool __ceph_is_any_real_caps(struct ceph_inode_info *ci)
>  
>  extern int __ceph_caps_issued(struct ceph_inode_info *ci, int *implemented);
>  extern int __ceph_caps_issued_mask(struct ceph_inode_info *ci, int mask, int t);
> +extern int __ceph_caps_issued_mask_metric(struct ceph_inode_info *ci, int mask,
> +					  int t);
>  extern int __ceph_caps_issued_other(struct ceph_inode_info *ci,
>  				    struct ceph_cap *cap);
>  
> @@ -651,12 +653,12 @@ static inline int ceph_caps_issued(struct ceph_inode_info *ci)
>  	return issued;
>  }
>  
> -static inline int ceph_caps_issued_mask(struct ceph_inode_info *ci, int mask,
> -					int touch)
> +static inline int ceph_caps_issued_mask_metric(struct ceph_inode_info *ci,
> +					       int mask, int touch)
>  {
>  	int r;
>  	spin_lock(&ci->i_ceph_lock);
> -	r = __ceph_caps_issued_mask(ci, mask, touch);
> +	r = __ceph_caps_issued_mask_metric(ci, mask, touch);
>  	spin_unlock(&ci->i_ceph_lock);
>  	return r;
>  }
> diff --git a/fs/ceph/xattr.c b/fs/ceph/xattr.c
> index 7b8a070a782d..71ee34d160c3 100644
> --- a/fs/ceph/xattr.c
> +++ b/fs/ceph/xattr.c
> @@ -856,7 +856,7 @@ ssize_t __ceph_getxattr(struct inode *inode, const char *name, void *value,
>  
>  	if (ci->i_xattrs.version == 0 ||
>  	    !((req_mask & CEPH_CAP_XATTR_SHARED) ||
> -	      __ceph_caps_issued_mask(ci, CEPH_CAP_XATTR_SHARED, 1))) {
> +	      __ceph_caps_issued_mask_metric(ci, CEPH_CAP_XATTR_SHARED, 1))) {
>  		spin_unlock(&ci->i_ceph_lock);
>  
>  		/* security module gets xattr while filling trace */
> @@ -914,7 +914,7 @@ ssize_t ceph_listxattr(struct dentry *dentry, char *names, size_t size)
>  	     ci->i_xattrs.version, ci->i_xattrs.index_version);
>  
>  	if (ci->i_xattrs.version == 0 ||
> -	    !__ceph_caps_issued_mask(ci, CEPH_CAP_XATTR_SHARED, 1)) {
> +	    !__ceph_caps_issued_mask_metric(ci, CEPH_CAP_XATTR_SHARED, 1)) {
>  		spin_unlock(&ci->i_ceph_lock);
>  		err = ceph_do_getattr(inode, CEPH_STAT_CAP_XATTR, true);
>  		if (err)

-- 
Jeff Layton <jlayton@kernel.org>

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: [PATCH v8 5/5] ceph: add global metadata perf metric support
  2020-02-21  7:05 ` [PATCH v8 5/5] ceph: add global metadata perf " xiubli
@ 2020-02-21 12:03   ` Jeff Layton
  2020-02-21 14:56     ` Ilya Dryomov
  2020-02-22  1:09     ` Xiubo Li
  0 siblings, 2 replies; 16+ messages in thread
From: Jeff Layton @ 2020-02-21 12:03 UTC (permalink / raw)
  To: xiubli, idryomov; +Cc: sage, zyan, pdonnell, ceph-devel

On Fri, 2020-02-21 at 02:05 -0500, xiubli@redhat.com wrote:
> From: Xiubo Li <xiubli@redhat.com>
> 
> It will calculate the latency for the metedata requests, which only
> include the time cousumed by network and the ceph.
> 

"and the ceph MDS" ?

> item          total       sum_lat(us)     avg_lat(us)
> -----------------------------------------------------
> metadata      113         220000          1946
> 
> URL: https://tracker.ceph.com/issues/43215
> Signed-off-by: Xiubo Li <xiubli@redhat.com>
> ---
>  fs/ceph/debugfs.c    |  6 ++++++
>  fs/ceph/mds_client.c | 20 ++++++++++++++++++++
>  fs/ceph/metric.h     | 13 +++++++++++++
>  3 files changed, 39 insertions(+)
> 
> diff --git a/fs/ceph/debugfs.c b/fs/ceph/debugfs.c
> index 464bfbdb970d..60f3e307fca1 100644
> --- a/fs/ceph/debugfs.c
> +++ b/fs/ceph/debugfs.c
> @@ -146,6 +146,12 @@ static int metric_show(struct seq_file *s, void *p)
>  	avg = total ? sum / total : 0;
>  	seq_printf(s, "%-14s%-12lld%-16lld%lld\n", "write", total, sum, avg);
>  
> +	total = percpu_counter_sum(&mdsc->metric.total_metadatas);
> +	sum = percpu_counter_sum(&mdsc->metric.metadata_latency_sum);
> +	sum = jiffies_to_usecs(sum);
> +	avg = total ? sum / total : 0;
> +	seq_printf(s, "%-14s%-12lld%-16lld%lld\n", "metadata", total, sum, avg);
> +
>  	seq_printf(s, "\n");
>  	seq_printf(s, "item          total           miss            hit\n");
>  	seq_printf(s, "-------------------------------------------------\n");
> diff --git a/fs/ceph/mds_client.c b/fs/ceph/mds_client.c
> index 0a3447966b26..3e792eca6af7 100644
> --- a/fs/ceph/mds_client.c
> +++ b/fs/ceph/mds_client.c
> @@ -3017,6 +3017,12 @@ static void handle_reply(struct ceph_mds_session *session, struct ceph_msg *msg)
>  
>  	/* kick calling process */
>  	complete_request(mdsc, req);
> +
> +	if (!result || result == -ENOENT) {
> +		s64 latency = jiffies - req->r_started;
> +
> +		ceph_update_metadata_latency(&mdsc->metric, latency);
> +	}

Should we add an r_end_stamp field to the mds request struct and use
that to calculate this? Many jiffies may have passed between the reply
coming in and this point. If you really want to measure the latency that
would be more accurate, I think.

>  out:
>  	ceph_mdsc_put_request(req);
>  	return;
> @@ -4196,8 +4202,20 @@ static int ceph_mdsc_metric_init(struct ceph_client_metric *metric)
>  	if (ret)
>  		goto err_write_latency_sum;
>  
> +	ret = percpu_counter_init(&metric->total_metadatas, 0, GFP_KERNEL);
> +	if (ret)
> +		goto err_total_metadatas;
> +
> +	ret = percpu_counter_init(&metric->metadata_latency_sum, 0, GFP_KERNEL);
> +	if (ret)
> +		goto err_metadata_latency_sum;
> +
>  	return 0;
>  
> +err_metadata_latency_sum:
> +	percpu_counter_destroy(&metric->total_metadatas);
> +err_total_metadatas:
> +	percpu_counter_destroy(&metric->write_latency_sum);
>  err_write_latency_sum:
>  	percpu_counter_destroy(&metric->total_writes);
>  err_total_writes:
> @@ -4553,6 +4571,8 @@ void ceph_mdsc_destroy(struct ceph_fs_client *fsc)
>  
>  	ceph_mdsc_stop(mdsc);
>  
> +	percpu_counter_destroy(&mdsc->metric.metadata_latency_sum);
> +	percpu_counter_destroy(&mdsc->metric.total_metadatas);
>  	percpu_counter_destroy(&mdsc->metric.write_latency_sum);
>  	percpu_counter_destroy(&mdsc->metric.total_writes);
>  	percpu_counter_destroy(&mdsc->metric.read_latency_sum);
> diff --git a/fs/ceph/metric.h b/fs/ceph/metric.h
> index a3d342f258e6..4c14b4ac089d 100644
> --- a/fs/ceph/metric.h
> +++ b/fs/ceph/metric.h
> @@ -18,6 +18,9 @@ struct ceph_client_metric {
>  
>  	struct percpu_counter total_writes;
>  	struct percpu_counter write_latency_sum;
> +
> +	struct percpu_counter total_metadatas;
> +	struct percpu_counter metadata_latency_sum;
>  };
>  
>  static inline void ceph_update_cap_hit(struct ceph_client_metric *m)
> @@ -65,4 +68,14 @@ static inline void ceph_update_write_latency(struct ceph_client_metric *m,
>  		percpu_counter_add(&m->write_latency_sum, latency);
>  	}
>  }
> +
> +static inline void ceph_update_metadata_latency(struct ceph_client_metric *m,
> +						s64 latency)
> +{
> +	if (!m)
> +		return;
> +
> +	percpu_counter_inc(&m->total_metadatas);
> +	percpu_counter_add(&m->metadata_latency_sum, latency);
> +}
>  #endif /* _FS_CEPH_MDS_METRIC_H */

-- 
Jeff Layton <jlayton@kernel.org>

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: [PATCH v8 5/5] ceph: add global metadata perf metric support
  2020-02-21 12:03   ` Jeff Layton
@ 2020-02-21 14:56     ` Ilya Dryomov
  2020-02-22  1:20       ` Xiubo Li
  2020-02-22  1:09     ` Xiubo Li
  1 sibling, 1 reply; 16+ messages in thread
From: Ilya Dryomov @ 2020-02-21 14:56 UTC (permalink / raw)
  To: Jeff Layton
  Cc: Xiubo Li, Sage Weil, Yan, Zheng, Patrick Donnelly, Ceph Development

On Fri, Feb 21, 2020 at 1:03 PM Jeff Layton <jlayton@kernel.org> wrote:
>
> On Fri, 2020-02-21 at 02:05 -0500, xiubli@redhat.com wrote:
> > From: Xiubo Li <xiubli@redhat.com>
> >
> > It will calculate the latency for the metedata requests, which only
> > include the time cousumed by network and the ceph.
> >
>
> "and the ceph MDS" ?
>
> > item          total       sum_lat(us)     avg_lat(us)
> > -----------------------------------------------------
> > metadata      113         220000          1946
> >
> > URL: https://tracker.ceph.com/issues/43215
> > Signed-off-by: Xiubo Li <xiubli@redhat.com>
> > ---
> >  fs/ceph/debugfs.c    |  6 ++++++
> >  fs/ceph/mds_client.c | 20 ++++++++++++++++++++
> >  fs/ceph/metric.h     | 13 +++++++++++++
> >  3 files changed, 39 insertions(+)
> >
> > diff --git a/fs/ceph/debugfs.c b/fs/ceph/debugfs.c
> > index 464bfbdb970d..60f3e307fca1 100644
> > --- a/fs/ceph/debugfs.c
> > +++ b/fs/ceph/debugfs.c
> > @@ -146,6 +146,12 @@ static int metric_show(struct seq_file *s, void *p)
> >       avg = total ? sum / total : 0;
> >       seq_printf(s, "%-14s%-12lld%-16lld%lld\n", "write", total, sum, avg);
> >
> > +     total = percpu_counter_sum(&mdsc->metric.total_metadatas);
> > +     sum = percpu_counter_sum(&mdsc->metric.metadata_latency_sum);
> > +     sum = jiffies_to_usecs(sum);
> > +     avg = total ? sum / total : 0;
> > +     seq_printf(s, "%-14s%-12lld%-16lld%lld\n", "metadata", total, sum, avg);
> > +
> >       seq_printf(s, "\n");
> >       seq_printf(s, "item          total           miss            hit\n");
> >       seq_printf(s, "-------------------------------------------------\n");
> > diff --git a/fs/ceph/mds_client.c b/fs/ceph/mds_client.c
> > index 0a3447966b26..3e792eca6af7 100644
> > --- a/fs/ceph/mds_client.c
> > +++ b/fs/ceph/mds_client.c
> > @@ -3017,6 +3017,12 @@ static void handle_reply(struct ceph_mds_session *session, struct ceph_msg *msg)
> >
> >       /* kick calling process */
> >       complete_request(mdsc, req);
> > +
> > +     if (!result || result == -ENOENT) {
> > +             s64 latency = jiffies - req->r_started;
> > +
> > +             ceph_update_metadata_latency(&mdsc->metric, latency);
> > +     }
>
> Should we add an r_end_stamp field to the mds request struct and use
> that to calculate this? Many jiffies may have passed between the reply
> coming in and this point. If you really want to measure the latency that
> would be more accurate, I think.

Yes, capturing it after invoking the callback is inconsistent
with what is done for OSD requests (the new r_end_stamp is set in
finish_request()).

It looks like this is the only place where MDS r_end_stamp would be
needed, so perhaps just move this before complete_request() call?

Thanks,

                Ilya

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: [PATCH v8 5/5] ceph: add global metadata perf metric support
  2020-02-21 12:03   ` Jeff Layton
  2020-02-21 14:56     ` Ilya Dryomov
@ 2020-02-22  1:09     ` Xiubo Li
  1 sibling, 0 replies; 16+ messages in thread
From: Xiubo Li @ 2020-02-22  1:09 UTC (permalink / raw)
  To: Jeff Layton, idryomov; +Cc: sage, zyan, pdonnell, ceph-devel

On 2020/2/21 20:03, Jeff Layton wrote:
> On Fri, 2020-02-21 at 02:05 -0500, xiubli@redhat.com wrote:
>> From: Xiubo Li <xiubli@redhat.com>
>>
>> It will calculate the latency for the metedata requests, which only
>> include the time cousumed by network and the ceph.
>>
> "and the ceph MDS" ?

Yeah, will fix the commit comment.


>
>> item          total       sum_lat(us)     avg_lat(us)
>> -----------------------------------------------------
>> metadata      113         220000          1946
>>
>> URL: https://tracker.ceph.com/issues/43215
>> Signed-off-by: Xiubo Li <xiubli@redhat.com>
>> ---
>>   fs/ceph/debugfs.c    |  6 ++++++
>>   fs/ceph/mds_client.c | 20 ++++++++++++++++++++
>>   fs/ceph/metric.h     | 13 +++++++++++++
>>   3 files changed, 39 insertions(+)
>>
>> diff --git a/fs/ceph/debugfs.c b/fs/ceph/debugfs.c
>> index 464bfbdb970d..60f3e307fca1 100644
>> --- a/fs/ceph/debugfs.c
>> +++ b/fs/ceph/debugfs.c
>> @@ -146,6 +146,12 @@ static int metric_show(struct seq_file *s, void *p)
>>   	avg = total ? sum / total : 0;
>>   	seq_printf(s, "%-14s%-12lld%-16lld%lld\n", "write", total, sum, avg);
>>   
>> +	total = percpu_counter_sum(&mdsc->metric.total_metadatas);
>> +	sum = percpu_counter_sum(&mdsc->metric.metadata_latency_sum);
>> +	sum = jiffies_to_usecs(sum);
>> +	avg = total ? sum / total : 0;
>> +	seq_printf(s, "%-14s%-12lld%-16lld%lld\n", "metadata", total, sum, avg);
>> +
>>   	seq_printf(s, "\n");
>>   	seq_printf(s, "item          total           miss            hit\n");
>>   	seq_printf(s, "-------------------------------------------------\n");
>> diff --git a/fs/ceph/mds_client.c b/fs/ceph/mds_client.c
>> index 0a3447966b26..3e792eca6af7 100644
>> --- a/fs/ceph/mds_client.c
>> +++ b/fs/ceph/mds_client.c
>> @@ -3017,6 +3017,12 @@ static void handle_reply(struct ceph_mds_session *session, struct ceph_msg *msg)
>>   
>>   	/* kick calling process */
>>   	complete_request(mdsc, req);
>> +
>> +	if (!result || result == -ENOENT) {
>> +		s64 latency = jiffies - req->r_started;
>> +
>> +		ceph_update_metadata_latency(&mdsc->metric, latency);
>> +	}
> Should we add an r_end_stamp field to the mds request struct and use
> that to calculate this? Many jiffies may have passed between the reply
> coming in and this point. If you really want to measure the latency that
> would be more accurate, I think.

Okay, will add it.

Thanks.

BRs

>>   out:
>>   	ceph_mdsc_put_request(req);
>>   	return;
>> @@ -4196,8 +4202,20 @@ static int ceph_mdsc_metric_init(struct ceph_client_metric *metric)
>>   	if (ret)
>>   		goto err_write_latency_sum;
>>   
>> +	ret = percpu_counter_init(&metric->total_metadatas, 0, GFP_KERNEL);
>> +	if (ret)
>> +		goto err_total_metadatas;
>> +
>> +	ret = percpu_counter_init(&metric->metadata_latency_sum, 0, GFP_KERNEL);
>> +	if (ret)
>> +		goto err_metadata_latency_sum;
>> +
>>   	return 0;
>>   
>> +err_metadata_latency_sum:
>> +	percpu_counter_destroy(&metric->total_metadatas);
>> +err_total_metadatas:
>> +	percpu_counter_destroy(&metric->write_latency_sum);
>>   err_write_latency_sum:
>>   	percpu_counter_destroy(&metric->total_writes);
>>   err_total_writes:
>> @@ -4553,6 +4571,8 @@ void ceph_mdsc_destroy(struct ceph_fs_client *fsc)
>>   
>>   	ceph_mdsc_stop(mdsc);
>>   
>> +	percpu_counter_destroy(&mdsc->metric.metadata_latency_sum);
>> +	percpu_counter_destroy(&mdsc->metric.total_metadatas);
>>   	percpu_counter_destroy(&mdsc->metric.write_latency_sum);
>>   	percpu_counter_destroy(&mdsc->metric.total_writes);
>>   	percpu_counter_destroy(&mdsc->metric.read_latency_sum);
>> diff --git a/fs/ceph/metric.h b/fs/ceph/metric.h
>> index a3d342f258e6..4c14b4ac089d 100644
>> --- a/fs/ceph/metric.h
>> +++ b/fs/ceph/metric.h
>> @@ -18,6 +18,9 @@ struct ceph_client_metric {
>>   
>>   	struct percpu_counter total_writes;
>>   	struct percpu_counter write_latency_sum;
>> +
>> +	struct percpu_counter total_metadatas;
>> +	struct percpu_counter metadata_latency_sum;
>>   };
>>   
>>   static inline void ceph_update_cap_hit(struct ceph_client_metric *m)
>> @@ -65,4 +68,14 @@ static inline void ceph_update_write_latency(struct ceph_client_metric *m,
>>   		percpu_counter_add(&m->write_latency_sum, latency);
>>   	}
>>   }
>> +
>> +static inline void ceph_update_metadata_latency(struct ceph_client_metric *m,
>> +						s64 latency)
>> +{
>> +	if (!m)
>> +		return;
>> +
>> +	percpu_counter_inc(&m->total_metadatas);
>> +	percpu_counter_add(&m->metadata_latency_sum, latency);
>> +}
>>   #endif /* _FS_CEPH_MDS_METRIC_H */

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: [PATCH v8 5/5] ceph: add global metadata perf metric support
  2020-02-21 14:56     ` Ilya Dryomov
@ 2020-02-22  1:20       ` Xiubo Li
  2020-02-22  1:36         ` Xiubo Li
  2020-02-24  9:56         ` Ilya Dryomov
  0 siblings, 2 replies; 16+ messages in thread
From: Xiubo Li @ 2020-02-22  1:20 UTC (permalink / raw)
  To: Ilya Dryomov, Jeff Layton
  Cc: Sage Weil, Yan, Zheng, Patrick Donnelly, Ceph Development

On 2020/2/21 22:56, Ilya Dryomov wrote:
> On Fri, Feb 21, 2020 at 1:03 PM Jeff Layton <jlayton@kernel.org> wrote:
>> On Fri, 2020-02-21 at 02:05 -0500, xiubli@redhat.com wrote:
>>> From: Xiubo Li <xiubli@redhat.com>
>>>
>>> It will calculate the latency for the metedata requests, which only
>>> include the time cousumed by network and the ceph.
>>>
>> "and the ceph MDS" ?
>>
>>> item          total       sum_lat(us)     avg_lat(us)
>>> -----------------------------------------------------
>>> metadata      113         220000          1946
>>>
>>> URL: https://tracker.ceph.com/issues/43215
>>> Signed-off-by: Xiubo Li <xiubli@redhat.com>
>>> ---
>>>   fs/ceph/debugfs.c    |  6 ++++++
>>>   fs/ceph/mds_client.c | 20 ++++++++++++++++++++
>>>   fs/ceph/metric.h     | 13 +++++++++++++
>>>   3 files changed, 39 insertions(+)
>>>
>>> diff --git a/fs/ceph/debugfs.c b/fs/ceph/debugfs.c
>>> index 464bfbdb970d..60f3e307fca1 100644
>>> --- a/fs/ceph/debugfs.c
>>> +++ b/fs/ceph/debugfs.c
>>> @@ -146,6 +146,12 @@ static int metric_show(struct seq_file *s, void *p)
>>>        avg = total ? sum / total : 0;
>>>        seq_printf(s, "%-14s%-12lld%-16lld%lld\n", "write", total, sum, avg);
>>>
>>> +     total = percpu_counter_sum(&mdsc->metric.total_metadatas);
>>> +     sum = percpu_counter_sum(&mdsc->metric.metadata_latency_sum);
>>> +     sum = jiffies_to_usecs(sum);
>>> +     avg = total ? sum / total : 0;
>>> +     seq_printf(s, "%-14s%-12lld%-16lld%lld\n", "metadata", total, sum, avg);
>>> +
>>>        seq_printf(s, "\n");
>>>        seq_printf(s, "item          total           miss            hit\n");
>>>        seq_printf(s, "-------------------------------------------------\n");
>>> diff --git a/fs/ceph/mds_client.c b/fs/ceph/mds_client.c
>>> index 0a3447966b26..3e792eca6af7 100644
>>> --- a/fs/ceph/mds_client.c
>>> +++ b/fs/ceph/mds_client.c
>>> @@ -3017,6 +3017,12 @@ static void handle_reply(struct ceph_mds_session *session, struct ceph_msg *msg)
>>>
>>>        /* kick calling process */
>>>        complete_request(mdsc, req);
>>> +
>>> +     if (!result || result == -ENOENT) {
>>> +             s64 latency = jiffies - req->r_started;
>>> +
>>> +             ceph_update_metadata_latency(&mdsc->metric, latency);
>>> +     }
>> Should we add an r_end_stamp field to the mds request struct and use
>> that to calculate this? Many jiffies may have passed between the reply
>> coming in and this point. If you really want to measure the latency that
>> would be more accurate, I think.
> Yes, capturing it after invoking the callback is inconsistent
> with what is done for OSD requests (the new r_end_stamp is set in
> finish_request()).
>
> It looks like this is the only place where MDS r_end_stamp would be
> needed, so perhaps just move this before complete_request() call?

Currently for the OSD requests, they are almost in the same place where 
at the end of the handle_reply.

If we don't want to calculate the consumption by the most of 
handle_reply code, we may set the r_end_stamp in the begin of it for 
both OSD/MDS requests ?

I'm thinking since in the handle_reply, it may also wait for the mutex 
locks and then sleeps, so move the r_end_stamp to the beginning should 
make sense...

Thanks
BRs


> Thanks,
>
>                  Ilya
>

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: [PATCH v8 5/5] ceph: add global metadata perf metric support
  2020-02-22  1:20       ` Xiubo Li
@ 2020-02-22  1:36         ` Xiubo Li
  2020-02-24  9:56         ` Ilya Dryomov
  1 sibling, 0 replies; 16+ messages in thread
From: Xiubo Li @ 2020-02-22  1:36 UTC (permalink / raw)
  To: Ilya Dryomov, Jeff Layton
  Cc: Sage Weil, Yan, Zheng, Patrick Donnelly, Ceph Development

On 2020/2/22 9:20, Xiubo Li wrote:
> On 2020/2/21 22:56, Ilya Dryomov wrote:
>> On Fri, Feb 21, 2020 at 1:03 PM Jeff Layton <jlayton@kernel.org> wrote:
>>> On Fri, 2020-02-21 at 02:05 -0500, xiubli@redhat.com wrote:
>>>> From: Xiubo Li <xiubli@redhat.com>
>>>>
>>>> It will calculate the latency for the metedata requests, which only
>>>> include the time cousumed by network and the ceph.
>>>>
>>> "and the ceph MDS" ?
>>>
>>>> item          total sum_lat(us)     avg_lat(us)
>>>> -----------------------------------------------------
>>>> metadata      113         220000          1946
>>>>
>>>> URL: https://tracker.ceph.com/issues/43215
>>>> Signed-off-by: Xiubo Li <xiubli@redhat.com>
>>>> ---
>>>>   fs/ceph/debugfs.c    |  6 ++++++
>>>>   fs/ceph/mds_client.c | 20 ++++++++++++++++++++
>>>>   fs/ceph/metric.h     | 13 +++++++++++++
>>>>   3 files changed, 39 insertions(+)
>>>>
>>>> diff --git a/fs/ceph/debugfs.c b/fs/ceph/debugfs.c
>>>> index 464bfbdb970d..60f3e307fca1 100644
>>>> --- a/fs/ceph/debugfs.c
>>>> +++ b/fs/ceph/debugfs.c
>>>> @@ -146,6 +146,12 @@ static int metric_show(struct seq_file *s, 
>>>> void *p)
>>>>        avg = total ? sum / total : 0;
>>>>        seq_printf(s, "%-14s%-12lld%-16lld%lld\n", "write", total, 
>>>> sum, avg);
>>>>
>>>> +     total = percpu_counter_sum(&mdsc->metric.total_metadatas);
>>>> +     sum = percpu_counter_sum(&mdsc->metric.metadata_latency_sum);
>>>> +     sum = jiffies_to_usecs(sum);
>>>> +     avg = total ? sum / total : 0;
>>>> +     seq_printf(s, "%-14s%-12lld%-16lld%lld\n", "metadata", total, 
>>>> sum, avg);
>>>> +
>>>>        seq_printf(s, "\n");
>>>>        seq_printf(s, "item          total miss            hit\n");
>>>>        seq_printf(s, 
>>>> "-------------------------------------------------\n");
>>>> diff --git a/fs/ceph/mds_client.c b/fs/ceph/mds_client.c
>>>> index 0a3447966b26..3e792eca6af7 100644
>>>> --- a/fs/ceph/mds_client.c
>>>> +++ b/fs/ceph/mds_client.c
>>>> @@ -3017,6 +3017,12 @@ static void handle_reply(struct 
>>>> ceph_mds_session *session, struct ceph_msg *msg)
>>>>
>>>>        /* kick calling process */
>>>>        complete_request(mdsc, req);
>>>> +
>>>> +     if (!result || result == -ENOENT) {
>>>> +             s64 latency = jiffies - req->r_started;
>>>> +
>>>> + ceph_update_metadata_latency(&mdsc->metric, latency);
>>>> +     }
>>> Should we add an r_end_stamp field to the mds request struct and use
>>> that to calculate this? Many jiffies may have passed between the reply
>>> coming in and this point. If you really want to measure the latency 
>>> that
>>> would be more accurate, I think.
>> Yes, capturing it after invoking the callback is inconsistent
>> with what is done for OSD requests (the new r_end_stamp is set in
>> finish_request()).
>>
>> It looks like this is the only place where MDS r_end_stamp would be
>> needed, so perhaps just move this before complete_request() call?
>
> Currently for the OSD requests, they are almost in the same place 
> where at the end of the handle_reply.
>
> If we don't want to calculate the consumption by the most of 
> handle_reply code, we may set the r_end_stamp in the begin of it for 
> both OSD/MDS requests ?
>
> I'm thinking since in the handle_reply, it may also wait for the mutex 
> locks and then sleeps, so move the r_end_stamp to the beginning should 
> make sense...
>
Currently case: we are calculating the time took from OSD/MDS requests 
creating until the handle_reply finishes.

Another case mentioned above: we should move the r_end_stamp to the 
handle_reply beginning, move r_start_stamp just before the requesting 
submitted.

Which one should be better ?

Thanks.

BRs


> Thanks
> BRs
>
>
>> Thanks,
>>
>>                  Ilya
>>
>

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: [PATCH v8 2/5] ceph: add caps perf metric for each session
  2020-02-21 12:00   ` Jeff Layton
@ 2020-02-22  1:51     ` Xiubo Li
  2020-02-26  3:05       ` Jeff Layton
  0 siblings, 1 reply; 16+ messages in thread
From: Xiubo Li @ 2020-02-22  1:51 UTC (permalink / raw)
  To: Jeff Layton, idryomov; +Cc: sage, zyan, pdonnell, ceph-devel

On 2020/2/21 20:00, Jeff Layton wrote:
> On Fri, 2020-02-21 at 02:05 -0500, xiubli@redhat.com wrote:
>> From: Xiubo Li <xiubli@redhat.com>
>>
>> This will fulfill the cap hit/mis metric stuff per-superblock,
>> it will count the hit/mis counters based each inode, and if one
>> inode's 'issued & ~revoking == mask' will mean a hit, or a miss.
>>
>> item          total           miss            hit
>> -------------------------------------------------
>> caps          295             107             4119
>>
>> URL: https://tracker.ceph.com/issues/43215
>> Signed-off-by: Xiubo Li <xiubli@redhat.com>
>> ---
>>   fs/ceph/acl.c        |  2 +-
>>   fs/ceph/caps.c       | 19 +++++++++++++++++++
>>   fs/ceph/debugfs.c    | 16 ++++++++++++++++
>>   fs/ceph/dir.c        |  5 +++--
>>   fs/ceph/inode.c      |  4 ++--
>>   fs/ceph/mds_client.c | 26 ++++++++++++++++++++++----
>>   fs/ceph/metric.h     | 19 +++++++++++++++++++
>>   fs/ceph/super.h      |  8 +++++---
>>   fs/ceph/xattr.c      |  4 ++--
>>   9 files changed, 89 insertions(+), 14 deletions(-)
>>
>> diff --git a/fs/ceph/acl.c b/fs/ceph/acl.c
>> index 26be6520d3fb..e0465741c591 100644
>> --- a/fs/ceph/acl.c
>> +++ b/fs/ceph/acl.c
>> @@ -22,7 +22,7 @@ static inline void ceph_set_cached_acl(struct inode *inode,
>>   	struct ceph_inode_info *ci = ceph_inode(inode);
>>   
>>   	spin_lock(&ci->i_ceph_lock);
>> -	if (__ceph_caps_issued_mask(ci, CEPH_CAP_XATTR_SHARED, 0))
>> +	if (__ceph_caps_issued_mask_metric(ci, CEPH_CAP_XATTR_SHARED, 0))
>>   		set_cached_acl(inode, type, acl);
>>   	else
>>   		forget_cached_acl(inode, type);
> nit: calling __ceph_caps_issued_mask_metric means that you have an extra
> branch. One to set/forget acl and one to update the counter.
>
> This would be (very slightly) more efficient if you just put the cap
> hit/miss calls inside the existing if block above. IOW, you could just
> do:
>
> if (__ceph_caps_issued_mask(ci, CEPH_CAP_XATTR_SHARED, 0)) {
> 	set_cached_acl(inode, type, acl);
> 	ceph_update_cap_hit(&fsc->mdsc->metric);
> } else {
> 	forget_cached_acl(inode, type);
> 	ceph_update_cap_mis(&fsc->mdsc->metric);
> }

Yeah, this will works well here.


>> diff --git a/fs/ceph/dir.c b/fs/ceph/dir.c
>> index ff1714fe03aa..227949c3deb8 100644
>> --- a/fs/ceph/dir.c
>> +++ b/fs/ceph/dir.c
>> @@ -346,8 +346,9 @@ static int ceph_readdir(struct file *file, struct dir_context *ctx)
>>   	    !ceph_test_mount_opt(fsc, NOASYNCREADDIR) &&
>>   	    ceph_snap(inode) != CEPH_SNAPDIR &&
>>   	    __ceph_dir_is_complete_ordered(ci) &&
>> -	    __ceph_caps_issued_mask(ci, CEPH_CAP_FILE_SHARED, 1)) {
>> +	    __ceph_caps_issued_mask_metric(ci, CEPH_CAP_FILE_SHARED, 1)) {
> These could also just be cap_hit/mis calls inside the existing if
> blocks.

Yeah, right in the if branch we can be sure that the 
__ceph_caps_issued_mask() is called. But in the else branch we still 
need to get the return value from (rc = __ceph_caps_issued_mask()), and 
only when "rc == 0" cap_mis will need. This could simplify the code here 
and below.

This is main reason to add the __ceph_caps_issued_mask_metric() here. 
And if you do not like this approach I will switch it back :-)

>
>> @@ -7,5 +7,24 @@ struct ceph_client_metric {
>>   	atomic64_t            total_dentries;
>>   	struct percpu_counter d_lease_hit;
>>   	struct percpu_counter d_lease_mis;
>> +
>> +	struct percpu_counter i_caps_hit;
>> +	struct percpu_counter i_caps_mis;
>>   };
>> +
>> +static inline void ceph_update_cap_hit(struct ceph_client_metric *m)
>> +{
>> +	if (!m)
>> +		return;
>> +
> When are these ever NULL?

Will delete it.

Thanks

BRs

>
>> +	percpu_counter_inc(&m->i_caps_hit);
>> +}
>> +
>> +static inline void ceph_update_cap_mis(struct ceph_client_metric *m)
>> +{
>> +	if (!m)
>> +		return;
>> +
>> +	percpu_counter_inc(&m->i_caps_mis);
>> +}
>>   #endif /* _FS_CEPH_MDS_METRIC_H */
>> diff --git a/fs/ceph/super.h b/fs/ceph/super.h
>> index ebcf7612eac9..4b269dc845bb 100644
>> --- a/fs/ceph/super.h
>> +++ b/fs/ceph/super.h
>> @@ -639,6 +639,8 @@ static inline bool __ceph_is_any_real_caps(struct ceph_inode_info *ci)
>>   
>>   extern int __ceph_caps_issued(struct ceph_inode_info *ci, int *implemented);
>>   extern int __ceph_caps_issued_mask(struct ceph_inode_info *ci, int mask, int t);
>> +extern int __ceph_caps_issued_mask_metric(struct ceph_inode_info *ci, int mask,
>> +					  int t);
>>   extern int __ceph_caps_issued_other(struct ceph_inode_info *ci,
>>   				    struct ceph_cap *cap);
>>   
>> @@ -651,12 +653,12 @@ static inline int ceph_caps_issued(struct ceph_inode_info *ci)
>>   	return issued;
>>   }
>>   
>> -static inline int ceph_caps_issued_mask(struct ceph_inode_info *ci, int mask,
>> -					int touch)
>> +static inline int ceph_caps_issued_mask_metric(struct ceph_inode_info *ci,
>> +					       int mask, int touch)
>>   {
>>   	int r;
>>   	spin_lock(&ci->i_ceph_lock);
>> -	r = __ceph_caps_issued_mask(ci, mask, touch);
>> +	r = __ceph_caps_issued_mask_metric(ci, mask, touch);
>>   	spin_unlock(&ci->i_ceph_lock);
>>   	return r;
>>   }
>> diff --git a/fs/ceph/xattr.c b/fs/ceph/xattr.c
>> index 7b8a070a782d..71ee34d160c3 100644
>> --- a/fs/ceph/xattr.c
>> +++ b/fs/ceph/xattr.c
>> @@ -856,7 +856,7 @@ ssize_t __ceph_getxattr(struct inode *inode, const char *name, void *value,
>>   
>>   	if (ci->i_xattrs.version == 0 ||
>>   	    !((req_mask & CEPH_CAP_XATTR_SHARED) ||
>> -	      __ceph_caps_issued_mask(ci, CEPH_CAP_XATTR_SHARED, 1))) {
>> +	      __ceph_caps_issued_mask_metric(ci, CEPH_CAP_XATTR_SHARED, 1))) {
>>   		spin_unlock(&ci->i_ceph_lock);
>>   
>>   		/* security module gets xattr while filling trace */
>> @@ -914,7 +914,7 @@ ssize_t ceph_listxattr(struct dentry *dentry, char *names, size_t size)
>>   	     ci->i_xattrs.version, ci->i_xattrs.index_version);
>>   
>>   	if (ci->i_xattrs.version == 0 ||
>> -	    !__ceph_caps_issued_mask(ci, CEPH_CAP_XATTR_SHARED, 1)) {
>> +	    !__ceph_caps_issued_mask_metric(ci, CEPH_CAP_XATTR_SHARED, 1)) {
>>   		spin_unlock(&ci->i_ceph_lock);
>>   		err = ceph_do_getattr(inode, CEPH_STAT_CAP_XATTR, true);
>>   		if (err)

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: [PATCH v8 5/5] ceph: add global metadata perf metric support
  2020-02-22  1:20       ` Xiubo Li
  2020-02-22  1:36         ` Xiubo Li
@ 2020-02-24  9:56         ` Ilya Dryomov
  2020-02-24 10:20           ` Xiubo Li
  1 sibling, 1 reply; 16+ messages in thread
From: Ilya Dryomov @ 2020-02-24  9:56 UTC (permalink / raw)
  To: Xiubo Li
  Cc: Jeff Layton, Sage Weil, Yan, Zheng, Patrick Donnelly, Ceph Development

On Sat, Feb 22, 2020 at 2:21 AM Xiubo Li <xiubli@redhat.com> wrote:
>
> On 2020/2/21 22:56, Ilya Dryomov wrote:
> > On Fri, Feb 21, 2020 at 1:03 PM Jeff Layton <jlayton@kernel.org> wrote:
> >> On Fri, 2020-02-21 at 02:05 -0500, xiubli@redhat.com wrote:
> >>> From: Xiubo Li <xiubli@redhat.com>
> >>>
> >>> It will calculate the latency for the metedata requests, which only
> >>> include the time cousumed by network and the ceph.
> >>>
> >> "and the ceph MDS" ?
> >>
> >>> item          total       sum_lat(us)     avg_lat(us)
> >>> -----------------------------------------------------
> >>> metadata      113         220000          1946
> >>>
> >>> URL: https://tracker.ceph.com/issues/43215
> >>> Signed-off-by: Xiubo Li <xiubli@redhat.com>
> >>> ---
> >>>   fs/ceph/debugfs.c    |  6 ++++++
> >>>   fs/ceph/mds_client.c | 20 ++++++++++++++++++++
> >>>   fs/ceph/metric.h     | 13 +++++++++++++
> >>>   3 files changed, 39 insertions(+)
> >>>
> >>> diff --git a/fs/ceph/debugfs.c b/fs/ceph/debugfs.c
> >>> index 464bfbdb970d..60f3e307fca1 100644
> >>> --- a/fs/ceph/debugfs.c
> >>> +++ b/fs/ceph/debugfs.c
> >>> @@ -146,6 +146,12 @@ static int metric_show(struct seq_file *s, void *p)
> >>>        avg = total ? sum / total : 0;
> >>>        seq_printf(s, "%-14s%-12lld%-16lld%lld\n", "write", total, sum, avg);
> >>>
> >>> +     total = percpu_counter_sum(&mdsc->metric.total_metadatas);
> >>> +     sum = percpu_counter_sum(&mdsc->metric.metadata_latency_sum);
> >>> +     sum = jiffies_to_usecs(sum);
> >>> +     avg = total ? sum / total : 0;
> >>> +     seq_printf(s, "%-14s%-12lld%-16lld%lld\n", "metadata", total, sum, avg);
> >>> +
> >>>        seq_printf(s, "\n");
> >>>        seq_printf(s, "item          total           miss            hit\n");
> >>>        seq_printf(s, "-------------------------------------------------\n");
> >>> diff --git a/fs/ceph/mds_client.c b/fs/ceph/mds_client.c
> >>> index 0a3447966b26..3e792eca6af7 100644
> >>> --- a/fs/ceph/mds_client.c
> >>> +++ b/fs/ceph/mds_client.c
> >>> @@ -3017,6 +3017,12 @@ static void handle_reply(struct ceph_mds_session *session, struct ceph_msg *msg)
> >>>
> >>>        /* kick calling process */
> >>>        complete_request(mdsc, req);
> >>> +
> >>> +     if (!result || result == -ENOENT) {
> >>> +             s64 latency = jiffies - req->r_started;
> >>> +
> >>> +             ceph_update_metadata_latency(&mdsc->metric, latency);
> >>> +     }
> >> Should we add an r_end_stamp field to the mds request struct and use
> >> that to calculate this? Many jiffies may have passed between the reply
> >> coming in and this point. If you really want to measure the latency that
> >> would be more accurate, I think.
> > Yes, capturing it after invoking the callback is inconsistent
> > with what is done for OSD requests (the new r_end_stamp is set in
> > finish_request()).
> >
> > It looks like this is the only place where MDS r_end_stamp would be
> > needed, so perhaps just move this before complete_request() call?
>
> Currently for the OSD requests, they are almost in the same place where
> at the end of the handle_reply.

For OSD requests, r_end_request is captured _before_ the supplied
callback is invoked.  I suggest to do the same for MDS requests.

>
> If we don't want to calculate the consumption by the most of
> handle_reply code, we may set the r_end_stamp in the begin of it for
> both OSD/MDS requests ?
>
> I'm thinking since in the handle_reply, it may also wait for the mutex
> locks and then sleeps, so move the r_end_stamp to the beginning should
> make sense...

No, the time spent in handle_reply() must be included, just like the
time spent in submit_request() is included.  If you look at the code,
you will see that there is a case where handle_reply() drops the reply
on the floor and resubmits the OSD request.  Further, on many errors,
handle_reply() isn't even called, so finish_request() is the only place
where r_end_stamp can be captured in a consistent manner.

Thanks,

                Ilya

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: [PATCH v8 5/5] ceph: add global metadata perf metric support
  2020-02-24  9:56         ` Ilya Dryomov
@ 2020-02-24 10:20           ` Xiubo Li
  0 siblings, 0 replies; 16+ messages in thread
From: Xiubo Li @ 2020-02-24 10:20 UTC (permalink / raw)
  To: Ilya Dryomov
  Cc: Jeff Layton, Sage Weil, Yan, Zheng, Patrick Donnelly, Ceph Development

On 2020/2/24 17:56, Ilya Dryomov wrote:
> On Sat, Feb 22, 2020 at 2:21 AM Xiubo Li <xiubli@redhat.com> wrote:
>> On 2020/2/21 22:56, Ilya Dryomov wrote:
>>> On Fri, Feb 21, 2020 at 1:03 PM Jeff Layton <jlayton@kernel.org> wrote:
>>>> On Fri, 2020-02-21 at 02:05 -0500, xiubli@redhat.com wrote:
>>>>> From: Xiubo Li <xiubli@redhat.com>
>>>>>
>>>>> It will calculate the latency for the metedata requests, which only
>>>>> include the time cousumed by network and the ceph.
>>>>>
>>>> "and the ceph MDS" ?
>>>>
>>>>> item          total       sum_lat(us)     avg_lat(us)
>>>>> -----------------------------------------------------
>>>>> metadata      113         220000          1946
>>>>>
>>>>> URL: https://tracker.ceph.com/issues/43215
>>>>> Signed-off-by: Xiubo Li <xiubli@redhat.com>
>>>>> ---
>>>>>    fs/ceph/debugfs.c    |  6 ++++++
>>>>>    fs/ceph/mds_client.c | 20 ++++++++++++++++++++
>>>>>    fs/ceph/metric.h     | 13 +++++++++++++
>>>>>    3 files changed, 39 insertions(+)
>>>>>
>>>>> diff --git a/fs/ceph/debugfs.c b/fs/ceph/debugfs.c
>>>>> index 464bfbdb970d..60f3e307fca1 100644
>>>>> --- a/fs/ceph/debugfs.c
>>>>> +++ b/fs/ceph/debugfs.c
>>>>> @@ -146,6 +146,12 @@ static int metric_show(struct seq_file *s, void *p)
>>>>>         avg = total ? sum / total : 0;
>>>>>         seq_printf(s, "%-14s%-12lld%-16lld%lld\n", "write", total, sum, avg);
>>>>>
>>>>> +     total = percpu_counter_sum(&mdsc->metric.total_metadatas);
>>>>> +     sum = percpu_counter_sum(&mdsc->metric.metadata_latency_sum);
>>>>> +     sum = jiffies_to_usecs(sum);
>>>>> +     avg = total ? sum / total : 0;
>>>>> +     seq_printf(s, "%-14s%-12lld%-16lld%lld\n", "metadata", total, sum, avg);
>>>>> +
>>>>>         seq_printf(s, "\n");
>>>>>         seq_printf(s, "item          total           miss            hit\n");
>>>>>         seq_printf(s, "-------------------------------------------------\n");
>>>>> diff --git a/fs/ceph/mds_client.c b/fs/ceph/mds_client.c
>>>>> index 0a3447966b26..3e792eca6af7 100644
>>>>> --- a/fs/ceph/mds_client.c
>>>>> +++ b/fs/ceph/mds_client.c
>>>>> @@ -3017,6 +3017,12 @@ static void handle_reply(struct ceph_mds_session *session, struct ceph_msg *msg)
>>>>>
>>>>>         /* kick calling process */
>>>>>         complete_request(mdsc, req);
>>>>> +
>>>>> +     if (!result || result == -ENOENT) {
>>>>> +             s64 latency = jiffies - req->r_started;
>>>>> +
>>>>> +             ceph_update_metadata_latency(&mdsc->metric, latency);
>>>>> +     }
>>>> Should we add an r_end_stamp field to the mds request struct and use
>>>> that to calculate this? Many jiffies may have passed between the reply
>>>> coming in and this point. If you really want to measure the latency that
>>>> would be more accurate, I think.
>>> Yes, capturing it after invoking the callback is inconsistent
>>> with what is done for OSD requests (the new r_end_stamp is set in
>>> finish_request()).
>>>
>>> It looks like this is the only place where MDS r_end_stamp would be
>>> needed, so perhaps just move this before complete_request() call?
>> Currently for the OSD requests, they are almost in the same place where
>> at the end of the handle_reply.
> For OSD requests, r_end_request is captured _before_ the supplied
> callback is invoked.  I suggest to do the same for MDS requests.

Will do it in complete_request() for MDS case, there is no finish_request().


>> If we don't want to calculate the consumption by the most of
>> handle_reply code, we may set the r_end_stamp in the begin of it for
>> both OSD/MDS requests ?
>>
>> I'm thinking since in the handle_reply, it may also wait for the mutex
>> locks and then sleeps, so move the r_end_stamp to the beginning should
>> make sense...
> No, the time spent in handle_reply() must be included, just like the
> time spent in submit_request() is included.  If you look at the code,
> you will see that there is a case where handle_reply() drops the reply
> on the floor and resubmits the OSD request.  Further, on many errors,
> handle_reply() isn't even called, so finish_request() is the only place
> where r_end_stamp can be captured in a consistent manner.

Okay, get it.

Thanks Ilya.

BRs


> Thanks,
>
>                  Ilya
>

^ permalink raw reply	[flat|nested] 16+ messages in thread

* Re: [PATCH v8 2/5] ceph: add caps perf metric for each session
  2020-02-22  1:51     ` Xiubo Li
@ 2020-02-26  3:05       ` Jeff Layton
  0 siblings, 0 replies; 16+ messages in thread
From: Jeff Layton @ 2020-02-26  3:05 UTC (permalink / raw)
  To: Xiubo Li, idryomov; +Cc: sage, zyan, pdonnell, ceph-devel

On Sat, 2020-02-22 at 09:51 +0800, Xiubo Li wrote:
> On 2020/2/21 20:00, Jeff Layton wrote:
> > On Fri, 2020-02-21 at 02:05 -0500, xiubli@redhat.com wrote:
> > > From: Xiubo Li <xiubli@redhat.com>
> > > 
> > > This will fulfill the cap hit/mis metric stuff per-superblock,
> > > it will count the hit/mis counters based each inode, and if one
> > > inode's 'issued & ~revoking == mask' will mean a hit, or a miss.
> > > 
> > > item          total           miss            hit
> > > -------------------------------------------------
> > > caps          295             107             4119
> > > 
> > > URL: https://tracker.ceph.com/issues/43215
> > > Signed-off-by: Xiubo Li <xiubli@redhat.com>
> > > ---
> > >   fs/ceph/acl.c        |  2 +-
> > >   fs/ceph/caps.c       | 19 +++++++++++++++++++
> > >   fs/ceph/debugfs.c    | 16 ++++++++++++++++
> > >   fs/ceph/dir.c        |  5 +++--
> > >   fs/ceph/inode.c      |  4 ++--
> > >   fs/ceph/mds_client.c | 26 ++++++++++++++++++++++----
> > >   fs/ceph/metric.h     | 19 +++++++++++++++++++
> > >   fs/ceph/super.h      |  8 +++++---
> > >   fs/ceph/xattr.c      |  4 ++--
> > >   9 files changed, 89 insertions(+), 14 deletions(-)
> > > 
> > > diff --git a/fs/ceph/acl.c b/fs/ceph/acl.c
> > > index 26be6520d3fb..e0465741c591 100644
> > > --- a/fs/ceph/acl.c
> > > +++ b/fs/ceph/acl.c
> > > @@ -22,7 +22,7 @@ static inline void ceph_set_cached_acl(struct inode *inode,
> > >   	struct ceph_inode_info *ci = ceph_inode(inode);
> > >   
> > >   	spin_lock(&ci->i_ceph_lock);
> > > -	if (__ceph_caps_issued_mask(ci, CEPH_CAP_XATTR_SHARED, 0))
> > > +	if (__ceph_caps_issued_mask_metric(ci, CEPH_CAP_XATTR_SHARED, 0))
> > >   		set_cached_acl(inode, type, acl);
> > >   	else
> > >   		forget_cached_acl(inode, type);
> > nit: calling __ceph_caps_issued_mask_metric means that you have an extra
> > branch. One to set/forget acl and one to update the counter.
> > 
> > This would be (very slightly) more efficient if you just put the cap
> > hit/miss calls inside the existing if block above. IOW, you could just
> > do:
> > 
> > if (__ceph_caps_issued_mask(ci, CEPH_CAP_XATTR_SHARED, 0)) {
> > 	set_cached_acl(inode, type, acl);
> > 	ceph_update_cap_hit(&fsc->mdsc->metric);
> > } else {
> > 	forget_cached_acl(inode, type);
> > 	ceph_update_cap_mis(&fsc->mdsc->metric);
> > }
> 
> Yeah, this will works well here.
> 
> 
> > > diff --git a/fs/ceph/dir.c b/fs/ceph/dir.c
> > > index ff1714fe03aa..227949c3deb8 100644
> > > --- a/fs/ceph/dir.c
> > > +++ b/fs/ceph/dir.c
> > > @@ -346,8 +346,9 @@ static int ceph_readdir(struct file *file, struct dir_context *ctx)
> > >   	    !ceph_test_mount_opt(fsc, NOASYNCREADDIR) &&
> > >   	    ceph_snap(inode) != CEPH_SNAPDIR &&
> > >   	    __ceph_dir_is_complete_ordered(ci) &&
> > > -	    __ceph_caps_issued_mask(ci, CEPH_CAP_FILE_SHARED, 1)) {
> > > +	    __ceph_caps_issued_mask_metric(ci, CEPH_CAP_FILE_SHARED, 1)) {
> > These could also just be cap_hit/mis calls inside the existing if
> > blocks.
> 
> Yeah, right in the if branch we can be sure that the 
> __ceph_caps_issued_mask() is called. But in the else branch we still 
> need to get the return value from (rc = __ceph_caps_issued_mask()), and 
> only when "rc == 0" cap_mis will need. This could simplify the code here 
> and below.
> 
> This is main reason to add the __ceph_caps_issued_mask_metric() here. 
> And if you do not like this approach I will switch it back :-)
> 

Ok, good point. Let's leave this one as-is.

-- 
Jeff Layton <jlayton@kernel.org>

^ permalink raw reply	[flat|nested] 16+ messages in thread

end of thread, other threads:[~2020-02-26  3:05 UTC | newest]

Thread overview: 16+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2020-02-21  7:05 [PATCH v8 0/5] ceph: add perf metrics support xiubli
2020-02-21  7:05 ` [PATCH v8 1/5] ceph: add global dentry lease metric support xiubli
2020-02-21  7:05 ` [PATCH v8 2/5] ceph: add caps perf metric for each session xiubli
2020-02-21 12:00   ` Jeff Layton
2020-02-22  1:51     ` Xiubo Li
2020-02-26  3:05       ` Jeff Layton
2020-02-21  7:05 ` [PATCH v8 3/5] ceph: add global read latency metric support xiubli
2020-02-21  7:05 ` [PATCH v8 4/5] ceph: add global write " xiubli
2020-02-21  7:05 ` [PATCH v8 5/5] ceph: add global metadata perf " xiubli
2020-02-21 12:03   ` Jeff Layton
2020-02-21 14:56     ` Ilya Dryomov
2020-02-22  1:20       ` Xiubo Li
2020-02-22  1:36         ` Xiubo Li
2020-02-24  9:56         ` Ilya Dryomov
2020-02-24 10:20           ` Xiubo Li
2020-02-22  1:09     ` Xiubo Li

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.