From cd8fb1e8d300c0622200d6b25d187d8d0472e79f Mon Sep 17 00:00:00 2001 From: Emoly Liu Date: Wed, 3 Jun 2020 18:48:00 +0800 Subject: [PATCH] LU-13597 ofd: add more information to job_stats Request processing times/latency and basic IO size information is added to the job_stats output. This allows monitoring per-job request processing performance. Except read_bytes and write_bytes in bytes units, all the others use "usecs" units and show min/max/sum values. What's more, two new counters for read and write time are added to calculate bandwidth. The output format is like: write_bytes: { samples: 1, unit: bytes, min: x, max: x, sum: x, sumsq: x} sanity.sh test_205b is modified to verify this patch. Signed-off-by: Emoly Liu Change-Id: I7a5b77ca0ba464f6330a4bc56735c7762e167019 Reviewed-on: https://review.whamcloud.com/38816 Tested-by: jenkins Reviewed-by: Andreas Dilger Reviewed-by: Wang Shilong Tested-by: Maloo Reviewed-by: Oleg Drokin --- lustre/include/lprocfs_status.h | 11 ++++++-- lustre/llite/lproc_llite.c | 8 ++---- lustre/mdt/mdt_fs.c | 2 +- lustre/mdt/mdt_handler.c | 12 ++++++--- lustre/mdt/mdt_internal.h | 7 ++--- lustre/mdt/mdt_io.c | 20 +++++++------- lustre/mdt/mdt_lproc.c | 55 +++++++++++++++++--------------------- lustre/mdt/mdt_open.c | 14 +++++++--- lustre/mdt/mdt_reint.c | 37 ++++++++++++++++++------- lustre/mdt/mdt_xattr.c | 8 ++++-- lustre/obdclass/lprocfs_jobstats.c | 2 +- lustre/ofd/lproc_ofd.c | 34 ++++++++++++----------- lustre/ofd/ofd_dev.c | 39 +++++++++++++++++---------- lustre/ofd/ofd_internal.h | 9 ++++--- lustre/ofd/ofd_io.c | 10 +++++-- lustre/ofd/ofd_obd.c | 6 +++-- lustre/tests/sanity.sh | 14 ++++++---- 17 files changed, 176 insertions(+), 112 deletions(-) diff --git a/lustre/include/lprocfs_status.h b/lustre/include/lprocfs_status.h index af4c89a..55af6cd 100644 --- a/lustre/include/lprocfs_status.h +++ b/lustre/include/lprocfs_status.h @@ -154,8 +154,14 @@ enum { LPROCFS_TYPE_BYTES = 0x0200, LPROCFS_TYPE_PAGES = 0x0400, LPROCFS_TYPE_USEC = 0x0800, -}; + LPROCFS_TYPE_LATENCY = LPROCFS_TYPE_USEC | + LPROCFS_CNTR_AVGMINMAX | + LPROCFS_CNTR_STDDEV, + LPROCFS_TYPE_BYTES_FULL = LPROCFS_TYPE_BYTES | + LPROCFS_CNTR_AVGMINMAX | + LPROCFS_CNTR_STDDEV, +}; #define LC_MIN_INIT ((~(__u64)0) >> 1) struct lprocfs_counter_header { @@ -395,7 +401,8 @@ struct obd_histogram; #define JOBSTATS_NODELOCAL "nodelocal" #define JOBSTATS_SESSION "session" -typedef void (*cntr_init_callback)(struct lprocfs_stats *stats); +typedef void (*cntr_init_callback)(struct lprocfs_stats *stats, + unsigned int offset); struct obd_job_stats { struct cfs_hash *ojs_hash; /* hash of jobids */ diff --git a/lustre/llite/lproc_llite.c b/lustre/llite/lproc_llite.c index 55b15b5..79f352f 100644 --- a/lustre/llite/lproc_llite.c +++ b/lustre/llite/lproc_llite.c @@ -1537,18 +1537,14 @@ static struct kobj_type sbi_ktype = { .release = sbi_kobj_release, }; -#define LPROCFS_TYPE_LATENCY \ - (LPROCFS_TYPE_USEC | LPROCFS_CNTR_AVGMINMAX | LPROCFS_CNTR_STDDEV) static const struct llite_file_opcode { __u32 opcode; __u32 type; const char *opname; } llite_opcode_table[LPROC_LL_FILE_OPCODES] = { /* file operation */ - { LPROC_LL_READ_BYTES, LPROCFS_CNTR_AVGMINMAX | LPROCFS_TYPE_BYTES, - "read_bytes" }, - { LPROC_LL_WRITE_BYTES, LPROCFS_CNTR_AVGMINMAX | LPROCFS_TYPE_BYTES, - "write_bytes" }, + { LPROC_LL_READ_BYTES, LPROCFS_TYPE_BYTES_FULL, "read_bytes" }, + { LPROC_LL_WRITE_BYTES, LPROCFS_TYPE_BYTES_FULL, "write_bytes" }, { LPROC_LL_READ, LPROCFS_TYPE_LATENCY, "read" }, { LPROC_LL_WRITE, LPROCFS_TYPE_LATENCY, "write" }, { LPROC_LL_IOCTL, LPROCFS_TYPE_REQS, "ioctl" }, diff --git a/lustre/mdt/mdt_fs.c b/lustre/mdt/mdt_fs.c index 862d19a..90c0269 100644 --- a/lustre/mdt/mdt_fs.c +++ b/lustre/mdt/mdt_fs.c @@ -78,7 +78,7 @@ int mdt_export_stats_init(struct obd_device *obd, struct obd_export *exp, if (stats->nid_stats == NULL) RETURN(-ENOMEM); - mdt_stats_counter_init(stats->nid_stats); + mdt_stats_counter_init(stats->nid_stats, 0); rc = lprocfs_register_stats(stats->nid_proc, "stats", stats->nid_stats); if (rc != 0) { diff --git a/lustre/mdt/mdt_handler.c b/lustre/mdt/mdt_handler.c index 91920b3..7b4bc0f 100644 --- a/lustre/mdt/mdt_handler.c +++ b/lustre/mdt/mdt_handler.c @@ -415,6 +415,7 @@ static int mdt_statfs(struct tgt_session_info *tsi) struct obd_statfs *osfs; struct mdt_body *reqbody = NULL; struct mdt_statfs_cache *msf; + ktime_t kstart = ktime_get(); int rc; ENTRY; @@ -504,7 +505,8 @@ static int mdt_statfs(struct tgt_session_info *tsi) osfs->os_bsize = 1 << COMPAT_BSIZE_SHIFT; } if (rc == 0) - mdt_counter_incr(req, LPROC_MDT_STATFS); + mdt_counter_incr(req, LPROC_MDT_STATFS, + ktime_us_delta(ktime_get(), kstart)); out: mdt_thread_info_fini(info); RETURN(rc); @@ -1295,6 +1297,7 @@ static int mdt_getattr_internal(struct mdt_thread_info *info, struct mdt_body *repbody; struct lu_buf *buffer = &info->mti_buf; struct obd_export *exp = info->mti_exp; + ktime_t kstart = ktime_get(); int rc; ENTRY; @@ -1533,7 +1536,8 @@ static int mdt_getattr_internal(struct mdt_thread_info *info, out: if (rc == 0) - mdt_counter_incr(req, LPROC_MDT_GETATTR); + mdt_counter_incr(req, LPROC_MDT_GETATTR, + ktime_us_delta(ktime_get(), kstart)); RETURN(rc); } @@ -2783,6 +2787,7 @@ static int mdt_sync(struct tgt_session_info *tsi) struct ptlrpc_request *req = tgt_ses_req(tsi); struct req_capsule *pill = tsi->tsi_pill; struct mdt_body *body; + ktime_t kstart = ktime_get(); int rc; ENTRY; @@ -2819,7 +2824,8 @@ static int mdt_sync(struct tgt_session_info *tsi) mdt_thread_info_fini(info); } if (rc == 0) - mdt_counter_incr(req, LPROC_MDT_SYNC); + mdt_counter_incr(req, LPROC_MDT_SYNC, + ktime_us_delta(ktime_get(), kstart)); RETURN(rc); } diff --git a/lustre/mdt/mdt_internal.h b/lustre/mdt/mdt_internal.h index f712f00..5f099bc 100644 --- a/lustre/mdt/mdt_internal.h +++ b/lustre/mdt/mdt_internal.h @@ -1298,8 +1298,8 @@ enum mdt_stat_idx { LPROC_MDT_LAST, }; -void mdt_counter_incr(struct ptlrpc_request *req, int opcode); -void mdt_stats_counter_init(struct lprocfs_stats *stats); +void mdt_counter_incr(struct ptlrpc_request *req, int opcode, long amount); +void mdt_stats_counter_init(struct lprocfs_stats *stats, unsigned int offset); int mdt_tunables_init(struct mdt_device *mdt, const char *name); void mdt_tunables_fini(struct mdt_device *mdt); @@ -1309,7 +1309,8 @@ int lprocfs_mdt_open_files_seq_open(struct inode *inode, void mdt_rename_counter_tally(struct mdt_thread_info *info, struct mdt_device *mdt, struct ptlrpc_request *req, - struct mdt_object *src, struct mdt_object *tgt); + struct mdt_object *src, struct mdt_object *tgt, + long count); static inline struct obd_device *mdt2obd_dev(const struct mdt_device *mdt) { diff --git a/lustre/mdt/mdt_io.c b/lustre/mdt/mdt_io.c index e67b73b..04cfe5d 100644 --- a/lustre/mdt/mdt_io.c +++ b/lustre/mdt/mdt_io.c @@ -35,12 +35,6 @@ /* functions below are stubs for now, they will be implemented with * grant support on MDT */ -static inline void mdt_io_counter_incr(struct obd_export *exp, int opcode, - char *jobid, long amount) -{ - return; -} - static inline void mdt_dom_read_lock(struct mdt_object *mo) { down_read(&mo->mot_dom_sem); @@ -364,6 +358,8 @@ static int mdt_preprw_read(const struct lu_env *env, struct obd_export *exp, struct niobuf_remote *rnb, int *nr_local, struct niobuf_local *lnb, char *jobid) { + struct tgt_session_info *tsi = tgt_ses_info(env); + struct ptlrpc_request *req = tgt_ses_req(tsi); struct dt_object *dob; int i, j, rc, tot_bytes = 0; int maxlnb = *nr_local; @@ -422,7 +418,7 @@ static int mdt_preprw_read(const struct lu_env *env, struct obd_export *exp, if (unlikely(rc)) GOTO(buf_put, rc); - mdt_io_counter_incr(exp, LPROC_MDT_IO_READ, jobid, tot_bytes); + mdt_counter_incr(req, LPROC_MDT_IO_READ, tot_bytes); RETURN(0); buf_put: dt_bufs_put(env, dob, lnb, *nr_local); @@ -437,6 +433,8 @@ static int mdt_preprw_write(const struct lu_env *env, struct obd_export *exp, struct niobuf_remote *rnb, int *nr_local, struct niobuf_local *lnb, char *jobid) { + struct tgt_session_info *tsi = tgt_ses_info(env); + struct ptlrpc_request *req = tgt_ses_req(tsi); struct dt_object *dob; int i, j, k, rc = 0, tot_bytes = 0; int maxlnb = *nr_local; @@ -496,7 +494,7 @@ static int mdt_preprw_write(const struct lu_env *env, struct obd_export *exp, if (likely(rc)) GOTO(err, rc); - mdt_io_counter_incr(exp, LPROC_MDT_IO_WRITE, jobid, tot_bytes); + mdt_counter_incr(req, LPROC_MDT_IO_WRITE, tot_bytes); RETURN(0); err: dt_bufs_put(env, dob, lnb, *nr_local); @@ -849,6 +847,7 @@ stop: int mdt_punch_hdl(struct tgt_session_info *tsi) { const struct obdo *oa = &tsi->tsi_ost_body->oa; + struct ptlrpc_request *req = tgt_ses_req(tsi); struct ost_body *repbody; struct mdt_thread_info *info; struct lu_attr *la; @@ -859,6 +858,7 @@ int mdt_punch_hdl(struct tgt_session_info *tsi) struct dt_object *dob; __u64 flags = 0; struct lustre_handle lh = { 0, }; + ktime_t kstart = ktime_get(); __u64 start, end; int rc; bool srvlock; @@ -942,8 +942,8 @@ int mdt_punch_hdl(struct tgt_session_info *tsi) GOTO(out_put, rc); mdt_dom_obj_lvb_update(tsi->tsi_env, mo, false); - mdt_io_counter_incr(tsi->tsi_exp, LPROC_MDT_IO_PUNCH, - tsi->tsi_jobid, 1); + mdt_counter_incr(req, LPROC_MDT_IO_PUNCH, + ktime_us_delta(ktime_get(), kstart)); EXIT; out_put: lu_object_put(tsi->tsi_env, &mo->mot_obj); diff --git a/lustre/mdt/mdt_lproc.c b/lustre/mdt/mdt_lproc.c index e483884..452c7cc 100644 --- a/lustre/mdt/mdt_lproc.c +++ b/lustre/mdt/mdt_lproc.c @@ -165,7 +165,7 @@ void mdt_rename_counter_tally(struct mdt_thread_info *info, struct mdt_device *mdt, struct ptlrpc_request *req, struct mdt_object *src, - struct mdt_object *tgt) + struct mdt_object *tgt, long count) { struct md_attr *ma = &info->mti_attr; struct rename_stats *rstats = &mdt->mdt_rename_stats; @@ -181,13 +181,13 @@ void mdt_rename_counter_tally(struct mdt_thread_info *info, } if (src == tgt) { - mdt_counter_incr(req, LPROC_MDT_SAMEDIR_RENAME); + mdt_counter_incr(req, LPROC_MDT_SAMEDIR_RENAME, count); lprocfs_oh_tally_log2(&rstats->hist[RENAME_SAMEDIR_SIZE], (unsigned int)ma->ma_attr.la_size); return; } - mdt_counter_incr(req, LPROC_MDT_CROSSDIR_RENAME); + mdt_counter_incr(req, LPROC_MDT_CROSSDIR_RENAME, count); lprocfs_oh_tally_log2(&rstats->hist[RENAME_CROSSDIR_SRC_SIZE], (unsigned int)ma->ma_attr.la_size); @@ -1346,20 +1346,21 @@ int lprocfs_mdt_open_files_seq_open(struct inode *inode, struct file *file) return 0; } -void mdt_counter_incr(struct ptlrpc_request *req, int opcode) +void mdt_counter_incr(struct ptlrpc_request *req, int opcode, long amount) { struct obd_export *exp = req->rq_export; if (exp->exp_obd && exp->exp_obd->obd_md_stats) - lprocfs_counter_incr(exp->exp_obd->obd_md_stats, - opcode + LPROC_MD_LAST_OPC); + lprocfs_counter_add(exp->exp_obd->obd_md_stats, + opcode + LPROC_MD_LAST_OPC, amount); if (exp->exp_nid_stats && exp->exp_nid_stats->nid_stats != NULL) - lprocfs_counter_incr(exp->exp_nid_stats->nid_stats, opcode); + lprocfs_counter_add(exp->exp_nid_stats->nid_stats, opcode, + amount); if (exp->exp_obd && exp->exp_obd->u.obt.obt_jobstats.ojs_hash && (exp_connect_flags(exp) & OBD_CONNECT_JOBSTATS)) lprocfs_job_stats_log(exp->exp_obd, lustre_msg_get_jobid(req->rq_reqmsg), - opcode, 1); + opcode, amount); } static const char * const mdt_stats[] = { @@ -1385,19 +1386,24 @@ static const char * const mdt_stats[] = { [LPROC_MDT_MIGRATE] = "migrate", }; -void mdt_stats_counter_init(struct lprocfs_stats *stats) +void mdt_stats_counter_init(struct lprocfs_stats *stats, unsigned int offset) { - int idx; + int array_size = ARRAY_SIZE(mdt_stats); + int oidx; /* obd_md_stats index */ + int midx; /* mdt_stats index */ - LASSERT(stats && stats->ls_num >= ARRAY_SIZE(mdt_stats)); + LASSERT(stats && stats->ls_num >= offset + array_size); - for (idx = 0; idx < ARRAY_SIZE(mdt_stats); idx++) { - int flags = 0; - - if (idx == LPROC_MDT_IO_WRITE || idx == LPROC_MDT_IO_READ) - flags = LPROCFS_CNTR_AVGMINMAX; - - lprocfs_counter_init(stats, idx, flags, mdt_stats[idx], "reqs"); + for (midx = 0; midx < array_size; midx++) { + oidx = midx + offset; + if (midx == LPROC_MDT_IO_READ || midx == LPROC_MDT_IO_WRITE) + lprocfs_counter_init(stats, oidx, + LPROCFS_TYPE_BYTES_FULL, + mdt_stats[midx], "bytes"); + else + lprocfs_counter_init(stats, oidx, + LPROCFS_TYPE_LATENCY, + mdt_stats[midx], "usecs"); } } @@ -1405,7 +1411,6 @@ int mdt_tunables_init(struct mdt_device *mdt, const char *name) { struct obd_device *obd = mdt2obd_dev(mdt); int rc; - int i; ENTRY; LASSERT(name != NULL); @@ -1444,17 +1449,7 @@ int mdt_tunables_init(struct mdt_device *mdt, const char *name) return rc; /* add additional MDT md_stats after the default ones */ - for (i = 0; i < ARRAY_SIZE(mdt_stats); i++) { - int idx = i + LPROC_MD_LAST_OPC; - int flags = 0; - - if (idx == LPROC_MDT_IO_WRITE || idx == LPROC_MDT_IO_READ) - flags = LPROCFS_CNTR_AVGMINMAX; - - lprocfs_counter_init(obd->obd_md_stats, idx, flags, - mdt_stats[i], "reqs"); - } - + mdt_stats_counter_init(obd->obd_md_stats, LPROC_MD_LAST_OPC); rc = lprocfs_job_stats_init(obd, ARRAY_SIZE(mdt_stats), mdt_stats_counter_init); diff --git a/lustre/mdt/mdt_open.c b/lustre/mdt/mdt_open.c index 5f557d1..bb46c20 100644 --- a/lustre/mdt/mdt_open.c +++ b/lustre/mdt/mdt_open.c @@ -1318,12 +1318,12 @@ int mdt_reint_open(struct mdt_thread_info *info, struct mdt_lock_handle *lhc) int created = 0; int object_locked = 0; u32 msg_flags; + ktime_t kstart = ktime_get(); ENTRY; OBD_FAIL_TIMEOUT_ORSET(OBD_FAIL_MDS_PAUSE_OPEN, OBD_FAIL_ONCE, (obd_timeout + 1) / 4); - mdt_counter_incr(req, LPROC_MDT_OPEN); repbody = req_capsule_server_get(info->mti_pill, &RMF_MDT_BODY); ma->ma_need = MA_INODE; @@ -1497,7 +1497,8 @@ int mdt_reint_open(struct mdt_thread_info *info, struct mdt_lock_handle *lhc) GOTO(out_child, result); } created = 1; - mdt_counter_incr(req, LPROC_MDT_MKNOD); + mdt_counter_incr(req, LPROC_MDT_MKNOD, + ktime_us_delta(ktime_get(), kstart)); } else { /* * The object is on remote node, return its FID for remote open. @@ -1603,6 +1604,10 @@ int mdt_reint_open(struct mdt_thread_info *info, struct mdt_lock_handle *lhc) mdt_clear_disposition(info, ldlm_rep, DISP_OPEN_CREATE); } } + + mdt_counter_incr(req, LPROC_MDT_OPEN, + ktime_us_delta(ktime_get(), kstart)); + EXIT; out_child_unlock: if (object_locked) @@ -2440,10 +2445,10 @@ int mdt_close(struct tgt_session_info *tsi) struct ptlrpc_request *req = tgt_ses_req(tsi); struct md_attr *ma = &info->mti_attr; struct mdt_body *repbody = NULL; + ktime_t kstart = ktime_get(); int rc, ret = 0; ENTRY; - mdt_counter_incr(req, LPROC_MDT_CLOSE); /* Close may come with the Size-on-MDS update. Unpack it. */ rc = mdt_close_unpack(info); if (rc) @@ -2498,5 +2503,8 @@ int mdt_close(struct tgt_session_info *tsi) tsi->tsi_reply_fail_id = OBD_FAIL_MDS_CLOSE_NET_REP; out: mdt_thread_info_fini(info); + if (rc == 0) + mdt_counter_incr(req, LPROC_MDT_CLOSE, + ktime_us_delta(ktime_get(), kstart)); RETURN(rc ? rc : ret); } diff --git a/lustre/mdt/mdt_reint.c b/lustre/mdt/mdt_reint.c index c64abaa..7314162 100644 --- a/lustre/mdt/mdt_reint.c +++ b/lustre/mdt/mdt_reint.c @@ -789,6 +789,7 @@ static int mdt_reint_setattr(struct mdt_thread_info *info, struct ptlrpc_request *req = mdt_info_req(info); struct mdt_object *mo; struct mdt_body *repbody; + ktime_t kstart = ktime_get(); int rc, rc2; ENTRY; @@ -958,7 +959,8 @@ out_put: mdt_object_put(info->mti_env, mo); out: if (rc == 0) - mdt_counter_incr(req, LPROC_MDT_SETATTR); + mdt_counter_incr(req, LPROC_MDT_SETATTR, + ktime_us_delta(ktime_get(), kstart)); mdt_client_compatibility(info); rc2 = mdt_fix_reply(info); @@ -971,6 +973,7 @@ static int mdt_reint_create(struct mdt_thread_info *info, struct mdt_lock_handle *lhc) { struct ptlrpc_request *req = mdt_info_req(info); + ktime_t kstart = ktime_get(); int rc; ENTRY; @@ -986,16 +989,12 @@ static int mdt_reint_create(struct mdt_thread_info *info, switch (info->mti_attr.ma_attr.la_mode & S_IFMT) { case S_IFDIR: - mdt_counter_incr(req, LPROC_MDT_MKDIR); - break; case S_IFREG: case S_IFLNK: case S_IFCHR: case S_IFBLK: case S_IFIFO: case S_IFSOCK: - /* Special file should stay on the same node as parent. */ - mdt_counter_incr(req, LPROC_MDT_MKNOD); break; default: CERROR("%s: Unsupported mode %o\n", @@ -1005,6 +1004,16 @@ static int mdt_reint_create(struct mdt_thread_info *info, } rc = mdt_create(info); + if (rc == 0) { + if ((info->mti_attr.ma_attr.la_mode & S_IFMT) == S_IFDIR) + mdt_counter_incr(req, LPROC_MDT_MKDIR, + ktime_us_delta(ktime_get(), kstart)); + else + /* Special file should stay on the same node as parent*/ + mdt_counter_incr(req, LPROC_MDT_MKNOD, + ktime_us_delta(ktime_get(), kstart)); + } + RETURN(rc); } @@ -1027,6 +1036,7 @@ static int mdt_reint_unlink(struct mdt_thread_info *info, __u64 lock_ibits; bool cos_incompat = false; int no_name = 0; + ktime_t kstart = ktime_get(); int rc; ENTRY; @@ -1216,7 +1226,8 @@ out_stat: if (ma->ma_valid & MA_INODE) { switch (ma->ma_attr.la_mode & S_IFMT) { case S_IFDIR: - mdt_counter_incr(req, LPROC_MDT_RMDIR); + mdt_counter_incr(req, LPROC_MDT_RMDIR, + ktime_us_delta(ktime_get(), kstart)); break; case S_IFREG: case S_IFLNK: @@ -1224,7 +1235,8 @@ out_stat: case S_IFBLK: case S_IFIFO: case S_IFSOCK: - mdt_counter_incr(req, LPROC_MDT_UNLINK); + mdt_counter_incr(req, LPROC_MDT_UNLINK, + ktime_us_delta(ktime_get(), kstart)); break; default: LASSERTF(0, "bad file type %o unlinking\n", @@ -1260,6 +1272,7 @@ static int mdt_reint_link(struct mdt_thread_info *info, struct mdt_object *mp; struct mdt_lock_handle *lhs; struct mdt_lock_handle *lhp; + ktime_t kstart = ktime_get(); bool cos_incompat; int rc; @@ -1356,7 +1369,8 @@ static int mdt_reint_link(struct mdt_thread_info *info, mdt_object_child(ms), &rr->rr_name, ma); if (rc == 0) - mdt_counter_incr(req, LPROC_MDT_LINK); + mdt_counter_incr(req, LPROC_MDT_LINK, + ktime_us_delta(ktime_get(), kstart)); EXIT; unlock_source: @@ -2460,6 +2474,7 @@ static int mdt_reint_rename(struct mdt_thread_info *info, __u64 lock_ibits; bool reverse = false, discard = false; bool cos_incompat; + ktime_t kstart = ktime_get(); int rc; ENTRY; @@ -2783,13 +2798,15 @@ relock: /* handle last link of tgt object */ if (rc == 0) { - mdt_counter_incr(req, LPROC_MDT_RENAME); + mdt_counter_incr(req, LPROC_MDT_RENAME, + ktime_us_delta(ktime_get(), kstart)); if (mnew) { mdt_handle_last_unlink(info, mnew, ma); discard = mdt_dom_check_for_discard(info, mnew); } mdt_rename_counter_tally(info, info->mti_mdt, req, - msrcdir, mtgtdir); + msrcdir, mtgtdir, + ktime_us_delta(ktime_get(), kstart)); } EXIT; diff --git a/lustre/mdt/mdt_xattr.c b/lustre/mdt/mdt_xattr.c index 04aee19..7d78be8 100644 --- a/lustre/mdt/mdt_xattr.c +++ b/lustre/mdt/mdt_xattr.c @@ -244,6 +244,7 @@ int mdt_getxattr(struct mdt_thread_info *info) struct lu_buf *buf; int easize, rc; u64 valid; + ktime_t kstart = ktime_get(); ENTRY; LASSERT(info->mti_object != NULL); @@ -307,7 +308,8 @@ int mdt_getxattr(struct mdt_thread_info *info) EXIT; out: if (rc >= 0) { - mdt_counter_incr(req, LPROC_MDT_GETXATTR); + mdt_counter_incr(req, LPROC_MDT_GETXATTR, + ktime_us_delta(ktime_get(), kstart)); /* LU-11109: Set OBD_MD_FLXATTR on success so that * newer clients can distinguish between nonexistent * xattrs and zero length values. @@ -536,6 +538,7 @@ int mdt_reint_setxattr(struct mdt_thread_info *info, const char *xattr_name = rr->rr_name.ln_name; int xattr_len = rr->rr_eadatalen; __u64 lockpart = MDS_INODELOCK_UPDATE; + ktime_t kstart = ktime_get(); int rc; ENTRY; @@ -684,7 +687,8 @@ int mdt_reint_setxattr(struct mdt_thread_info *info, } if (rc == 0) - mdt_counter_incr(req, LPROC_MDT_SETXATTR); + mdt_counter_incr(req, LPROC_MDT_SETXATTR, + ktime_us_delta(ktime_get(), kstart)); EXIT; out_unlock: diff --git a/lustre/obdclass/lprocfs_jobstats.c b/lustre/obdclass/lprocfs_jobstats.c index e4aad7f..93ba6e6 100644 --- a/lustre/obdclass/lprocfs_jobstats.c +++ b/lustre/obdclass/lprocfs_jobstats.c @@ -250,7 +250,7 @@ static struct job_stat *job_alloc(char *jobid, struct obd_job_stats *jobs) return NULL; } - jobs->ojs_cntr_init_fn(job->js_stats); + jobs->ojs_cntr_init_fn(job->js_stats, 0); memcpy(job->js_jobid, jobid, sizeof(job->js_jobid)); job->js_timestamp = ktime_get_real_seconds(); diff --git a/lustre/ofd/lproc_ofd.c b/lustre/ofd/lproc_ofd.c index a36c316..04aa829 100644 --- a/lustre/ofd/lproc_ofd.c +++ b/lustre/ofd/lproc_ofd.c @@ -1026,36 +1026,40 @@ struct lprocfs_vars lprocfs_ofd_obd_vars[] = { * * param[in] stats statistics counters */ -void ofd_stats_counter_init(struct lprocfs_stats *stats) +void ofd_stats_counter_init(struct lprocfs_stats *stats, unsigned int offset) { LASSERT(stats && stats->ls_num >= LPROC_OFD_STATS_LAST); + lprocfs_counter_init(stats, LPROC_OFD_STATS_READ_BYTES, + LPROCFS_TYPE_BYTES_FULL, "read_bytes", "bytes"); + lprocfs_counter_init(stats, LPROC_OFD_STATS_WRITE_BYTES, + LPROCFS_TYPE_BYTES_FULL, "write_bytes", "bytes"); lprocfs_counter_init(stats, LPROC_OFD_STATS_READ, - LPROCFS_CNTR_AVGMINMAX, "read_bytes", "bytes"); + LPROCFS_TYPE_LATENCY, "read", "usecs"); lprocfs_counter_init(stats, LPROC_OFD_STATS_WRITE, - LPROCFS_CNTR_AVGMINMAX, "write_bytes", "bytes"); + LPROCFS_TYPE_LATENCY, "write", "usecs"); lprocfs_counter_init(stats, LPROC_OFD_STATS_GETATTR, - 0, "getattr", "reqs"); + LPROCFS_TYPE_LATENCY, "getattr", "usecs"); lprocfs_counter_init(stats, LPROC_OFD_STATS_SETATTR, - 0, "setattr", "reqs"); + LPROCFS_TYPE_LATENCY, "setattr", "usecs"); lprocfs_counter_init(stats, LPROC_OFD_STATS_PUNCH, - 0, "punch", "reqs"); + LPROCFS_TYPE_LATENCY, "punch", "usecs"); lprocfs_counter_init(stats, LPROC_OFD_STATS_SYNC, - 0, "sync", "reqs"); + LPROCFS_TYPE_LATENCY, "sync", "usecs"); lprocfs_counter_init(stats, LPROC_OFD_STATS_DESTROY, - 0, "destroy", "reqs"); + LPROCFS_TYPE_LATENCY, "destroy", "usecs"); lprocfs_counter_init(stats, LPROC_OFD_STATS_CREATE, - 0, "create", "reqs"); + LPROCFS_TYPE_LATENCY, "create", "usecs"); lprocfs_counter_init(stats, LPROC_OFD_STATS_STATFS, - 0, "statfs", "reqs"); + LPROCFS_TYPE_LATENCY, "statfs", "usecs"); lprocfs_counter_init(stats, LPROC_OFD_STATS_GET_INFO, - 0, "get_info", "reqs"); + LPROCFS_TYPE_LATENCY, "get_info", "usecs"); lprocfs_counter_init(stats, LPROC_OFD_STATS_SET_INFO, - 0, "set_info", "reqs"); + LPROCFS_TYPE_LATENCY, "set_info", "usecs"); lprocfs_counter_init(stats, LPROC_OFD_STATS_QUOTACTL, - 0, "quotactl", "reqs"); + LPROCFS_TYPE_LATENCY, "quotactl", "usecs"); lprocfs_counter_init(stats, LPROC_OFD_STATS_PREALLOC, - 0, "prealloc", "reqs"); + LPROCFS_TYPE_LATENCY, "prealloc", "usecs"); } LPROC_SEQ_FOPS(lprocfs_nid_stats_clear); @@ -1154,7 +1158,7 @@ int ofd_tunables_init(struct ofd_device *ofd) GOTO(obd_free_stats, rc); } - ofd_stats_counter_init(obd->obd_stats); + ofd_stats_counter_init(obd->obd_stats, 0); rc = lprocfs_job_stats_init(obd, LPROC_OFD_STATS_LAST, ofd_stats_counter_init); diff --git a/lustre/ofd/ofd_dev.c b/lustre/ofd/ofd_dev.c index f13affd..beb1900 100644 --- a/lustre/ofd/ofd_dev.c +++ b/lustre/ofd/ofd_dev.c @@ -880,6 +880,7 @@ static int ofd_set_info_hdl(struct tgt_session_info *tsi) void *key, *val = NULL; int keylen, vallen, rc = 0; bool is_grant_shrink; + ktime_t kstart = ktime_get(); ENTRY; @@ -928,7 +929,7 @@ static int ofd_set_info_hdl(struct tgt_session_info *tsi) rc = -EOPNOTSUPP; } ofd_counter_incr(tsi->tsi_exp, LPROC_OFD_STATS_SET_INFO, - tsi->tsi_jobid, 1); + tsi->tsi_jobid, ktime_us_delta(ktime_get(), kstart)); RETURN(rc); } @@ -1074,6 +1075,7 @@ static int ofd_get_info_hdl(struct tgt_session_info *tsi) void *key; int keylen; int replylen, rc = 0; + ktime_t kstart = ktime_get(); ENTRY; @@ -1188,7 +1190,7 @@ out_put: rc = -EOPNOTSUPP; } ofd_counter_incr(tsi->tsi_exp, LPROC_OFD_STATS_GET_INFO, - tsi->tsi_jobid, 1); + tsi->tsi_jobid, ktime_us_delta(ktime_get(), kstart)); RETURN(rc); } @@ -1213,6 +1215,7 @@ static int ofd_getattr_hdl(struct tgt_session_info *tsi) struct ofd_object *fo; __u64 flags = 0; enum ldlm_mode lock_mode = LCK_PR; + ktime_t kstart = ktime_get(); bool srvlock; int rc; ENTRY; @@ -1277,7 +1280,7 @@ out: tgt_extent_unlock(&lh, lock_mode); ofd_counter_incr(tsi->tsi_exp, LPROC_OFD_STATS_GETATTR, - tsi->tsi_jobid, 1); + tsi->tsi_jobid, ktime_us_delta(ktime_get(), kstart)); repbody->oa.o_valid |= OBD_MD_FLFLAGS; repbody->oa.o_flags = OBD_FL_FLUSH; @@ -1304,6 +1307,7 @@ static int ofd_setattr_hdl(struct tgt_session_info *tsi) struct ost_body *repbody; struct ldlm_resource *res; struct ofd_object *fo; + ktime_t kstart = ktime_get(); int rc = 0; ENTRY; @@ -1352,7 +1356,7 @@ static int ofd_setattr_hdl(struct tgt_session_info *tsi) OFD_VALID_FLAGS | LA_UID | LA_GID | LA_PROJID); ofd_counter_incr(tsi->tsi_exp, LPROC_OFD_STATS_SETATTR, - tsi->tsi_jobid, 1); + tsi->tsi_jobid, ktime_us_delta(ktime_get(), kstart)); EXIT; out_put: ofd_object_put(tsi->tsi_env, fo); @@ -1489,10 +1493,11 @@ static int ofd_create_hdl(struct tgt_session_info *tsi) u64 seq = ostid_seq(&oa->o_oi); u64 oid = ostid_id(&oa->o_oi); struct ofd_seq *oseq; - s64 diff; - int rc = 0; int sync_trans = 0; long granted = 0; + ktime_t kstart = ktime_get(); + s64 diff; + int rc = 0; ENTRY; @@ -1730,7 +1735,7 @@ static int ofd_create_hdl(struct tgt_session_info *tsi) } EXIT; ofd_counter_incr(exp, LPROC_OFD_STATS_CREATE, - tsi->tsi_jobid, 1); + tsi->tsi_jobid, ktime_us_delta(ktime_get(), kstart)); if (unlikely(!oseq->os_last_id_synced)) oseq->os_last_id_synced = 1; out: @@ -1763,6 +1768,7 @@ static int ofd_destroy_hdl(struct tgt_session_info *tsi) struct ofd_device *ofd = ofd_exp(tsi->tsi_exp); struct ofd_thread_info *fti = tsi2ofd_info(tsi); struct lu_fid *fid = &fti->fti_fid; + ktime_t kstart = ktime_get(); u64 oid; u32 count; int rc = 0; @@ -1824,7 +1830,7 @@ static int ofd_destroy_hdl(struct tgt_session_info *tsi) } ofd_counter_incr(tsi->tsi_exp, LPROC_OFD_STATS_DESTROY, - tsi->tsi_jobid, 1); + tsi->tsi_jobid, ktime_us_delta(ktime_get(), kstart)); GOTO(out, rc); @@ -1846,6 +1852,7 @@ out: */ static int ofd_statfs_hdl(struct tgt_session_info *tsi) { + ktime_t kstart = ktime_get(); struct obd_statfs *osfs; int rc; @@ -1865,7 +1872,7 @@ static int ofd_statfs_hdl(struct tgt_session_info *tsi) rc = -EINPROGRESS; ofd_counter_incr(tsi->tsi_exp, LPROC_OFD_STATS_STATFS, - tsi->tsi_jobid, 1); + tsi->tsi_jobid, ktime_us_delta(ktime_get(), kstart)); RETURN(rc); } @@ -1888,6 +1895,7 @@ static int ofd_sync_hdl(struct tgt_session_info *tsi) struct ofd_thread_info *fti = tsi2ofd_info(tsi); struct ofd_device *ofd = ofd_exp(tsi->tsi_exp); struct ofd_object *fo = NULL; + ktime_t kstart = ktime_get(); int rc = 0; ENTRY; @@ -1908,7 +1916,7 @@ static int ofd_sync_hdl(struct tgt_session_info *tsi) GOTO(put, rc); ofd_counter_incr(tsi->tsi_exp, LPROC_OFD_STATS_SYNC, - tsi->tsi_jobid, 1); + tsi->tsi_jobid, ktime_us_delta(ktime_get(), kstart)); if (fo == NULL) RETURN(0); @@ -1953,6 +1961,7 @@ static int ofd_fallocate_hdl(struct tgt_session_info *tsi) int rc, mode; __u64 start, end; bool srvlock; + ktime_t kstart = ktime_get(); repbody = req_capsule_server_get(tsi->tsi_pill, &RMF_OST_BODY); if (repbody == NULL) @@ -2006,7 +2015,7 @@ static int ofd_fallocate_hdl(struct tgt_session_info *tsi) rc = 0; ofd_counter_incr(tsi->tsi_exp, LPROC_OFD_STATS_PREALLOC, - tsi->tsi_jobid, 1); + tsi->tsi_jobid, ktime_us_delta(ktime_get(), kstart)); EXIT; out_put: @@ -2058,9 +2067,10 @@ static int ofd_punch_hdl(struct tgt_session_info *tsi) struct ofd_object *fo; __u64 flags = 0; struct lustre_handle lh = { 0, }; - int rc; __u64 start, end; bool srvlock; + ktime_t kstart = ktime_get(); + int rc; ENTRY; @@ -2122,7 +2132,7 @@ static int ofd_punch_hdl(struct tgt_session_info *tsi) GOTO(out_put, rc); ofd_counter_incr(tsi->tsi_exp, LPROC_OFD_STATS_PUNCH, - tsi->tsi_jobid, 1); + tsi->tsi_jobid, ktime_us_delta(ktime_get(), kstart)); EXIT; out_put: ofd_object_put(tsi->tsi_env, fo); @@ -2348,6 +2358,7 @@ static int ofd_quotactl(struct tgt_session_info *tsi) { struct obd_quotactl *oqctl, *repoqc; struct lu_nodemap *nodemap; + ktime_t kstart = ktime_get(); int id; int rc; @@ -2385,7 +2396,7 @@ static int ofd_quotactl(struct tgt_session_info *tsi) rc = lquotactl_slv(tsi->tsi_env, tsi->tsi_tgt->lut_bottom, repoqc); ofd_counter_incr(tsi->tsi_exp, LPROC_OFD_STATS_QUOTACTL, - tsi->tsi_jobid, 1); + tsi->tsi_jobid, ktime_us_delta(ktime_get(), kstart)); if (repoqc->qc_id != id) swap(repoqc->qc_id, id); diff --git a/lustre/ofd/ofd_internal.h b/lustre/ofd/ofd_internal.h index 9d06085..8d07cda 100644 --- a/lustre/ofd/ofd_internal.h +++ b/lustre/ofd/ofd_internal.h @@ -61,7 +61,9 @@ /* request stats */ enum { - LPROC_OFD_STATS_READ = 0, + LPROC_OFD_STATS_READ_BYTES = 0, + LPROC_OFD_STATS_WRITE_BYTES, + LPROC_OFD_STATS_READ, LPROC_OFD_STATS_WRITE, LPROC_OFD_STATS_GETATTR, LPROC_OFD_STATS_SETATTR, @@ -368,9 +370,10 @@ int ofd_txn_stop_cb(const struct lu_env *env, struct thandle *txn, /* lproc_ofd.c */ int ofd_tunables_init(struct ofd_device *ofd); #ifdef CONFIG_PROC_FS -void ofd_stats_counter_init(struct lprocfs_stats *stats); +void ofd_stats_counter_init(struct lprocfs_stats *stats, unsigned int offset); #else -static inline void ofd_stats_counter_init(struct lprocfs_stats *stats) {} +static inline void ofd_stats_counter_init(struct lprocfs_stats *stats, + unsigned int offset) {} #endif /* ofd_objects.c */ diff --git a/lustre/ofd/ofd_io.c b/lustre/ofd/ofd_io.c index cdb3198..5e7801f 100644 --- a/lustre/ofd/ofd_io.c +++ b/lustre/ofd/ofd_io.c @@ -572,6 +572,7 @@ static int ofd_preprw_read(const struct lu_env *env, struct obd_export *exp, enum dt_bufs_type dbt = DT_BUFS_TYPE_READ; int maxlnb = *nr_local; __u64 begin, end; + ktime_t kstart = ktime_get(); ENTRY; LASSERT(env != NULL); @@ -638,7 +639,9 @@ static int ofd_preprw_read(const struct lu_env *env, struct obd_export *exp, niocount, READ); - ofd_counter_incr(exp, LPROC_OFD_STATS_READ, jobid, tot_bytes); + ofd_counter_incr(exp, LPROC_OFD_STATS_READ_BYTES, jobid, tot_bytes); + ofd_counter_incr(exp, LPROC_OFD_STATS_READ, jobid, + ktime_us_delta(ktime_get(), kstart)); RETURN(0); buf_put: @@ -684,6 +687,7 @@ static int ofd_preprw_write(const struct lu_env *env, struct obd_export *exp, enum dt_bufs_type dbt = DT_BUFS_TYPE_WRITE; int maxlnb = *nr_local; __u64 begin, end; + ktime_t kstart = ktime_get(); ENTRY; LASSERT(env != NULL); @@ -838,7 +842,9 @@ static int ofd_preprw_write(const struct lu_env *env, struct obd_export *exp, obj->ioo_bufcnt, WRITE); - ofd_counter_incr(exp, LPROC_OFD_STATS_WRITE, jobid, tot_bytes); + ofd_counter_incr(exp, LPROC_OFD_STATS_WRITE_BYTES, jobid, tot_bytes); + ofd_counter_incr(exp, LPROC_OFD_STATS_WRITE, jobid, + ktime_us_delta(ktime_get(), kstart)); RETURN(0); err: dt_bufs_put(env, ofd_object_child(fo), lnb, *nr_local); diff --git a/lustre/ofd/ofd_obd.c b/lustre/ofd/ofd_obd.c index 3c6e518..e92d0f0 100644 --- a/lustre/ofd/ofd_obd.c +++ b/lustre/ofd/ofd_obd.c @@ -88,7 +88,7 @@ static int ofd_export_stats_init(struct ofd_device *ofd, if (!stats->nid_stats) RETURN(-ENOMEM); - ofd_stats_counter_init(stats->nid_stats); + ofd_stats_counter_init(stats->nid_stats, 0); rc = lprocfs_register_stats(stats->nid_proc, "stats", stats->nid_stats); if (rc != 0) { @@ -903,6 +903,7 @@ static int ofd_echo_setattr(const struct lu_env *env, struct obd_export *exp, struct ldlm_resource *res; struct ofd_object *fo; struct lu_fid *fid = &oa->o_oi.oi_fid; + ktime_t kstart = ktime_get(); int rc = 0; ENTRY; @@ -946,7 +947,8 @@ static int ofd_echo_setattr(const struct lu_env *env, struct obd_export *exp, if (rc) GOTO(out_unlock, rc); - ofd_counter_incr(exp, LPROC_OFD_STATS_SETATTR, NULL, 1); + ofd_counter_incr(exp, LPROC_OFD_STATS_SETATTR, NULL, + ktime_us_delta(ktime_get(), kstart)); EXIT; out_unlock: ofd_object_put(env, fo); diff --git a/lustre/tests/sanity.sh b/lustre/tests/sanity.sh index e4ad1fe..a4a189d 100755 --- a/lustre/tests/sanity.sh +++ b/lustre/tests/sanity.sh @@ -16353,16 +16353,20 @@ test_205a() { # Job stats } run_test 205a "Verify job stats" -# LU-13117 +# LU-13117, LU-13597 test_205b() { + job_stats="mdt.*.job_stats" + $LCTL set_param $job_stats=clear $LCTL set_param jobid_var=USER jobid_name="%e.%u" env -i USERTESTJOBSTATS=foolish touch $DIR/$tfile.1 - do_facet $SINGLEMDS $LCTL get_param mdt.*.job_stats | - grep job_id: | grep foolish && + do_facet $SINGLEMDS $LCTL get_param $job_stats | + grep "job_id:.*foolish" && error "Unexpected jobid found" - true + do_facet $SINGLEMDS $LCTL get_param $job_stats | + grep "open:.*min.*max.*sum" || + error "wrong job_stats format found" } -run_test 205b "Verify job stats jobid parsing" +run_test 205b "Verify job stats jobid and output format" # LU-1480, LU-1773 and LU-1657 test_206() { -- 1.8.3.1