DHT/Rebalance - Ensure Rebalance reports status only once upon stopping (#1783)

DHT/Rebalance - Ensure Rebalance reports status only once upon stopping

Upon issuing rebalance stop command, the status of rebalance is being
logged twice to the log file, which can sometime result in an
inconsistent reports (one report states status stopped, while the other
may report something else).

This fix ensures rebalance reports it's status only once and that the
correct status is being reported.

fixes: #1782
Change-Id: Id3206edfad33b3db60e9df8e95a519928dc7cb37
Signed-off-by: Barak Sason Rofman <bsasonro@redhat.com>

4 files changed, 110 insertions, 37 deletions

diff --git a/tests/bugs/distribute/bug-1286171.t b/tests/bugs/distribute/bug-1286171.t
new file mode 100644
index 0000000000..a2ca36fa66
--- /dev/null
+++ b/tests/bugs/distribute/bug-1286171.t
@@ -0,0 +1,75 @@
+#!/bin/bash
+
+. $(dirname $0)/../../include.rc
+. $(dirname $0)/../../cluster.rc
+. $(dirname $0)/../../volume.rc
+
+# Initialize
+#------------------------------------------------------------
+cleanup;
+
+volname=bug-1286171
+
+# Start glusterd
+TEST glusterd;
+TEST pidof glusterd;
+TEST $CLI volume info;
+
+# Create a volume
+TEST $CLI volume create $volname $H0:$B0/${volname}{1,2}
+
+# Verify volume creation
+EXPECT "$volname" volinfo_field $volname 'Volume Name';
+EXPECT 'Created' volinfo_field $volname 'Status';
+
+# Start volume and verify successful start
+TEST $CLI volume start $volname;
+EXPECT 'Started' volinfo_field $volname 'Status';
+TEST glusterfs --volfile-id=$volname --volfile-server=$H0 --entry-timeout=0 $M0;
+#------------------------------------------------------------
+
+# Create a nested dir structure and some file under MP
+cd $M0;
+for i in {1..5}
+do
+	mkdir dir$i
+	cd dir$i
+	for j in {1..5}
+	do
+		mkdir dir$i$j
+		cd dir$i$j
+		for k in {1..5}
+		do
+			mkdir dir$i$j$k
+			cd dir$i$j$k
+			touch {1..300}
+			cd ..
+		done
+		touch {1..300}
+		cd ..
+	done
+	touch {1..300}
+	cd ..
+done
+touch {1..300}
+
+# Add-brick and start rebalance
+TEST $CLI volume add-brick $volname $H0:$B0/${volname}4;
+TEST $CLI volume rebalance $volname start;
+
+# Let rebalance run for a while
+sleep 5
+
+# Stop rebalance
+TEST $CLI volume rebalance $volname stop;
+
+# Allow rebalance to stop
+sleep 5
+
+# Examine the logfile for errors
+cd /var/log/glusterfs;
+failures=`grep "failures:" ${volname}-rebalance.log | tail -1 | sed 's/.*failures: //; s/,.*//'`;
+
+TEST [ $failures == 0 ];
+
+cleanup;
diff --git a/xlators/cluster/dht/src/dht-common.c b/xlators/cluster/dht/src/dht-common.c
index 10ae05db14..8c326b96c2 100644
--- a/xlators/cluster/dht/src/dht-common.c
+++ b/xlators/cluster/dht/src/dht-common.c
@@ -10964,7 +10964,7 @@ dht_notify(xlator_t *this, int event, void *data, ...)
                     goto unlock;
                 if ((cmd == GF_DEFRAG_CMD_STATUS) ||
                     (cmd == GF_DEFRAG_CMD_DETACH_STATUS))
-                    gf_defrag_status_get(conf, output);
+                    gf_defrag_status_get(conf, output, _gf_false);
                 else if (cmd == GF_DEFRAG_CMD_DETACH_START)
                     defrag->cmd = GF_DEFRAG_CMD_DETACH_START;
                 else if (cmd == GF_DEFRAG_CMD_STOP ||
diff --git a/xlators/cluster/dht/src/dht-common.h b/xlators/cluster/dht/src/dht-common.h
index fe0dc3db34..e5d24f5ea4 100644
--- a/xlators/cluster/dht/src/dht-common.h
+++ b/xlators/cluster/dht/src/dht-common.h
@@ -1134,7 +1134,7 @@ dht_common_xattrop_cbk(call_frame_t *frame, void *cookie, xlator_t *this,
                        int32_t op_ret, int32_t op_errno, dict_t *dict,
                        dict_t *xdata);
 int
-gf_defrag_status_get(dht_conf_t *conf, dict_t *dict);
+gf_defrag_status_get(dht_conf_t *conf, dict_t *dict, gf_boolean_t log_status);
 
 int
 gf_defrag_stop(dht_conf_t *conf, gf_defrag_status_t status, dict_t *output);
diff --git a/xlators/cluster/dht/src/dht-rebalance.c b/xlators/cluster/dht/src/dht-rebalance.c
index 3c4458c3b8..29da90bed6 100644
--- a/xlators/cluster/dht/src/dht-rebalance.c
+++ b/xlators/cluster/dht/src/dht-rebalance.c
@@ -2673,7 +2673,6 @@ gf_defrag_migrate_single_file(void *opaque)
     iatt_ptr = &entry->d_stat;
 
     if (defrag->defrag_status != GF_DEFRAG_STATUS_STARTED) {
-        ret = -1;
         goto out;
     }
 
@@ -2938,7 +2937,6 @@ gf_defrag_task(void *opaque)
     set_lk_owner_from_ptr(&lkowner, &lkowner);
     syncopctx_setfslkowner(&lkowner);
 
-
     q_head = &(defrag->queue[0].list);
 
     /* The following while loop will dequeue one entry from the defrag->queue
@@ -3693,7 +3691,6 @@ gf_defrag_fix_layout(xlator_t *this, gf_defrag_info_t *defrag, loc_t *loc,
         list_for_each_entry_safe(entry, tmp, &entries.list, list)
         {
             if (defrag->defrag_status != GF_DEFRAG_STATUS_STARTED) {
-                ret = 1;
                 goto out;
             }
 
@@ -4451,12 +4448,10 @@ out:
         gf_defrag_estimates_cleanup(this, defrag, filecnt_thread);
     }
 
-    dht_send_rebalance_event(this, defrag->cmd, defrag->defrag_status);
-
     status = dict_new();
     LOCK(&defrag->lock);
     {
-        gf_defrag_status_get(conf, status);
+        gf_defrag_status_get(conf, status, _gf_true);
         if (ctx && ctx->notify)
             ctx->notify(GF_EN_DEFRAG_STATUS, status);
         if (status)
@@ -4465,6 +4460,8 @@ out:
     }
     UNLOCK(&defrag->lock);
 
+    dht_send_rebalance_event(this, defrag->cmd, defrag->defrag_status);
+
     GF_FREE(defrag);
     conf->defrag = NULL;
 
@@ -4587,7 +4584,7 @@ out:
 }
 
 int
-gf_defrag_status_get(dht_conf_t *conf, dict_t *dict)
+gf_defrag_status_get(dht_conf_t *conf, dict_t *dict, gf_boolean_t log_status)
 {
     int ret = 0;
     uint64_t files = 0;
@@ -4666,34 +4663,35 @@ gf_defrag_status_get(dht_conf_t *conf, dict_t *dict)
         gf_log(THIS->name, GF_LOG_WARNING, "failed to set time-left");
 
 log:
-    switch (defrag->defrag_status) {
-        case GF_DEFRAG_STATUS_NOT_STARTED:
-            status = "not started";
-            break;
-        case GF_DEFRAG_STATUS_STARTED:
-            status = "in progress";
-            break;
-        case GF_DEFRAG_STATUS_STOPPED:
-            status = "stopped";
-            break;
-        case GF_DEFRAG_STATUS_COMPLETE:
-            status = "completed";
-            break;
-        case GF_DEFRAG_STATUS_FAILED:
-            status = "failed";
-            break;
-        default:
-            break;
-    }
+    if (log_status) {
+        switch (defrag->defrag_status) {
+            case GF_DEFRAG_STATUS_NOT_STARTED:
+                status = "not started";
+                break;
+            case GF_DEFRAG_STATUS_STARTED:
+                status = "in progress";
+                break;
+            case GF_DEFRAG_STATUS_STOPPED:
+                status = "stopped";
+                break;
+            case GF_DEFRAG_STATUS_COMPLETE:
+                status = "completed";
+                break;
+            case GF_DEFRAG_STATUS_FAILED:
+                status = "failed";
+                break;
+            default:
+                break;
+        }
 
-    gf_msg(THIS->name, GF_LOG_INFO, 0, DHT_MSG_REBALANCE_STATUS,
-           "Rebalance is %s. Time taken is %.2f secs", status, elapsed);
-    gf_msg(THIS->name, GF_LOG_INFO, 0, DHT_MSG_REBALANCE_STATUS,
-           "Files migrated: %" PRIu64 ", size: %" PRIu64 ", lookups: %" PRIu64
-           ", failures: %" PRIu64
-           ", skipped: "
-           "%" PRIu64,
-           files, size, lookup, failures, skipped);
+        gf_msg("DHT", GF_LOG_INFO, 0, DHT_MSG_REBALANCE_STATUS,
+               "Rebalance is %s. Time taken is %.2f secs "
+               "Files migrated: %" PRIu64 ", size: %" PRIu64
+               ", lookups: %" PRIu64 ", failures: %" PRIu64
+               ", skipped: "
+               "%" PRIu64,
+               status, elapsed, files, size, lookup, failures, skipped);
+    }
 out:
     return 0;
 }
@@ -4717,7 +4715,7 @@ gf_defrag_stop(dht_conf_t *conf, gf_defrag_status_t status, dict_t *output)
     defrag->defrag_status = status;
 
     if (output)
-        gf_defrag_status_get(conf, output);
+        gf_defrag_status_get(conf, output, _gf_false);
     ret = 0;
 out:
     gf_msg_debug("", 0, "Returning %d", ret);