Skip to content

Improve logging of rebalancer and recovery #586

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
mrForza wants to merge 5 commits into
base: master
Choose a base branch
from
Open

Improve logging of rebalancer and recovery #586

Show file tree
Hide file tree
Changes from 1 commit
Commits
Show all changes
5 commits
Select commit Hold shift + click to select a range
b57d254
recovery: reduce spam of "Finish bucket recovery step" logs
mrForza Sep 17, 2025
eefe222
recovery: add logging of recovered buckets
mrForza Sep 17, 2025
c05dff5
rebalancer: add logging of routes
mrForza Sep 9, 2025
9d69cc6
rebalancer: refactoring of rebalancer_request_state
mrForza Nov 7, 2025
62c138e
rebalancer: add replicaset.id into rebalancer_request_state errors
mrForza Nov 7, 2025
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
4 changes: 2 additions & 2 deletions test/rebalancer/rebalancer.result
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -149,7 +149,7 @@ test_run:switch('box_1_a')
vshard.storage.rebalancer_enable()
---
...
wait_rebalancer_state("Rebalance routes are sent", test_run)
wait_rebalancer_state("The following rebalancer routes were sent", test_run)
---
...
wait_rebalancer_state('The cluster is balanced ok', test_run)
Expand Down Expand Up @@ -239,7 +239,7 @@ cfg.rebalancer_disbalance_threshold = 0.01
vshard.storage.cfg(cfg, util.name_to_uuid.box_1_a)
---
...
wait_rebalancer_state('Rebalance routes are sent', test_run)
wait_rebalancer_state('The following rebalancer routes were sent', test_run)
---
...
wait_rebalancer_state('The cluster is balanced ok', test_run)
Expand Down
4 changes: 2 additions & 2 deletions test/rebalancer/rebalancer.test.lua
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -78,7 +78,7 @@ util.map_bucket_protection(test_run, {REPLICASET_1}, true)

test_run:switch('box_1_a')
vshard.storage.rebalancer_enable()
wait_rebalancer_state("Rebalance routes are sent", test_run)
wait_rebalancer_state("The following rebalancer routes were sent", test_run)

wait_rebalancer_state('The cluster is balanced ok', test_run)
_bucket.index.status:count({vshard.consts.BUCKET.ACTIVE})
Expand Down Expand Up @@ -118,7 +118,7 @@ _bucket.index.status:count({vshard.consts.BUCKET.ACTIVE})
-- Return 1%.
cfg.rebalancer_disbalance_threshold = 0.01
vshard.storage.cfg(cfg, util.name_to_uuid.box_1_a)
wait_rebalancer_state('Rebalance routes are sent', test_run)
wait_rebalancer_state('The following rebalancer routes were sent', test_run)
wait_rebalancer_state('The cluster is balanced ok', test_run)
_bucket.index.status:count({vshard.consts.BUCKET.ACTIVE})
_bucket.index.status:min({vshard.consts.BUCKET.ACTIVE})
Expand Down
4 changes: 2 additions & 2 deletions test/rebalancer/stress_add_remove_several_rs.result
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -175,7 +175,7 @@ add_replicaset()
vshard.storage.cfg(cfg, util.name_to_uuid.box_1_a)
---
...
wait_rebalancer_state('Rebalance routes are sent', test_run)
wait_rebalancer_state('The following rebalancer routes were sent', test_run)
---
...
-- Now, add a second replicaset.
Expand Down Expand Up @@ -422,7 +422,7 @@ remove_second_replicaset_first_stage()
vshard.storage.cfg(cfg, util.name_to_uuid.box_1_a)
---
...
wait_rebalancer_state('Rebalance routes are sent', test_run)
wait_rebalancer_state('The following rebalancer routes were sent', test_run)
---
...
-- Rebalancing has been started - now remove second replicaset.
Expand Down
4 changes: 2 additions & 2 deletions test/rebalancer/stress_add_remove_several_rs.test.lua
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -71,7 +71,7 @@ fiber.sleep(0.5)
test_run:switch('box_1_a')
add_replicaset()
vshard.storage.cfg(cfg, util.name_to_uuid.box_1_a)
wait_rebalancer_state('Rebalance routes are sent', test_run)
wait_rebalancer_state('The following rebalancer routes were sent', test_run)

