LU-16231 misc: fix stats snapshot_time to use wallclock

The timestamps reported during stats collection inadvertently changed
from being POSIX epoch timestamps to elapsed-from-boot timestamps.

While some collection tools ignore these timestamps, or only use the
delta between successive reads, having uniform timestaps in stats
files simplifies stats correlation between different servers.

Revert the snapshot_time back to showing wallclock time.

Some "init" times were not initialized when stats were allocated or
cleared, do this for all stats shown by lprocfs_stats_header().

Rename struct osc_device fields from od_ to osc_ to avoid confusion
with struct osd_device. Having two od_stats was especially confusing.

Add a test case to verify snapshot_time, start_time, elapsed_time.

Test-Parameters: testlist=sanity env=ONLY=127a,ONLY_REPEAT=100
Fixes: ea2cd3af7b ("LU-11407 obdclass: add start time to stats files")
Signed-off-by: Andreas Dilger <adilger@whamcloud.com>
Change-Id: I421c3b0301c2566b48c2fc6fe7bb8b54ec48ca5d
Reviewed-on: https://review.whamcloud.com/c/fs/lustre-release/+/48821
Tested-by: jenkins <devops@whamcloud.com>
Tested-by: Maloo <maloo@whamcloud.com>
Reviewed-by: Li Xi <lixi@ddn.com>
Reviewed-by: Ellis Wilson <elliswilson@microsoft.com>
Reviewed-by: Feng Lei <flei@whamcloud.com>
Reviewed-by: James Simmons <jsimmons@infradead.org>
Reviewed-by: Oleg Drokin <green@whamcloud.com>

diff --git a/lustre/include/lustre_osc.h b/lustre/include/lustre_osc.h
index 14ed9e2..4a4880d 100644 (file)
--- a/lustre/include/lustre_osc.h
+++ b/lustre/include/lustre_osc.h
@@ -104,18 +104,18 @@ static inline struct osc_async_page *brw_page2oap(struct brw_page *pga)
 }
 
 struct osc_device {
-       struct cl_device        od_cl;
-       struct obd_export       *od_exp;
+       struct cl_device        osc_cl;
+       struct obd_export       *osc_exp;
 
        /* Write stats is actually protected by client_obd's lock. */
        struct osc_stats {
                ktime_t         os_init;
                uint64_t        os_lockless_writes;    /* by bytes */
                uint64_t        os_lockless_reads;     /* by bytes */
-       } od_stats;
+       } osc_stats;
 
        /* configuration item(s) */
-       time64_t                od_contention_time;
+       time64_t                osc_contention_time;
 };
 
 struct osc_extent;
@@ -761,12 +761,12 @@ static inline struct osc_io *osc_env_io(const struct lu_env *env)
 
 static inline struct osc_device *lu2osc_dev(const struct lu_device *d)
 {
-       return container_of_safe(d, struct osc_device, od_cl.cd_lu_dev);
+       return container_of_safe(d, struct osc_device, osc_cl.cd_lu_dev);
 }
 
 static inline struct obd_export *osc_export(const struct osc_object *obj)
 {
-       return lu2osc_dev(obj->oo_cl.co_lu.lo_dev)->od_exp;
+       return lu2osc_dev(obj->oo_cl.co_lu.lo_dev)->osc_exp;
 }
 
 static inline struct client_obd *osc_cli(const struct osc_object *obj)
@@ -787,12 +787,12 @@ static inline struct cl_object *osc2cl(const struct osc_object *obj)
 static inline struct osc_device *obd2osc_dev(const struct obd_device *obd)
 {
        return container_of_safe(obd->obd_lu_dev, struct osc_device,
-                                od_cl.cd_lu_dev);
+                                osc_cl.cd_lu_dev);
 }
 
 static inline struct lu_device *osc2lu_dev(struct osc_device *osc)
 {
-       return &osc->od_cl.cd_lu_dev;
+       return &osc->osc_cl.cd_lu_dev;
 }
 
 static inline struct lu_object *osc2lu(struct osc_object *osc)

diff --git a/lustre/ldlm/ldlm_lib.c b/lustre/ldlm/ldlm_lib.c
index cbca1a6..b8973d1 100644 (file)
--- a/lustre/ldlm/ldlm_lib.c
+++ b/lustre/ldlm/ldlm_lib.c
@@ -508,6 +508,7 @@ int client_obd_setup(struct obd_device *obd, struct lustre_cfg *lcfg)
        cli->cl_mod_rpcs_in_flight = 0;
        cli->cl_close_rpcs_in_flight = 0;
        init_waitqueue_head(&cli->cl_mod_rpcs_waitq);
