Skip to content

branch-4.1: [feat](cloud) Add lock wait and bthread schedule delay metrics to SyncRowset profile #61036 #61450

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

Merged
yiguolei merged 1 commit into from
Mar 18, 2026
+79 −1
Merged

branch-4.1: [feat](cloud) Add lock wait and bthread schedule delay metrics to SyncRowset profile #61036 #61450

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
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
14 changes: 14 additions & 0 deletions be/src/cloud/cloud_meta_mgr.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -590,7 +590,14 @@ Status CloudMetaMgr::sync_tablet_rowsets_unlocked(CloudTablet* tablet,
idx->set_index_id(index_id);
idx->set_partition_id(tablet->partition_id());
{
auto lock_start = std::chrono::steady_clock::now();
std::shared_lock rlock(tablet->get_header_lock());
if (sync_stats) {
sync_stats->meta_lock_wait_ns +=
std::chrono::duration_cast<std::chrono::nanoseconds>(
std::chrono::steady_clock::now() - lock_start)
.count();
}
if (options.full_sync) {
req.set_start_version(0);
} else {
Expand Down Expand Up @@ -693,7 +700,14 @@ Status CloudMetaMgr::sync_tablet_rowsets_unlocked(CloudTablet* tablet,
});
{
const auto& stats = resp.stats();
auto lock_start = std::chrono::steady_clock::now();
std::unique_lock wlock(tablet->get_header_lock());
if (sync_stats) {
sync_stats->meta_lock_wait_ns +=
std::chrono::duration_cast<std::chrono::nanoseconds>(
std::chrono::steady_clock::now() - lock_start)
.count();
}

// ATTN: we are facing following data race
//
Expand Down
36 changes: 36 additions & 0 deletions be/src/cloud/cloud_tablet.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -301,16 +301,34 @@ Status CloudTablet::sync_rowsets(const SyncOptions& options, SyncRowsetStats* st
RETURN_IF_ERROR(sync_if_not_running(stats));

if (options.query_version > 0) {
auto lock_start = std::chrono::steady_clock::now();
std::shared_lock rlock(_meta_lock);
if (stats) {
stats->meta_lock_wait_ns += std::chrono::duration_cast<std::chrono::nanoseconds>(
std::chrono::steady_clock::now() - lock_start)
.count();
}
if (_max_version >= options.query_version) {
return Status::OK();
}
}

// serially execute sync to reduce unnecessary network overhead
auto sync_lock_start = std::chrono::steady_clock::now();
std::unique_lock lock(_sync_meta_lock);
if (stats) {
stats->sync_meta_lock_wait_ns += std::chrono::duration_cast<std::chrono::nanoseconds>(
std::chrono::steady_clock::now() - sync_lock_start)
.count();
}
if (options.query_version > 0) {
auto lock_start = std::chrono::steady_clock::now();
std::shared_lock rlock(_meta_lock);
if (stats) {
stats->meta_lock_wait_ns += std::chrono::duration_cast<std::chrono::nanoseconds>(
std::chrono::steady_clock::now() - lock_start)
.count();
}
if (_max_version >= options.query_version) {
return Status::OK();
}
Expand All @@ -333,10 +351,22 @@ Status CloudTablet::sync_if_not_running(SyncRowsetStats* stats) {
}

// Serially execute sync to reduce unnecessary network overhead
auto sync_lock_start = std::chrono::steady_clock::now();
std::unique_lock lock(_sync_meta_lock);
if (stats) {
stats->sync_meta_lock_wait_ns += std::chrono::duration_cast<std::chrono::nanoseconds>(
std::chrono::steady_clock::now() - sync_lock_start)
.count();
}

{
auto lock_start = std::chrono::steady_clock::now();
std::shared_lock rlock(_meta_lock);
if (stats) {
stats->meta_lock_wait_ns += std::chrono::duration_cast<std::chrono::nanoseconds>(
std::chrono::steady_clock::now() - lock_start)
.count();
}
if (tablet_state() == TABLET_RUNNING) {
return Status::OK();
}
Expand All @@ -358,7 +388,13 @@ Status CloudTablet::sync_if_not_running(SyncRowsetStats* stats) {

TimestampedVersionTracker empty_tracker;
{
auto lock_start = std::chrono::steady_clock::now();
std::lock_guard wlock(_meta_lock);
if (stats) {
stats->meta_lock_wait_ns += std::chrono::duration_cast<std::chrono::nanoseconds>(
std::chrono::steady_clock::now() - lock_start)
.count();
}
RETURN_IF_ERROR(set_tablet_state(TABLET_RUNNING));
_rs_version_map.clear();
_stale_rs_version_map.clear();
Expand Down
5 changes: 5 additions & 0 deletions be/src/cloud/cloud_tablet.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -53,6 +53,11 @@ struct SyncRowsetStats {
int64_t get_remote_tablet_meta_rpc_ns {0};
int64_t tablet_meta_cache_hit {0};
int64_t tablet_meta_cache_miss {0};

int64_t bthread_schedule_delay_ns {0};
int64_t meta_lock_wait_ns {0}; // _meta_lock (std::shared_mutex) wait across all acquisitions
int64_t sync_meta_lock_wait_ns {
0}; // _sync_meta_lock (bthread::Mutex) wait across all acquisitions
};

struct SyncOptions {
Expand Down
22 changes: 21 additions & 1 deletion be/src/pipeline/exec/olap_scan_operator.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -172,6 +172,12 @@ Status OlapScanLocalState::_init_profile() {
TUnit::BYTES, sync_rowset_timer_name);
_sync_rowset_get_remote_delete_bitmap_rpc_timer = ADD_CHILD_TIMER(
_scanner_profile, "SyncRowsetGetRemoteDeleteBitmapRpcTime", sync_rowset_timer_name);
_sync_rowset_bthread_schedule_wait_timer = ADD_CHILD_TIMER(
_scanner_profile, "SyncRowsetBthreadScheduleWaitTime", sync_rowset_timer_name);
_sync_rowset_meta_lock_wait_timer = ADD_CHILD_TIMER(
_scanner_profile, "SyncRowsetMetaLockWaitTime", sync_rowset_timer_name);
_sync_rowset_sync_meta_lock_wait_timer = ADD_CHILD_TIMER(
_scanner_profile, "SyncRowsetSyncMetaLockWaitTime", sync_rowset_timer_name);
}
_block_init_timer = ADD_TIMER(_segment_profile, "BlockInitTime");
_block_init_seek_timer = ADD_TIMER(_segment_profile, "BlockInitSeekTime");
Expand Down Expand Up @@ -610,7 +616,16 @@ Status OlapScanLocalState::_sync_cloud_tablets(RuntimeState* state) {
_scan_ranges[i]->version.data() + _scan_ranges[i]->version.size(),
version);
auto task_ctx = state->get_task_execution_context();
tasks.emplace_back([this, sync_stats, version, i, task_ctx]() {
auto task_create_time = std::chrono::steady_clock::now();
tasks.emplace_back([this, sync_stats, version, i, task_ctx, task_create_time]() {
// Record bthread scheduling delay
auto task_start_time = std::chrono::steady_clock::now();
if (sync_stats) {
sync_stats->bthread_schedule_delay_ns +=
std::chrono::duration_cast<std::chrono::nanoseconds>(
task_start_time - task_create_time)
.count();
}
auto task_lock = task_ctx.lock();
if (task_lock == nullptr) {
return Status::OK();
Expand Down Expand Up @@ -684,6 +699,11 @@ Status OlapScanLocalState::prepare(RuntimeState* state) {
sync_stats.get_remote_delete_bitmap_bytes);
COUNTER_UPDATE(_sync_rowset_get_remote_delete_bitmap_rpc_timer,
sync_stats.get_remote_delete_bitmap_rpc_ns);
COUNTER_UPDATE(_sync_rowset_bthread_schedule_wait_timer,
sync_stats.bthread_schedule_delay_ns);
COUNTER_UPDATE(_sync_rowset_meta_lock_wait_timer, sync_stats.meta_lock_wait_ns);
COUNTER_UPDATE(_sync_rowset_sync_meta_lock_wait_timer,
sync_stats.sync_meta_lock_wait_ns);
}
auto time_ms = _sync_cloud_tablets_watcher.elapsed_time_microseconds();
if (time_ms >= config::sync_rowsets_slow_threshold_ms) {
Expand Down
3 changes: 3 additions & 0 deletions be/src/pipeline/exec/olap_scan_operator.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -181,6 +181,9 @@ class OlapScanLocalState final : public ScanLocalState<OlapScanLocalState> {
RuntimeProfile::Counter* _sync_rowset_get_remote_delete_bitmap_key_count = nullptr;
RuntimeProfile::Counter* _sync_rowset_get_remote_delete_bitmap_bytes = nullptr;
RuntimeProfile::Counter* _sync_rowset_get_remote_delete_bitmap_rpc_timer = nullptr;
RuntimeProfile::Counter* _sync_rowset_bthread_schedule_wait_timer = nullptr;
RuntimeProfile::Counter* _sync_rowset_meta_lock_wait_timer = nullptr;
RuntimeProfile::Counter* _sync_rowset_sync_meta_lock_wait_timer = nullptr;
RuntimeProfile::Counter* _block_load_timer = nullptr;
RuntimeProfile::Counter* _block_load_counter = nullptr;
// Add more detail seek timer and counter profile
Expand Down
Loading