bitrot: getting correct value of scrub stat's

When user execute bitrot scrub status command then gluster
is not giving correct value of Number of Scrubbed files,
Number of Unsigned files, Last completed scrub time,
Duration of last scrub.

With this patch scrub status will give correct value for
all the above fields.

Change-Id: Ic966f76d22db5b0c889e6386a1c2219afbda1f49
BUG: 1285989
Signed-off-by: Gaurav Kumar Garg <ggarg@redhat.com>
Signed-off-by: Kotresh HR <khiremat@redhat.com>
Reviewed-on: http://review.gluster.org/12776
Tested-by: NetBSD Build System <jenkins@build.gluster.org>
Tested-by: Gluster Build System <jenkins@build.gluster.com>
Reviewed-by: Venky Shankar <vshankar@redhat.com>

6 files changed, 220 insertions, 41 deletions

diff --git a/cli/src/cli-rpc-ops.c b/cli/src/cli-rpc-ops.c
index 022f5a1d5f3..d59ff8b6d2c 100644
--- a/cli/src/cli-rpc-ops.c
+++ b/cli/src/cli-rpc-ops.c
@@ -10730,7 +10730,11 @@ gf_cli_print_bitrot_scrub_status (dict_t *dict)
         uint64_t       scrub_files      = 0;
         uint64_t       unsigned_files   = 0;
         uint64_t       scrub_time       = 0;
-        uint64_t       last_scrub       = 0;
+        uint64_t       days             = 0;
+        uint64_t       hour             = 0;
+        uint64_t       minut            = 0;
+        uint64_t       second           = 0;
+        char          *last_scrub       = NULL;
         uint64_t       error_count      = 0;
 
 