+       cli->cl_mod_rpcs_init = ktime_get_real();
        cli->cl_mod_tag_bitmap = NULL;
 
        INIT_LIST_HEAD(&cli->cl_chg_dev_linkage);

diff --git a/lustre/llite/lproc_llite.c b/lustre/llite/lproc_llite.c
index 6247c50..b9e9dd6 100644 (file)
--- a/lustre/llite/lproc_llite.c
+++ b/lustre/llite/lproc_llite.c
@@ -2058,8 +2058,8 @@ static int ll_rw_extents_stats_pp_seq_show(struct seq_file *seq, void *v)
        }
 
        spin_lock(&sbi->ll_pp_extent_lock);
-       lprocfs_stats_header(seq, ktime_get(), rw_extents->pp_init, 25, ":",
-                            true, "");
+       lprocfs_stats_header(seq, ktime_get_real(), rw_extents->pp_init, 25,
+                            ":", true, "");
        seq_printf(seq, "%15s %19s       | %20s\n", " ", "read", "write");
        seq_printf(seq, "%13s   %14s %4s %4s  | %14s %4s %4s\n",
                   "extents", "calls", "%", "cum%", "calls", "%", "cum%");
@@ -2090,6 +2090,7 @@ static int alloc_rw_stats_info(struct ll_sb_info *sbi)
                spin_lock_init(&rw_extents->pp_extents[i].pp_r_hist.oh_lock);
                spin_lock_init(&rw_extents->pp_extents[i].pp_w_hist.oh_lock);
        }
+       rw_extents->pp_init = ktime_get_real();
 
        spin_lock(&sbi->ll_pp_extent_lock);
        if (!sbi->ll_rw_extents_info)
@@ -2112,6 +2113,7 @@ static int alloc_rw_stats_info(struct ll_sb_info *sbi)
        if (!sbi->ll_rw_offset_info)
                sbi->ll_rw_offset_info = offset;
        spin_unlock(&sbi->ll_process_lock);
+       sbi->ll_process_stats_init = ktime_get_real();
 
        /* another writer allocated the structs before we got the lock */
        if (sbi->ll_rw_offset_info != offset)
