rebalancer: reduce spam in logs

Before this patch "Some buckets are not active ..." logs were printed every
`REBALANCER_WORK_INTERVAL` seconds, flooding the log file with redundant
entries. Also these records were lacking of information about the current
replicaset. This patch fixes the issue by limiting this log frequency and
adding information about replicaset's id to log messages.

Part of #212

NO_DOC=bugfix

Author: mrForza

test/storage-luatest/storage_1_1_1_test.lua

@@ -247,3 +247,26 @@ rebalancer_recovery_group.test_rebalancer_routes_logging = function(g)
     t.assert(g.replica_1_a:grep_log(route_1_to_2))
     t.assert(g.replica_1_a:grep_log(route_1_to_3))
 end
+
+rebalancer_recovery_group.test_no_log_spam_when_buckets_no_active = function(g)
+    g.replica_2_a:stop()
+    g.replica_1_a:exec(function()
+        rawset(_G, 'old_rebalancer_interval', ivconst.REBALANCER_WORK_INTERVAL)
+        rawset(_G, 'old_rebalancer_timeout',
+               ivconst.REBALANCER_GET_STATE_TIMEOUT)
+        ivconst.REBALANCER_WORK_INTERVAL = 0.01
+        ivconst.REBALANCER_GET_STATE_TIMEOUT = 0.01
+    end)
+
+    t.helpers.retrying({timeout = 10}, function()
+        t.assert(g.replica_1_a:grep_log(g.buckets_not_active_log))
+    end)
+    test_only_one_record_appears_in_logs(g.replica_1_a,
+                                         g.buckets_not_active_pattern,
+                                         g.rebalancer_wait_interval * 2)
+    g.replica_1_a:exec(function()
+        ivconst.REBALANCER_WORK_INTERVAL = _G.old_rebalancer_interval
+        ivconst.REBALANCER_GET_STATE_TIMEOUT = _G.old_rebalancer_timeout
+    end)
+    g.replica_2_a:start()
+end

vshard/storage/init.lua

@@ -2823,6 +2823,7 @@ end
 --
 local function rebalancer_service_f(service)
     local module_version = M.module_version
+    local some_buckets_are_not_active = false
     while module_version == M.module_version do
         service:next_iter()
         while not M.is_rebalancer_active do
@@ -2844,7 +2845,13 @@ local function rebalancer_service_f(service)
                     'Error during downloading rebalancer states: %s',
                     replicasets))
             end
-            log.info('Some buckets are not active, retry rebalancing later')
+            if not some_buckets_are_not_active then
+                log.info('Some buckets are not active, replicaset ' ..
+                         string.format('%s will retry', M.this_replicaset.id) ..
+                         string.format(' rebalancing every %s s.',
+                                       consts.REBALANCER_WORK_INTERVAL))
+                some_buckets_are_not_active = true
+            end
             service:set_activity('idling')
             lfiber.testcancel()
             lfiber.sleep(consts.REBALANCER_WORK_INTERVAL)
@@ -2874,6 +2881,7 @@ local function rebalancer_service_f(service)
             service:set_activity('idling')
             lfiber.testcancel()
             lfiber.sleep(consts.REBALANCER_IDLE_INTERVAL)
+            some_buckets_are_not_active = false
             goto continue
         end
         local routes = rebalancer_build_routes(replicasets)
@@ -2901,6 +2909,7 @@ local function rebalancer_service_f(service)
                 goto continue
             end
         end
+        some_buckets_are_not_active = false
         log.info('Rebalance routes are sent. Schedule next wakeup after '..
                  '%f seconds', consts.REBALANCER_WORK_INTERVAL)
         service:set_activity('idling')