-- Now, add a second replicaset.

Expand Down Expand Up @@ -153,7 +153,7 @@ fiber.sleep(0.5)
test_run:switch('box_1_a')
remove_second_replicaset_first_stage()
vshard.storage.cfg(cfg, util.name_to_uuid.box_1_a)
wait_rebalancer_state('Rebalance routes are sent', test_run)
wait_rebalancer_state('The following rebalancer routes were sent', test_run)
-- Rebalancing has been started - now remove second replicaset.
remove_replicaset_first_stage()
vshard.storage.cfg(cfg, util.name_to_uuid.box_1_a)
Expand Down
31 changes: 31 additions & 0 deletions test/storage-luatest/storage_1_1_1_test.lua
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -149,6 +149,14 @@ local function wait_for_bucket_is_transferred(src_storage, dest_storage,
end, {bucket_id})
end

local function move_bucket(src_storage, dest_storage, bucket_id)
src_storage:exec(function(bucket_id, replicaset_id)
local res, err = ivshard.storage.bucket_send(bucket_id, replicaset_id)
Copy link
Collaborator

@Gerold103 Gerold103 Dec 1, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please, give it a long timeout. Otherwise this test will be flaky.

t.assert(res and not err, 'Error during transferring bucket')
end, {bucket_id, dest_storage:replicaset_uuid()})
wait_for_bucket_is_transferred(src_storage, dest_storage, bucket_id)
end

--
-- Reduce spam of "Finish bucket recovery step" logs and add logging of
-- recovered buckets in recovery service (gh-212).
Expand Down Expand Up @@ -196,3 +204,26 @@ test_group.test_no_logs_while_unsuccess_recovery = function(g)
wait_for_bucket_is_transferred(g.replica_2_a, g.replica_1_a,
hanged_bucket_id_2)
end

--
-- Add logging of routes in rebalancer service (gh-212).
--
test_group.test_rebalancer_routes_logging = function(g)
local moved_bucket_from_2 = vtest.storage_first_bucket(g.replica_2_a)
move_bucket(g.replica_2_a, g.replica_1_a, moved_bucket_from_2)
local moved_bucket_from_3 = vtest.storage_first_bucket(g.replica_3_a)
move_bucket(g.replica_3_a, g.replica_1_a, moved_bucket_from_3)
t.helpers.retrying({timeout = 60}, function()
g.replica_1_a:exec(function() ivshard.storage.rebalancer_wakeup() end)
Copy link
Collaborator

@Gerold103 Gerold103 Dec 1, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If this is the test case for which you have enabled the rebalancer in the first commit, then please, 1) enable the rebalancer here, 2) disable it in the end of the test case.

t.assert(g.replica_1_a:grep_log('Apply rebalancer routes with 1 ' ..
'workers'))
end)
local rebalancer_routes_msg = string.format(
"{\"%s\":{\"%s\":1}}", g.replica_1_a:replicaset_uuid(),
g.replica_2_a:replicaset_uuid())
t.helpers.retrying({}, function()
t.assert(g.replica_1_a:grep_log(rebalancer_routes_msg))
g.replica_1_a:exec(function() ivshard.storage.rebalancer_wakeup() end)
g.replica_1_a:grep_log('The cluster is balanced ok.')
end)
end
5 changes: 3 additions & 2 deletions vshard/storage/init.lua
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -2915,8 +2915,9 @@ local function rebalancer_service_f(service, limiter)
goto continue
end
end
log.info('Rebalance routes are sent. Schedule next wakeup after '..
'%f seconds', consts.REBALANCER_WORK_INTERVAL)
log.info('The following rebalancer routes were sent: %s. ' ..
'Schedule next wakeup after %f seconds', json_encode(routes),
consts.REBALANCER_WORK_INTERVAL)
service:set_activity('idling')
lfiber.testcancel()
lfiber.sleep(consts.REBALANCER_WORK_INTERVAL)
Expand Down