@@ -2175,7 +2177,7 @@ static ssize_t ll_rw_extents_stats_pp_seq_write(struct file *file,
        spin_lock(&sbi->ll_pp_extent_lock);
        rw_extents = sbi->ll_rw_extents_info;
        if (rw_extents) {
-               rw_extents->pp_init = ktime_get();
+               rw_extents->pp_init = ktime_get_real();
                for (i = 0; i < LL_PROCESS_HIST_MAX; i++) {
                        rw_extents->pp_extents[i].pid = 0;
                        lprocfs_oh_clear(&rw_extents->pp_extents[i].pp_r_hist);
@@ -2200,8 +2202,8 @@ static int ll_rw_extents_stats_seq_show(struct seq_file *seq, void *v)
        }
 
        spin_lock(&sbi->ll_lock);
-       lprocfs_stats_header(seq, ktime_get(), rw_extents->pp_init, 25, ":",
-                            true, "");
+       lprocfs_stats_header(seq, ktime_get_real(), rw_extents->pp_init, 25,
+                            ":", true, "");
 
        seq_printf(seq, "%15s %19s       | %20s\n", " ", "read", "write");
        seq_printf(seq, "%13s   %14s %4s %4s  | %14s %4s %4s\n",
@@ -2244,7 +2246,7 @@ static ssize_t ll_rw_extents_stats_seq_write(struct file *file,
        spin_lock(&sbi->ll_pp_extent_lock);
        rw_extents = sbi->ll_rw_extents_info;
        if (rw_extents) {
-               rw_extents->pp_init = ktime_get();
+               rw_extents->pp_init = ktime_get_real();
                for (i = 0; i <= LL_PROCESS_HIST_MAX; i++) {
                        rw_extents->pp_extents[i].pid = 0;
                        lprocfs_oh_clear(&rw_extents->pp_extents[i].pp_r_hist);
@@ -2383,8 +2385,8 @@ static int ll_rw_offset_stats_seq_show(struct seq_file *seq, void *v)
        }
 
        spin_lock(&sbi->ll_process_lock);
-       lprocfs_stats_header(seq, ktime_get(), sbi->ll_process_stats_init, 25,
-                            ":", true, "");
+       lprocfs_stats_header(seq, ktime_get_real(), sbi->ll_process_stats_init,
+                            25, ":", true, "");
        seq_printf(seq, "%3s %10s %14s %14s %17s %17s %14s\n",
                   "R/W", "PID", "RANGE START", "RANGE END",
                   "SMALLEST EXTENT", "LARGEST EXTENT", "OFFSET");
@@ -2451,7 +2453,7 @@ static ssize_t ll_rw_offset_stats_seq_write(struct file *file,
        spin_lock(&sbi->ll_process_lock);
        sbi->ll_offset_process_count = 0;
        sbi->ll_rw_offset_entry_count = 0;
-       sbi->ll_process_stats_init = ktime_get();
+       sbi->ll_process_stats_init = ktime_get_real();
        if (sbi->ll_rw_process_info)
                memset(sbi->ll_rw_process_info, 0,
                       sizeof(struct ll_rw_process_info) * LL_PROCESS_HIST_MAX);

diff --git a/lustre/mdc/lproc_mdc.c b/lustre/mdc/lproc_mdc.c
index 6b2eecf..26e86a8 100644 (file)
--- a/lustre/mdc/lproc_mdc.c
+++ b/lustre/mdc/lproc_mdc.c
@@ -415,6 +415,7 @@ static ssize_t mdc_rpc_stats_seq_write(struct file *file,
        lprocfs_oh_clear(&cli->cl_write_page_hist);
        lprocfs_oh_clear(&cli->cl_read_offset_hist);
        lprocfs_oh_clear(&cli->cl_write_offset_hist);
+       cli->cl_mod_rpcs_init = ktime_get_real();
 
        return len;
 }
@@ -516,10 +517,10 @@ LPROC_SEQ_FOPS(mdc_rpc_stats);
 static int mdc_stats_seq_show(struct seq_file *seq, void *v)
 {
        struct obd_device *obd = seq->private;
-       struct osc_stats *stats = &obd2osc_dev(obd)->od_stats;
+       struct osc_stats *stats = &obd2osc_dev(obd)->osc_stats;
 
-       lprocfs_stats_header(seq, ktime_get(), stats->os_init, 25, ":", true,
-                            "");
+       lprocfs_stats_header(seq, ktime_get_real(), stats->os_init, 25, ":",
+                            true, "");
        seq_printf(seq, "lockless_write_bytes\t\t%llu\n",
                   stats->os_lockless_writes);
        seq_printf(seq, "lockless_read_bytes\t\t%llu\n",
@@ -533,10 +534,10 @@ static ssize_t mdc_stats_seq_write(struct file *file,
 {
        struct seq_file *seq = file->private_data;
        struct obd_device *obd = seq->private;
-       struct osc_stats *stats = &obd2osc_dev(obd)->od_stats;
+       struct osc_stats *stats = &obd2osc_dev(obd)->osc_stats;
 
        memset(stats, 0, sizeof(*stats));
-       stats->os_init = ktime_get();
+       stats->os_init = ktime_get_real();
 
        return len;
 }

diff --git a/lustre/mdc/mdc_dev.c b/lustre/mdc/mdc_dev.c
index 339d18a..956ff9d 100644 (file)
--- a/lustre/mdc/mdc_dev.c
+++ b/lustre/mdc/mdc_dev.c
@@ -1589,16 +1589,16 @@ static struct lu_device *mdc_device_alloc(const struct lu_env *env,
                                          struct lustre_cfg *cfg)
 {
        struct lu_device *d;
-       struct osc_device *od;
+       struct osc_device *oc;
        struct obd_device *obd;
        int rc;
 
-       OBD_ALLOC_PTR(od);
-       if (od == NULL)
+       OBD_ALLOC_PTR(oc);
+       if (oc == NULL)
                RETURN(ERR_PTR(-ENOMEM));
 
-       cl_device_init(&od->od_cl, t);
-       d = osc2lu_dev(od);
+       cl_device_init(&oc->osc_cl, t);
+       d = osc2lu_dev(oc);
        d->ld_ops = &mdc_lu_ops;
 
        /* Setup MDC OBD */
@@ -1611,7 +1611,8 @@ static struct lu_device *mdc_device_alloc(const struct lu_env *env,
                osc_device_free(env, d);
                RETURN(ERR_PTR(rc));
        }
-       od->od_exp = obd->obd_self_export;
+       oc->osc_exp = obd->obd_self_export;
+       oc->osc_stats.os_init = ktime_get_real();
        RETURN(d);
 }
 

diff --git a/lustre/mdt/mdt_handler.c b/lustre/mdt/mdt_handler.c
index 4b6e3b5..7ea83d6 100644 (file)
--- a/lustre/mdt/mdt_handler.c
+++ b/lustre/mdt/mdt_handler.c
@@ -6007,7 +6007,6 @@ static int mdt_init0(const struct lu_env *env, struct mdt_device *m,
        m->mdt_enable_remote_subdir_mount = 1;
        m->mdt_enable_striped_dir = 1;
        m->mdt_dir_restripe_nsonly = 1;
-       m->mdt_rename_stats.rs_init = ktime_get();
 
        atomic_set(&m->mdt_mds_mds_conns, 0);
        atomic_set(&m->mdt_async_commit_count, 0);

diff --git a/lustre/mdt/mdt_lproc.c b/lustre/mdt/mdt_lproc.c
index 050b065..39f8264 100644 (file)
--- a/lustre/mdt/mdt_lproc.c
+++ b/lustre/mdt/mdt_lproc.c
@@ -109,13 +109,15 @@ static void display_rename_stats(struct seq_file *seq, char *name,
        }
 }
 
-static void rename_stats_show(struct seq_file *seq,
-                             struct rename_stats *rename_stats)
+static int mdt_rename_stats_seq_show(struct seq_file *seq, void *v)
 {
+       struct mdt_device *mdt = seq->private;
+       struct rename_stats *rename_stats = &mdt->mdt_rename_stats;
+
        /* this sampling races with updates */
        seq_puts(seq, "rename_stats:\n-\n");
-       lprocfs_stats_header(seq, ktime_get(), rename_stats->rs_init, 15, ":",
-                            false, "  ");
+       lprocfs_stats_header(seq, ktime_get_real(), rename_stats->rs_init, 15,
+                            ":", false, "  ");
 
        display_rename_stats(seq, "same_dir",
                             &rename_stats->rs_hist[RENAME_SAMEDIR_SIZE]);
@@ -123,13 +125,6 @@ static void rename_stats_show(struct seq_file *seq,
                             &rename_stats->rs_hist[RENAME_CROSSDIR_SRC_SIZE]);
        display_rename_stats(seq, "crossdir_tgt",
                             &rename_stats->rs_hist[RENAME_CROSSDIR_TGT_SIZE]);
-}
-
-static int mdt_rename_stats_seq_show(struct seq_file *seq, void *v)
-{
-       struct mdt_device *mdt = seq->private;
-
-       rename_stats_show(seq, &mdt->mdt_rename_stats);
 
        return 0;
 }
@@ -144,7 +139,7 @@ mdt_rename_stats_seq_write(struct file *file, const char __user *buf,
 
        for (i = 0; i < RENAME_LAST; i++)
                lprocfs_oh_clear(&mdt->mdt_rename_stats.rs_hist[i]);
-       mdt->mdt_rename_stats.rs_init = ktime_get();
+       mdt->mdt_rename_stats.rs_init = ktime_get_real();
 
        return len;
 }
@@ -156,6 +151,7 @@ static int lproc_mdt_attach_rename_seqstat(struct mdt_device *mdt)
 
        for (i = 0; i < RENAME_LAST; i++)
                spin_lock_init(&mdt->mdt_rename_stats.rs_hist[i].oh_lock);
+       mdt->mdt_rename_stats.rs_init = ktime_get_real();
 
        return lprocfs_obd_seq_create(mdt2obd_dev(mdt), "rename_stats", 0644,
                                      &mdt_rename_stats_fops, mdt);

diff --git a/lustre/obdclass/genops.c b/lustre/obdclass/genops.c
index 509426c..7fc8971 100644 (file)
--- a/lustre/obdclass/genops.c
+++ b/lustre/obdclass/genops.c
@@ -2201,7 +2201,7 @@ int obd_mod_rpc_stats_seq_show(struct client_obd *cli,
        int i;
 
        spin_lock_irq(&cli->cl_mod_rpcs_waitq.lock);
-       lprocfs_stats_header(seq, ktime_get(), cli->cl_mod_rpcs_init, 25,
+       lprocfs_stats_header(seq, ktime_get_real(), cli->cl_mod_rpcs_init, 25,
                             ":", true, "");
        seq_printf(seq, "modify_RPCs_in_flight:  %hu\n",
                   cli->cl_mod_rpcs_in_flight);

diff --git a/lustre/obdclass/lprocfs_jobstats.c b/lustre/obdclass/lprocfs_jobstats.c
index 041ebe7..2bd6039 100644 (file)
--- a/lustre/obdclass/lprocfs_jobstats.c
+++ b/lustre/obdclass/lprocfs_jobstats.c
@@ -199,7 +199,7 @@ static int job_cleanup_iter_callback(struct cfs_hash *hs,
 static void lprocfs_job_cleanup(struct obd_job_stats *stats, bool clear)
 {
        ktime_t cleanup_interval = stats->ojs_cleanup_interval;
-       ktime_t now = ktime_get();
+       ktime_t now = ktime_get_real();
        ktime_t oldest;
 
        if (likely(!clear)) {
@@ -242,7 +242,7 @@ static void lprocfs_job_cleanup(struct obd_job_stats *stats, bool clear)
 
        write_lock(&stats->ojs_lock);
        stats->ojs_cleaning = false;
-       stats->ojs_cleanup_last = ktime_get();
+       stats->ojs_cleanup_last = ktime_get_real();
        write_unlock(&stats->ojs_lock);
 }
 
@@ -263,8 +263,7 @@ static struct job_stat *job_alloc(char *jobid, struct obd_job_stats *jobs)
        jobs->ojs_cntr_init_fn(job->js_stats, 0, 0);
 
        memcpy(job->js_jobid, jobid, sizeof(job->js_jobid));
-       job->js_time_init = ktime_get();
-       job->js_time_latest = job->js_time_init;
+       job->js_time_latest = job->js_stats->ls_init;
        job->js_jobstats = jobs;
        INIT_HLIST_NODE(&job->js_hash);
        INIT_LIST_HEAD(&job->js_list);
@@ -324,7 +323,7 @@ int lprocfs_job_stats_log(struct obd_device *obd, char *jobid,
 
 found:
        LASSERT(stats == job->js_jobstats);
-       job->js_time_latest = ktime_get();
+       job->js_time_latest = ktime_get_real();
        lprocfs_counter_add(job->js_stats, event, amount);
 
        job_putref(job);
@@ -468,8 +467,8 @@ static int lprocfs_jobstats_seq_show(struct seq_file *p, void *v)
 
        seq_printf(p, "- %-16s %s%*s%s\n",
                   "job_id:", quote, joblen, escaped, quote);
-       lprocfs_stats_header(p, job->js_time_latest, job->js_time_init, 16,
-                            ":", true, "  ");
+       lprocfs_stats_header(p, job->js_time_latest, job->js_stats->ls_init,
+                            16, ":", true, "  ");
 
        s = job->js_stats;
        for (i = 0; i < s->ls_num; i++) {
@@ -671,7 +670,7 @@ int lprocfs_job_stats_init(struct obd_device *obd, int cntr_num,
         * it is easier to work with.
         */
        stats->ojs_cleanup_interval = ktime_set(600 / 2, 0); /* default 10 min*/
-       stats->ojs_cleanup_last = ktime_get();
+       stats->ojs_cleanup_last = ktime_get_real();
 
        entry = lprocfs_add_simple(obd->obd_proc_entry, "job_stats", stats,
                                   &lprocfs_jobstats_seq_fops);

diff --git a/lustre/obdclass/lprocfs_status.c b/lustre/obdclass/lprocfs_status.c
index 1f9d353..165281c 100644 (file)
--- a/lustre/obdclass/lprocfs_status.c
+++ b/lustre/obdclass/lprocfs_status.c
@@ -1220,6 +1220,7 @@ struct lprocfs_stats *lprocfs_alloc_stats(unsigned int num,
 
        stats->ls_num = num;
        stats->ls_flags = flags;
+       stats->ls_init = ktime_get_real();
        spin_lock_init(&stats->ls_lock);
 
        /* alloc num of counter headers */
@@ -1338,6 +1339,7 @@ void lprocfs_clear_stats(struct lprocfs_stats *stats)
                                percpu_cntr->lc_sum_irq = 0;
                }
        }
+       stats->ls_init = ktime_get_real();
 
        lprocfs_stats_unlock(stats, LPROCFS_GET_NUM_CPU, &flags);
 }
@@ -1419,8 +1421,8 @@ static int lprocfs_stats_seq_show(struct seq_file *p, void *v)
        int idx = *(loff_t *)v;
 
        if (idx == 0)
-               lprocfs_stats_header(p, ktime_get(), stats->ls_init, 25, "",
-                                    true, "");
+               lprocfs_stats_header(p, ktime_get_real(), stats->ls_init, 25,
+                                    "", true, "");
 
        hdr = &stats->ls_cnt_header[idx];
        lprocfs_stats_collect(stats, idx, &ctr);

diff --git a/lustre/obdclass/lprocfs_status_server.c b/lustre/obdclass/lprocfs_status_server.c
index d68fc84..24b2bbf 100644 (file)
--- a/lustre/obdclass/lprocfs_status_server.c
+++ b/lustre/obdclass/lprocfs_status_server.c
@@ -779,8 +779,8 @@ static int brw_stats_seq_show(struct seq_file *seq, void *v)
        int i;
 
        /* this sampling races with updates */
-       lprocfs_stats_header(seq, ktime_get(), brw_stats->bs_init, 25, ":",
-                            true, "");
+       lprocfs_stats_header(seq, ktime_get_real(), brw_stats->bs_init, 25,
+                            ":", true, "");
 
        for (i = 0; i < ARRAY_SIZE(brw_stats->bs_props); i++) {
                if (!brw_stats->bs_props[i].bsp_name)
@@ -806,6 +806,7 @@ static ssize_t brw_stats_seq_write(struct file *file,
 
        for (i = 0; i < BRW_RW_STATS_NUM; i++)
                lprocfs_oh_clear_pcpu(&brw_stats->bs_hist[i]);
+       brw_stats->bs_init = ktime_get_real();
 
        return len;
 }
@@ -842,7 +843,7 @@ void ldebugfs_register_osd_stats(struct dentry *parent,
        int i;
 
        LASSERT(brw_stats);
-       brw_stats->bs_init = ktime_get();
+       brw_stats->bs_init = ktime_get_real();
        for (i = 0; i < BRW_RW_STATS_NUM; i++) {
                struct brw_stats_props *props = brw_stats->bs_props;
 

diff --git a/lustre/osc/lproc_osc.c b/lustre/osc/lproc_osc.c
index 10de69a..58d95f3 100644 (file)
--- a/lustre/osc/lproc_osc.c
+++ b/lustre/osc/lproc_osc.c
@@ -713,8 +713,8 @@ static int osc_rpc_stats_seq_show(struct seq_file *seq, void *v)
 
        spin_lock(&cli->cl_loi_list_lock);
 
-       lprocfs_stats_header(seq, ktime_get(), cli->cl_stats_init, 25, ":",
-                            true, "");
+       lprocfs_stats_header(seq, ktime_get_real(), cli->cl_stats_init, 25,
+                            ":", true, "");
        seq_printf(seq, "read RPCs in flight:  %d\n",
                   cli->cl_r_in_flight);
        seq_printf(seq, "write RPCs in flight: %d\n",
@@ -812,7 +812,7 @@ static ssize_t osc_rpc_stats_seq_write(struct file *file,
        lprocfs_oh_clear(&cli->cl_write_page_hist);
        lprocfs_oh_clear(&cli->cl_read_offset_hist);
        lprocfs_oh_clear(&cli->cl_write_offset_hist);
-       cli->cl_stats_init = ktime_get();
+       cli->cl_stats_init = ktime_get_real();
 
        return len;
 }
@@ -821,10 +821,10 @@ LPROC_SEQ_FOPS(osc_rpc_stats);
 static int osc_stats_seq_show(struct seq_file *seq, void *v)
 {
        struct obd_device *obd = seq->private;
-       struct osc_stats *stats = &obd2osc_dev(obd)->od_stats;
+       struct osc_stats *stats = &obd2osc_dev(obd)->osc_stats;
 
-       lprocfs_stats_header(seq, ktime_get(), stats->os_init, 25, ":", true,
-                            "");
+       lprocfs_stats_header(seq, ktime_get_real(), stats->os_init, 25, ":",
+                            true, "");
        seq_printf(seq, "lockless_write_bytes\t\t%llu\n",
                   stats->os_lockless_writes);
        seq_printf(seq, "lockless_read_bytes\t\t%llu\n",
@@ -838,10 +838,10 @@ static ssize_t osc_stats_seq_write(struct file *file,
 {
        struct seq_file *seq = file->private_data;
        struct obd_device *obd = seq->private;
-       struct osc_stats *stats = &obd2osc_dev(obd)->od_stats;
+       struct osc_stats *stats = &obd2osc_dev(obd)->osc_stats;
 
        memset(stats, 0, sizeof(*stats));
-       stats->os_init = ktime_get();
+       stats->os_init = ktime_get_real();
 
        return len;
 }

diff --git a/lustre/osc/osc_cache.c b/lustre/osc/osc_cache.c
index 20408c0..8240ae6 100644 (file)
--- a/lustre/osc/osc_cache.c
+++ b/lustre/osc/osc_cache.c
@@ -1315,7 +1315,7 @@ static int osc_completion(const struct lu_env *env, struct osc_async_page *oap,
        /* statistic */
        if (rc == 0 && srvlock) {
                struct lu_device *ld = osc_page_object(opg)->oo_cl.co_lu.lo_dev;
-               struct osc_stats *stats = &lu2osc_dev(ld)->od_stats;
+               struct osc_stats *stats = &lu2osc_dev(ld)->osc_stats;
                size_t bytes = oap->oap_count;
 
                if (crt == CRT_READ)

diff --git a/lustre/osc/osc_dev.c b/lustre/osc/osc_dev.c
index 5464e50..a2d3bca 100644 (file)
--- a/lustre/osc/osc_dev.c
+++ b/lustre/osc/osc_dev.c
@@ -190,41 +190,42 @@ EXPORT_SYMBOL(osc_device_fini);
 struct lu_device *osc_device_free(const struct lu_env *env,
                                  struct lu_device *d)
 {
-       struct osc_device *od = lu2osc_dev(d);
+       struct osc_device *oc = lu2osc_dev(d);
 
        cl_device_fini(lu2cl_dev(d));
-       OBD_FREE_PTR(od);
+       OBD_FREE_PTR(oc);
        return NULL;
 }
 EXPORT_SYMBOL(osc_device_free);
 
 static struct lu_device *osc_device_alloc(const struct lu_env *env,
-                                          struct lu_device_type *t,
-                                          struct lustre_cfg *cfg)
+                                         struct lu_device_type *t,
+                                         struct lustre_cfg *cfg)
 {
-        struct lu_device *d;
-        struct osc_device *od;
-        struct obd_device *obd;
-        int rc;
-
-        OBD_ALLOC_PTR(od);
-        if (od == NULL)
-                RETURN(ERR_PTR(-ENOMEM));
-
-        cl_device_init(&od->od_cl, t);
-        d = osc2lu_dev(od);
-        d->ld_ops = &osc_lu_ops;
-
-        /* Setup OSC OBD */
-        obd = class_name2obd(lustre_cfg_string(cfg, 0));
-        LASSERT(obd != NULL);
-        rc = osc_setup(obd, cfg);
-        if (rc) {
-                osc_device_free(env, d);
-                RETURN(ERR_PTR(rc));
-        }
-        od->od_exp = obd->obd_self_export;
-        RETURN(d);
+       struct lu_device *d;
+       struct osc_device *osc;
+       struct obd_device *obd;
+       int rc;
+
+       OBD_ALLOC_PTR(osc);
+       if (osc == NULL)
+               RETURN(ERR_PTR(-ENOMEM));
+
+       cl_device_init(&osc->osc_cl, t);
+       d = osc2lu_dev(osc);
+       d->ld_ops = &osc_lu_ops;
+
+       /* Setup OSC OBD */
+       obd = class_name2obd(lustre_cfg_string(cfg, 0));
+       LASSERT(obd != NULL);
+       rc = osc_setup(obd, cfg);
+       if (rc) {
+               osc_device_free(env, d);
+               RETURN(ERR_PTR(rc));
+       }
+       osc->osc_exp = obd->obd_self_export;
+       osc->osc_stats.os_init = ktime_get_real();
+       RETURN(d);
 }
 
 static const struct lu_device_type_operations osc_device_type_ops = {

diff --git a/lustre/osp/lproc_osp.c b/lustre/osp/lproc_osp.c
index 6fa08c4..a93cfbd 100644 (file)
--- a/lustre/osp/lproc_osp.c
+++ b/lustre/osp/lproc_osp.c
@@ -890,6 +890,7 @@ static ssize_t osp_rpc_stats_seq_write(struct file *file,
        struct client_obd *cli = &dev->u.cli;
 
        lprocfs_oh_clear(&cli->cl_mod_rpcs_hist);
+       cli->cl_mod_rpcs_init = ktime_get_real();
 
        return len;
 }

diff --git a/lustre/tests/sanity.sh b/lustre/tests/sanity.sh
index 92aca85..3faa5e1 100755 (executable)
--- a/lustre/tests/sanity.sh
+++ b/lustre/tests/sanity.sh
@@ -13644,20 +13644,44 @@ run_test 126 "check that the fsgid provided by the client is taken into account"
 test_127a() { # bug 15521
        [ $PARALLEL == "yes" ] && skip "skip parallel run"
        local name count samp unit min max sum sumsq
+       local tmpfile=$TMP/$tfile.tmp
 
        $LFS setstripe -i 0 -c 1 $DIR/$tfile || error "setstripe failed"
        echo "stats before reset"
-       $LCTL get_param osc.*.stats
+       stack_trap "rm -f $tmpfile"
+       local now=$(date +%s)
+
+       $LCTL get_param osc.*.stats | tee $tmpfile
+
+       local snapshot_time=$(awk '/snapshot_time/ { print $2; exit }' $tmpfile)
+       local start_time=$(awk '/start_time/ { print $2; exit }' $tmpfile)
+       local elapsed=$(awk '/elapsed_time/ { print $2; exit }' $tmpfile)
+       local uptime=$(awk '{ print $1 }' /proc/uptime)
+
+       # snapshot_time should match POSIX epoch time, allow some delta for VMs
+       (( ${snapshot_time%\.*} >= $now - 5 &&
+          ${snapshot_time%\.*} <= $now + 5 )) ||
+               error "snapshot_time=$snapshot_time != now=$now"
+       # elapsed _should_ be from mount, but at least less than uptime
+       (( ${elapsed%\.*} < ${uptime%\.*} )) ||
+               error "elapsed=$elapsed > uptime=$uptime"
+       (( ${snapshot_time%\.*} - ${start_time%\.*} >= ${elapsed%\.*} - 2 &&
+          ${snapshot_time%\.*} - ${start_time%\.*} <= ${elapsed%\.*} + 2 )) ||
+               error "elapsed=$elapsed != $snapshot_time - $start_time"
+
        $LCTL set_param osc.*.stats=0
+       local reset=$(date +%s)
        local fsize=$((2048 * 1024))
 
        dd if=/dev/zero of=$DIR/$tfile bs=$fsize count=1
        cancel_lru_locks osc
        dd if=$DIR/$tfile of=/dev/null bs=$fsize
 
-       $LCTL get_param osc.*0000-osc-*.stats | grep samples > $DIR/$tfile.tmp
-       stack_trap "rm -f $TMP/$tfile.tmp"
+       now=$(date +%s)
+       $LCTL get_param osc.*0000-osc-*.stats > $tmpfile
        while read name count samp unit min max sum sumsq; do
+               [[ "$samp" == "samples" ]] || continue
+
                echo "got name=$name count=$count unit=$unit min=$min max=$max"
                [ ! $min ] && error "Missing min value for $name proc entry"
                eval $name=$count || error "Wrong proc format"
@@ -13682,13 +13706,29 @@ test_127a() { # bug 15521
                        ;;
                *)      ;;
                esac
-       done < $DIR/$tfile.tmp
+       done < $tmpfile
 
        #check that we actually got some stats
        [ "$read_bytes" ] || error "Missing read_bytes stats"
        [ "$write_bytes" ] || error "Missing write_bytes stats"
        [ "$read_bytes" != 0 ] || error "no read done"
        [ "$write_bytes" != 0 ] || error "no write done"
+
+       snapshot_time=$(awk '/snapshot_time/ { print $2; exit }' $tmpfile)
+       start_time=$(awk '/start_time/ { print $2; exit }' $tmpfile)
+       elapsed=$(awk '/elapsed_time/ { print $2; exit }' $tmpfile)
+
+       # snapshot_time should match POSIX epoch time, allow some delta for VMs
+       (( ${snapshot_time%\.*} >= $now - 5 &&
+          ${snapshot_time%\.*} <= $now + 5 )) ||
+               error "reset snapshot_time=$snapshot_time != now=$now"
+       # elapsed should be from time of stats reset
+       (( ${elapsed%\.*} >= $now - $reset - 2 &&
+          ${elapsed%\.*} <= $now - $reset + 2 )) ||
+               error "reset elapsed=$elapsed > $now - $reset"
+       (( ${snapshot_time%\.*} - ${start_time%\.*} >= ${elapsed%\.*} - 2 &&
+          ${snapshot_time%\.*} - ${start_time%\.*} <= ${elapsed%\.*} + 2 )) ||
+               error "reset elapsed=$elapsed != $snapshot_time - $start_time"
 }
 run_test 127a "verify the client stats are sane"