On Fri, Feb 21, 2020 at 1:03 PM Jeff Layton <jlayton@xxxxxxxxxx> wrote: > > On Fri, 2020-02-21 at 02:05 -0500, xiubli@xxxxxxxxxx wrote: > > From: Xiubo Li <xiubli@xxxxxxxxxx> > > > > 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@xxxxxxxxxx> > > --- > > 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