@@ -10784,8 +10788,12 @@ gf_cli_print_bitrot_scrub_status (dict_t *dict)
         for (i = 1; i <= count; i++) {
                 /* Reset the variables to prevent carryover of values */
                 node_name       = NULL;
-                last_scrub      = 0;
+                last_scrub      = NULL;
                 scrub_time      = 0;
+                days            = 0;
+                hour            = 0;
+                minut           = 0;
+                second          = 0;
                 error_count     = 0;
                 scrub_files     = 0;
                 unsigned_files  = 0;
@@ -10819,7 +10827,7 @@ gf_cli_print_bitrot_scrub_status (dict_t *dict)
 
                 memset (key, 0, 256);
                 snprintf (key, 256, "last-scrub-time-%d", i);
-                ret = dict_get_uint64 (dict, key, &last_scrub);
+                ret = dict_get_str (dict, key, &last_scrub);
                 if (ret)
                         gf_log ("cli", GF_LOG_TRACE, "failed to get last scrub"
                                 " time");
@@ -10842,11 +10850,17 @@ gf_cli_print_bitrot_scrub_status (dict_t *dict)
                 cli_out ("%s: %"PRIu64 "\n", "Number of Unsigned files",
                           unsigned_files);
 
-                cli_out ("%s: %"PRIu64 "\n", "Last completed scrub time",
-                          scrub_time);
-
-                cli_out ("%s: %"PRIu64 "\n", "Duration of last scrub",
-                          last_scrub);
+                cli_out ("%s: %s\n", "Last completed scrub time",
+                          (*last_scrub) ? last_scrub : "Scrubber pending to "
+                           "complete.");
+
+                /* Printing last scrub duration time in human readable form*/
+                days       = scrub_time/86400;
+                hour       = (scrub_time%86400)/3600;
+                minut      = (scrub_time%86400%3600)/60;
+                second     = (scrub_time%86400%3600%60);
+                cli_out ("%s: %"PRIu64 ":%"PRIu64 ":%"PRIu64 ":%"PRIu64 "\n",
+                         "Duration of last scrub", days, hour, minut, second);
 
                 cli_out ("%s: %"PRIu64 "\n", "Error count", error_count);
 
diff --git a/tests/bitrot/bug-1207627-bitrot-scrub-status.t b/tests/bitrot/bug-1207627-bitrot-scrub-status.t
index 0bbcb38cde2..bca3919e2ac 100644
--- a/tests/bitrot/bug-1207627-bitrot-scrub-status.t
+++ b/tests/bitrot/bug-1207627-bitrot-scrub-status.t
@@ -33,11 +33,4 @@ EXPECT_WITHIN $PROCESS_UP_TIMEOUT 'hourly' scrub_status $V0 'Scrub frequency'
 EXPECT_WITHIN $PROCESS_UP_TIMEOUT '/var/log/glusterfs/bitd.log' scrub_status $V0 'Bitrot error log location'
 EXPECT_WITHIN $PROCESS_UP_TIMEOUT '/var/log/glusterfs/scrub.log' scrub_status $V0 'Scrubber error log location'
 
-EXPECT_WITHIN $PROCESS_UP_TIMEOUT '0' scrub_status $V0 'Number of Scrubbed files'
-EXPECT_WITHIN $PROCESS_UP_TIMEOUT '0' scrub_status $V0 'Number of Unsigned files'
-EXPECT_WITHIN $PROCESS_UP_TIMEOUT '0' scrub_status $V0 'Last completed scrub time'
-EXPECT_WITHIN $PROCESS_UP_TIMEOUT '0' scrub_status $V0 'Duration of last scrub'
-EXPECT_WITHIN $PROCESS_UP_TIMEOUT '0' scrub_status $V0 'Error count'
-
-
 cleanup;
diff --git a/xlators/features/bit-rot/src/bitd/bit-rot-scrub.c b/xlators/features/bit-rot/src/bitd/bit-rot-scrub.c
index f776347e6d5..0a7212cd828 100644
--- a/xlators/features/bit-rot/src/bitd/bit-rot-scrub.c
+++ b/xlators/features/bit-rot/src/bitd/bit-rot-scrub.c
@@ -74,6 +74,20 @@ bitd_fetch_signature (xlator_t *this, br_child_t *child,
 
 }
 
+static void
+br_inc_unsigned_file_count (xlator_t *this)
+{
+        br_private_t   *priv = NULL;
+
+        priv = this->private;
+
+        pthread_mutex_lock (&priv->scrub_stat.lock);
+        {
+                priv->scrub_stat.unsigned_files++;
+        }
+        pthread_mutex_unlock (&priv->scrub_stat.lock);
+}
+
 /**
  * POST COMPUTE CHECK
  *
@@ -107,6 +121,7 @@ bitd_scrub_post_compute_check (xlator_t *this,
          * The log entry looks pretty ugly, but helps in debugging..
          */
         if (signptr->stale || (signptr->version != version)) {
+                br_inc_unsigned_file_count (this);
                 gf_msg_debug (this->name, 0, "<STAGE: POST> Object [GFID: %s] "
                               "either has a stale signature OR underwent "
                               "signing during checksumming {Stale: %d | "
@@ -181,6 +196,7 @@ bitd_scrub_pre_compute_check (xlator_t *this, br_child_t *child,
 
         ret = bitd_signature_staleness (this, child, fd, &stale, version);
         if (!ret && stale) {
+                br_inc_unsigned_file_count (this);
                 gf_msg_debug (this->name, 0, "<STAGE: PRE> Object [GFID: %s] "
                               "has stale signature",
                               uuid_utoa (fd->inode->gfid));
@@ -256,6 +272,16 @@ bitd_compare_ckum (xlator_t *this,
         return ret;
 }
 
+static void
+br_inc_scrubbed_file (br_private_t *priv)
+{
+        pthread_mutex_lock (&priv->scrub_stat.lock);
+        {
+                priv->scrub_stat.scrubbed_files++;
+        }
+        pthread_mutex_unlock (&priv->scrub_stat.lock);
+}
+
 /**
  * "The Scrubber"
  *
@@ -266,19 +292,20 @@ bitd_compare_ckum (xlator_t *this,
 int
 br_scrubber_scrub_begin (xlator_t *this, struct br_fsscan_entry *fsentry)
 {
-        int32_t              ret           = -1;
-        fd_t                *fd            = NULL;
-        loc_t                loc           = {0, };
-        struct iatt          iatt          = {0, };
-        struct iatt          parent_buf    = {0, };
-        pid_t                pid           = 0;
-        br_child_t          *child         = NULL;
-        unsigned char       *md            = NULL;
-        inode_t             *linked_inode  = NULL;
-        br_isignature_out_t *sign          = NULL;
-        unsigned long        signedversion = 0;
-        gf_dirent_t         *entry         = NULL;
-        loc_t               *parent        = NULL;
+        int32_t                ret           = -1;
+        fd_t                  *fd            = NULL;
+        loc_t                  loc           = {0, };
+        struct iatt            iatt          = {0, };
+        struct iatt            parent_buf    = {0, };
+        pid_t                  pid           = 0;
+        br_child_t            *child         = NULL;
+        unsigned char         *md            = NULL;
+        inode_t               *linked_inode  = NULL;
+        br_isignature_out_t   *sign          = NULL;
+        unsigned long          signedversion = 0;
+        gf_dirent_t           *entry         = NULL;
+        br_private_t          *priv          = NULL;
+        loc_t                 *parent        = NULL;
 
         GF_VALIDATE_OR_GOTO ("bit-rot", fsentry, out);
 
@@ -286,9 +313,12 @@ br_scrubber_scrub_begin (xlator_t *this, struct br_fsscan_entry *fsentry)
         parent = &fsentry->parent;
         child = fsentry->data;
 
+        priv = this->private;
+
         GF_VALIDATE_OR_GOTO ("bit-rot", entry, out);
         GF_VALIDATE_OR_GOTO ("bit-rot", parent, out);
         GF_VALIDATE_OR_GOTO ("bit-rot", child, out);
+        GF_VALIDATE_OR_GOTO ("bit-rot", priv, out);
 
         pid = GF_CLIENT_PID_SCRUB;
 
@@ -375,6 +405,9 @@ br_scrubber_scrub_begin (xlator_t *this, struct br_fsscan_entry *fsentry)
         ret = bitd_compare_ckum (this, sign, md,
                                  linked_inode, entry, fd, child, &loc);
 
+        /* Increment of total number of scrubbed file counter */
+        br_inc_scrubbed_file (priv);
+
         GF_FREE (sign); /* alloced on post-compute */
 
         /** fd_unref() takes care of closing fd.. like syncop_close() */
@@ -553,21 +586,72 @@ br_fsscan_deactivate (xlator_t *this, br_child_t *child)
 
         return 0;
 }
+static void
+br_update_scrub_start_time (xlator_t *this, struct timeval *tv)
+{
+        br_private_t     *priv = NULL;
+        static int       child;
+
+        priv = this->private;
+
+
+        /* Setting scrubber starting time for first child only */
+        if (child == 0) {
+                pthread_mutex_lock (&priv->scrub_stat.lock);
+                {
+                        priv->scrub_stat.scrub_start_tv.tv_sec = tv->tv_sec;
+                }
+                pthread_mutex_unlock (&priv->scrub_stat.lock);
+        }
+
+        if (++child == priv->up_children) {
+                child = 0;
+        }
+}
+
+static void
+br_update_scrub_finish_time (xlator_t *this, char *timestr, struct timeval *tv)
+{
+        br_private_t     *priv = NULL;
+        static int       child;
+
+        priv = this->private;
+
+        /*Setting scrubber finishing time at time time of last child operation*/
+        if (++child == priv->up_children) {
+                pthread_mutex_lock (&priv->scrub_stat.lock);
+                {
+                        priv->scrub_stat.scrub_end_tv.tv_sec = tv->tv_sec;
+
+                        priv->scrub_stat.scrub_duration =
+                                         priv->scrub_stat.scrub_end_tv.tv_sec -
+                                         priv->scrub_stat.scrub_start_tv.tv_sec;
+
+                        strncpy (priv->scrub_stat.last_scrub_time, timestr,
+                                 sizeof (priv->scrub_stat.last_scrub_time));
+
+                        child = 0;
+                }
+                pthread_mutex_unlock (&priv->scrub_stat.lock);
+        }
+}
 
 static void
 br_fsscanner_log_time (xlator_t *this, br_child_t *child, const char *sfx)
 {
-        struct timeval tv = {0,};
-        char timestr[1024] = {0,};
+        char           timestr[1024] = {0,};
+        struct         timeval tv    = {0,};
 
         gettimeofday (&tv, NULL);
         gf_time_fmt (timestr, sizeof (timestr), tv.tv_sec, gf_timefmt_FT);
 
         if (strcasecmp (sfx, "started") == 0) {
+                br_update_scrub_start_time (this, &tv);
                 gf_msg (this->name, GF_LOG_INFO, 0, BRB_MSG_SCRUB_START,
                         "Scrubbing \"%s\" %s at %s", child->brick_path, sfx,
                         timestr);
         } else {
+                br_update_scrub_finish_time (this, timestr, &tv);
                 gf_msg (this->name, GF_LOG_INFO, 0, BRB_MSG_SCRUB_FINISH,
                         "Scrubbing \"%s\" %s at %s", child->brick_path, sfx,
                         timestr);
@@ -575,14 +659,33 @@ br_fsscanner_log_time (xlator_t *this, br_child_t *child, const char *sfx)
 }
 
 static void
-br_fsscanner_wait_until_kicked (struct br_scanfs *fsscan)
+br_fsscanner_wait_until_kicked (xlator_t *this, struct br_scanfs *fsscan)
 {
+        static int            i;
+        br_private_t         *priv    = NULL;
+
+        priv = this->private;
+
         pthread_cleanup_push (_br_lock_cleaner, &fsscan->wakelock);
         pthread_mutex_lock (&fsscan->wakelock);
         {
                 while (!fsscan->kick)
                         pthread_cond_wait (&fsscan->wakecond,
                                            &fsscan->wakelock);
+
+                /* resetting total number of scrubbed file when scrubbing
+                 * done for all of its children */
+                if (i == priv->up_children) {
+                        pthread_mutex_lock (&priv->scrub_stat.lock);
+                        {
+                                priv->scrub_stat.scrubbed_files = 0;
+                                priv->scrub_stat.unsigned_files = 0;
+                                i = 0;
+                        }
+                        pthread_mutex_unlock (&priv->scrub_stat.lock);
+                }
+                ++i;
+
                 fsscan->kick = _gf_false;
         }
         pthread_mutex_unlock (&fsscan->wakelock);
@@ -640,7 +743,7 @@ br_fsscanner (void *arg)
         loc.inode = child->table->root;
 
         while (1) {
-                br_fsscanner_wait_until_kicked (fsscan);
+                br_fsscanner_wait_until_kicked (this, fsscan);
                 {
                         /* precursor for scrub */
                         br_fsscanner_entry_control (this, child);
diff --git a/xlators/features/bit-rot/src/bitd/bit-rot.c b/xlators/features/bit-rot/src/bitd/bit-rot.c
index b28bf2622af..4ee2020aaf1 100644
--- a/xlators/features/bit-rot/src/bitd/bit-rot.c
+++ b/xlators/features/bit-rot/src/bitd/bit-rot.c
@@ -1550,7 +1550,16 @@ int
 br_scrubber_status_get (xlator_t *this, dict_t **dict)
 {
 
-        int               ret    = -1;
+        int                    ret          = -1;
+        char                   key[256]     = {0,};
+        br_private_t          *priv         = NULL;
+        struct br_scrub_stats *scrub_stats  = NULL;
+
+        priv = this->private;
+
+        GF_VALIDATE_OR_GOTO ("bit-rot", priv, out);
+
+        scrub_stats = &priv->scrub_stat;
 
         ret = br_get_bad_objects_list (this, dict);
         if (ret) {
@@ -1558,6 +1567,40 @@ br_scrubber_status_get (xlator_t *this, dict_t **dict)
                               "files");
         }
 
+        memset (key, 0, 256);
+        snprintf (key, 256, "scrubbed-files");
+        ret = dict_set_uint32 (*dict, key, scrub_stats->scrubbed_files);
+        if (ret) {
+                gf_msg_debug (this->name, 0, "Failed to setting scrubbed file "
+                              "entry to the dictionary");
+        }
+
+        memset (key, 0, 256);
+        snprintf (key, 256, "unsigned-files");
+        ret = dict_set_uint32 (*dict, key, scrub_stats->unsigned_files);
+        if (ret) {
+                gf_msg_debug (this->name, 0, "Failed to set unsigned file count"
+                              " entry to the dictionary");
+        }
+
+        memset (key, 0, 256);
+        snprintf (key, 256, "scrub-duration");
+        ret = dict_set_uint32 (*dict, key, scrub_stats->scrub_duration);
+        if (ret) {
+                gf_msg_debug (this->name, 0, "Failed to set scrub duration"
+                              " entry to the dictionary");
+        }
+
+        memset (key, 0, 256);
+        snprintf (key, 256, "last-scrub-time");
+        ret = dict_set_dynstr_with_alloc (*dict, key,
+                                          scrub_stats->last_scrub_time);
+        if (ret) {
+                gf_msg_debug (this->name, 0, "Failed to set "
+                                      "last scrub time value");
+        }
+
+out:
         return ret;
 }
 
diff --git a/xlators/features/bit-rot/src/bitd/bit-rot.h b/xlators/features/bit-rot/src/bitd/bit-rot.h
index 16892a7e3fd..04336e641d0 100644
--- a/xlators/features/bit-rot/src/bitd/bit-rot.h
+++ b/xlators/features/bit-rot/src/bitd/bit-rot.h
@@ -154,6 +154,26 @@ struct br_scrubber {
 
 typedef struct br_obj_n_workers br_obj_n_workers_t;
 
+typedef struct br_private br_private_t;
+
+typedef void (*br_scrubbed_file_update) (br_private_t *priv);
+
+struct br_scrub_stats {
+        uint32_t       scrubbed_files;       /* Total number of scrubbed file */
+
+        uint32_t       unsigned_files;       /* Total number of unsigned file */
+
+        uint32_t       scrub_duration;            /* Duration of last scrub */
+
+        char           last_scrub_time[1024];    /*last scrub completion time */
+
+        struct         timeval scrub_start_tv;   /* Scrubbing starting time*/
+
+        struct         timeval scrub_end_tv;     /* Scrubbing finishing time */
+
+        pthread_mutex_t  lock;
+};
+
 struct br_private {
         pthread_mutex_t lock;
 
@@ -179,17 +199,18 @@ struct br_private {
                                              and ready to be picked up for
                                              signing and the workers which sign
                                              the objects */
+
         uint32_t expiry_time;              /* objects "wait" time */
 
         br_tbf_t *tbf;                    /* token bucket filter */
 
         gf_boolean_t iamscrubber;         /* function as a fs scrubber */
 
+        struct br_scrub_stats scrub_stat; /* statistics of scrub*/
+
         struct br_scrubber fsscrub;       /* scrubbers for this subvolume */
 };
 
-typedef struct br_private br_private_t;
-
 struct br_object {
         xlator_t *this;
 
diff --git a/xlators/mgmt/glusterd/src/glusterd-utils.c b/xlators/mgmt/glusterd/src/glusterd-utils.c
index d24c3dff12d..a388ac113c8 100644
--- a/xlators/mgmt/glusterd/src/glusterd-utils.c
+++ b/xlators/mgmt/glusterd/src/glusterd-utils.c
@@ -8326,7 +8326,8 @@ glusterd_volume_bitrot_scrub_use_rsp_dict (dict_t *aggr, dict_t *rsp_dict)
         uint64_t                 scrubbed_files     = 0;
         uint64_t                 unsigned_files     = 0;
         uint64_t                 scrub_duration     = 0;
-        uint64_t                 last_scrub_time    = 0;
+        char                    *last_scrub_time    = NULL;
+        char                    *scrub_time         = NULL;
         char                    *volname            = NULL;
         char                    *node_uuid          = NULL;
         char                    *node_uuid_str      = NULL;
@@ -8418,11 +8419,12 @@ glusterd_volume_bitrot_scrub_use_rsp_dict (dict_t *aggr, dict_t *rsp_dict)
 
         memset (key, 0, 256);
         snprintf (key, 256, "last-scrub-time-%d", src_count);
-        ret = dict_get_uint64 (rsp_dict, key, &value);
+        ret = dict_get_str (rsp_dict, key, &last_scrub_time);
         if (!ret) {
+                scrub_time = gf_strdup (last_scrub_time);
                 memset (key, 0, 256);
                 snprintf (key, 256, "last-scrub-time-%d", src_count+dst_count);
-                ret = dict_set_uint64 (aggr, key, value);
+                ret = dict_set_dynstr (aggr, key, scrub_time);
                 if (ret) {
                         gf_msg_debug (this->name, 0, "Failed to set "
                                       "last scrub time value");
@@ -8544,7 +8546,8 @@ glusterd_bitrot_volume_node_rsp (dict_t *aggr, dict_t *rsp_dict)
         uint64_t                 scrubbed_files     = 0;
         uint64_t                 unsigned_files     = 0;
         uint64_t                 scrub_duration     = 0;
-        uint64_t                 last_scrub_time    = 0;
+        char                    *last_scrub_time    = NULL;
+        char                    *scrub_time         = NULL;
         char                    *volname            = NULL;
         char                    *node_str           = NULL;
         char                    *scrub_freq         = NULL;
@@ -8685,11 +8688,13 @@ glusterd_bitrot_volume_node_rsp (dict_t *aggr, dict_t *rsp_dict)
                 }
         }
 
-        ret = dict_get_uint64 (rsp_dict, "last-scrub-time", &value);
+        ret = dict_get_str (rsp_dict, "last-scrub-time", &last_scrub_time);
         if (!ret) {
                 memset (key, 0, 256);
                 snprintf (key, 256, "last-scrub-time-%d", i);
-                ret = dict_set_uint64 (aggr, key, value);
+
+                scrub_time = gf_strdup (last_scrub_time);
+                ret = dict_set_dynstr (aggr, key, scrub_time);
                 if (ret) {
                         gf_msg_debug (this->name, 0, "Failed to set "
                                       "last scrub time value");