rebalancer: add replicaset.id in "Some buckets are not active" log

Before this patch the function `rebalancer_download_states` didn't
return information about replicaset from which the states could not
be downloaded. As a result, the log "Some buckets are not active
..." lacks of valuable information about unhealthy replicaset.

Now, we add replicaset.id in error which is returned from
`rebalancer_download_states`. It can help us to propagate replicaset.id
to "Some buckets are not active ..." and "Error during downloading
rebalancer states ..." log.

Also we change `rebalancer/rebalancer.test.lua` test which expected
the old "Some buckets are not active" log without replicaset.id.

Closes #212

NO_DOC=bugfix

Author: mrForza

test/rebalancer/rebalancer.result

@@ -318,7 +318,13 @@ _bucket:update({150}, {{'=', 2, vshard.consts.BUCKET.RECEIVING}})
 ---
 - [150, 'receiving']
 ...
-wait_rebalancer_state("Some buckets are not active", test_run)
+formatted_replicaset_uuid = string.gsub(util.replicasets[1], '%-', '%%-')
+---
+...
+log_msg = string.format('Some buckets in replicaset %s are not active', formatted_replicaset_uuid)
+---
+...
+wait_rebalancer_state(log_msg, test_run)
 ---
 ...
 _bucket:update({150}, {{'=', 2, vshard.consts.BUCKET.ACTIVE}})

test/rebalancer/rebalancer.test.lua

@@ -156,7 +156,9 @@ util.map_bucket_protection(test_run, {REPLICASET_1}, false)
 test_run:switch('box_1_a')
 vshard.storage.rebalancer_enable()
 _bucket:update({150}, {{'=', 2, vshard.consts.BUCKET.RECEIVING}})
-wait_rebalancer_state("Some buckets are not active", test_run)
+formatted_replicaset_uuid = string.gsub(util.replicasets[1], '%-', '%%-')
+log_msg = string.format('Some buckets in replicaset %s are not active', formatted_replicaset_uuid)
+wait_rebalancer_state(log_msg, test_run)
 _bucket:update({150}, {{'=', 2, vshard.consts.BUCKET.ACTIVE}})
 vshard.storage.sync()
 

test/storage-luatest/storage_1_1_1_test.lua

@@ -220,3 +220,20 @@ rebalancer_recovery_group.test_rebalancer_routes_logging = function(g)
         g.replica_1_a:grep_log('The cluster is balanced ok.')
     end)
 end
+
+rebalancer_recovery_group.test_no_log_spam_when_buckets_no_active = function(g)
+    local moved_bucket = vtest.storage_first_bucket(g.replica_2_a)
+    start_bucket_move(g.replica_1_a, g.replica_2_a, moved_bucket)
+    wait_for_bucket_is_transferred(g.replica_1_a, g.replica_2_a, moved_bucket)
+    vtest.storage_stop(g.replica_2_a)
+    local buckets_not_active = string.format('Some buckets in replicaset ' ..
+                                             '%s are not active',
+                                             g.replica_2_a:replicaset_uuid())
+    t.helpers.retrying({timeout = 60}, function()
+        g.replica_1_a:exec(function() ivshard.storage.rebalancer_wakeup() end)
+        t.assert(g.replica_1_a:grep_log(buckets_not_active))
+    end)
+    vtest.storage_start(g.replica_2_a, global_cfg)
+    start_bucket_move(g.replica_2_a, g.replica_1_a, moved_bucket)
+    wait_for_bucket_is_transferred(g.replica_2_a, g.replica_1_a, moved_bucket)
+end

vshard/storage/init.lua

@@ -2806,6 +2806,7 @@ local function rebalancer_download_states()
             replicaset, 'vshard.storage.rebalancer_request_state', {},
             {timeout = consts.REBALANCER_GET_STATE_TIMEOUT})
         if state == nil then
+            err.replicaset_id = replicaset.id
             return nil, err
         end
         local bucket_count = state.bucket_active_count +
@@ -2854,9 +2855,11 @@ local function rebalancer_service_f(service, limiter)
             local err = status and total_bucket_active_count or replicasets
             if err then
                 limiter:log_error(err, service:set_status_error(
-                    'Error during downloading rebalancer states: %s', err))
+                    'Error during downloading rebalancer states: %s',
+                    err.replicaset_id))
             end
-            log.info('Some buckets are not active, retry rebalancing later')
+            log.info('Some buckets in replicaset %s are not active, retry ' ..
+                     'rebalancing later', err and err.replicaset_id)
             service:set_activity('idling')
             lfiber.testcancel()
             lfiber.sleep(consts.REBALANCER_WORK_INTERVAL)