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.

Lustre-change: https://review.whamcloud.com/48821
Lustre-commit: e42efe35eec7b9725f7f4fff86aaee04093366b0

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/+/49220
Reviewed-by: Oleg Drokin <green@whamcloud.com>
Tested-by: jenkins <devops@whamcloud.com>
Tested-by: Maloo <maloo@whamcloud.com>

diff --git a/lustre/include/lustre_osc.h b/lustre/include/lustre_osc.h
index 5c3a157..60300fa 100644 (file)
--- a/lustre/include/lustre_osc.h
+++ b/lustre/include/lustre_osc.h
@@ -100,18 +100,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;
@@ -758,12 +758,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)
@@ -784,12 +784,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 62c182c..855269c 100644 (file)
--- a/lustre/ldlm/ldlm_lib.c
+++ b/lustre/ldlm/ldlm_lib.c
@@ -509,6 +509,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 ddcbc79..a67415e 100644 (file)
--- a/lustre/llite/lproc_llite.c
+++ b/lustre/llite/lproc_llite.c
@@ -2016,8 +2016,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%");
@@ -2048,6 +2048,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)
@@ -2070,6 +2071,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)
@@ -2133,7 +2135,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);
@@ -2158,8 +2160,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",
@@ -2202,7 +2204,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);
@@ -2341,8 +2343,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");
@@ -2409,7 +2411,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 dfa02fb..cd91f3d 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 2705461..45c0f3d 100644 (file)
--- a/lustre/mdc/mdc_dev.c
+++ b/lustre/mdc/mdc_dev.c
@@ -1583,16 +1583,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 */
@@ -1605,7 +1605,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_lproc.c b/lustre/mdt/mdt_lproc.c
index 954bc94..02eda11 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 2450ccf..787a67c 100644 (file)
--- a/lustre/obdclass/genops.c
+++ b/lustre/obdclass/genops.c
@@ -2198,7 +2198,7 @@ int obd_mod_rpc_stats_seq_show(struct client_obd *cli,
        int i;
 
        spin_lock(&cli->cl_mod_rpcs_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 5583462..fd8e57a 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);
 
        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++) {
@@ -639,7 +638,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 a2e7abf..1d2f4cc 100644 (file)
--- a/lustre/obdclass/lprocfs_status.c
+++ b/lustre/obdclass/lprocfs_status.c
@@ -1221,6 +1221,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 */
@@ -1326,6 +1327,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);
 }
@@ -1407,8 +1409,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 a437310..abf3906 100644 (file)
--- a/lustre/obdclass/lprocfs_status_server.c
+++ b/lustre/obdclass/lprocfs_status_server.c
@@ -776,8 +776,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)
@@ -803,6 +803,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;
 }
@@ -839,7 +840,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 d8be376..7883eb7 100644 (file)
--- a/lustre/osc/osc_cache.c
+++ b/lustre/osc/osc_cache.c
@@ -1324,7 +1324,7 @@ static int osc_completion(const struct lu_env *env, struct osc_async_page *oap,
        /* statistic */
        if (rc == 0 && srvlock) {
                struct lu_device *ld    = opg->ops_cl.cpl_obj->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 f0eb765..4a11e55 100644 (file)
--- a/lustre/osp/lproc_osp.c
+++ b/lustre/osp/lproc_osp.c
@@ -836,6 +836,7 @@ LDEBUGFS_SEQ_FOPS_RO_TYPE(osp, timeouts);
 LDEBUGFS_SEQ_FOPS_RW_TYPE(osp, import);
 LDEBUGFS_SEQ_FOPS_RO_TYPE(osp, state);
 
+
 /**
  * Show high watermark (in megabytes). If available free space at OST is grater
  * than high watermark and object allocation for OST is disabled, enable it.

diff --git a/lustre/tests/sanity.sh b/lustre/tests/sanity.sh
index 1533e55..4acd8d5 100755 (executable)
--- a/lustre/tests/sanity.sh
+++ b/lustre/tests/sanity.sh
@@ -13367,20 +13367,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"
@@ -13405,13 +13429,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"