This is an automated email from the ASF dual-hosted git repository.
yiguolei pushed a commit to branch branch-4.1
in repository https://gitbox.apache.org/repos/asf/doris.git
The following commit(s) were added to refs/heads/branch-4.1 by this push:
new fc13fb216cc branch-4.1: [enhancement](filecache) add more debug info
via VLOG_DEBUG (#65273)
fc13fb216cc is described below
commit fc13fb216cc2473c437683c014984154df522898
Author: zhengyu <[email protected]>
AuthorDate: Mon Jul 13 19:10:32 2026 +0800
branch-4.1: [enhancement](filecache) add more debug info via VLOG_DEBUG
(#65273)
### What problem does this PR solve?
Issue Number: close #xxx
Related PR: #58043
Problem Summary: Backport PR #58043 to branch-4.1. The original change
adds VLOG_DEBUG diagnostics to file cache warm-up, cache
eviction/removal paths, and S3 reads so debugging can include tablet
ids, stack traces, cache keys, offsets, and removal reasons. While
resolving conflicts, branch-4.1 existing warm-up and cache code paths
were preserved and only the missing debug information was applied.
### Release note
None
### Check List (For Author)
- Test:
- Manual test:
`PATH=/data/data4/zhangzhengyu/build-dep/ldb_toolchain.back/bin:$PATH
build-support/clang-format.sh`
- Manual test:
`PATH=/data/data4/zhangzhengyu/build-dep/ldb_toolchain.back/bin:$PATH
build-support/check-format.sh`
- Manual test: `JAVA_HOME=/mnt/disk1/zhangzhengyu/build-dep/jdk-17.0.2/
DORIS_TOOLCHAIN=clang DISABLE_BE_JAVA_EXTENSIONS=ON
ENABLE_INJECTION_POINT=ON ENABLE_CACHE_LOCK_DEBUG=0 ENABLE_PCH=0
./build.sh --be`
- Behavior changed: No
- Does this need documentation: No
Signed-off-by: zhengyu <[email protected]>
---
be/src/cloud/cloud_backend_service.cpp | 6 +++++-
be/src/cloud/cloud_tablet_mgr.cpp | 2 ++
be/src/cloud/cloud_warm_up_manager.cpp | 1 +
be/src/io/cache/block_file_cache.cpp | 36 +++++++++++++++++++++++++++-------
be/src/io/cache/block_file_cache.h | 3 ++-
be/src/io/fs/s3_file_reader.cpp | 3 +++
6 files changed, 42 insertions(+), 9 deletions(-)
diff --git a/be/src/cloud/cloud_backend_service.cpp
b/be/src/cloud/cloud_backend_service.cpp
index 73e0292c643..7b6a88fc7ea 100644
--- a/be/src/cloud/cloud_backend_service.cpp
+++ b/be/src/cloud/cloud_backend_service.cpp
@@ -32,6 +32,7 @@
#include "load/stream_load/stream_load_context.h"
#include "load/stream_load/stream_load_recorder.h"
#include "util/brpc_client_cache.h" // BrpcClientCache
+#include "util/stack_util.h"
#include "util/thrift_server.h"
namespace doris {
@@ -233,10 +234,13 @@ void
CloudBackendService::_warm_up_cache(TWarmUpCacheAsyncResponse& response,
return;
}
PGetFileCacheMetaRequest brpc_request;
- PGetFileCacheMetaResponse brpc_response;
+ std::stringstream ss;
for (int64_t tablet_id : request.tablet_ids) {
brpc_request.add_tablet_ids(tablet_id);
+ ss << tablet_id << ",";
}
+ VLOG_DEBUG << "tablets set: " << ss.str() << " stack: " <<
get_stack_trace();
+ PGetFileCacheMetaResponse brpc_response;
Status rpc_status = run_rpc_get_file_cache_meta(brpc_stub, brpc_addr,
std::move(brpc_request),
brpc_response);
diff --git a/be/src/cloud/cloud_tablet_mgr.cpp
b/be/src/cloud/cloud_tablet_mgr.cpp
index 324425666ac..7b0d0c5bb9a 100644
--- a/be/src/cloud/cloud_tablet_mgr.cpp
+++ b/be/src/cloud/cloud_tablet_mgr.cpp
@@ -180,6 +180,8 @@ Result<std::shared_ptr<CloudTablet>>
CloudTabletMgr::get_tablet(int64_t tablet_i
TabletMap& tablet_map;
};
+ VLOG_DEBUG << "get_tablet tablet_id=" << tablet_id << " stack: " <<
get_stack_trace();
+
auto tablet_id_str = std::to_string(tablet_id);
CacheKey key(tablet_id_str);
auto* handle = _cache->lookup(key);
diff --git a/be/src/cloud/cloud_warm_up_manager.cpp
b/be/src/cloud/cloud_warm_up_manager.cpp
index 82946e97d6a..f3aebad00e8 100644
--- a/be/src/cloud/cloud_warm_up_manager.cpp
+++ b/be/src/cloud/cloud_warm_up_manager.cpp
@@ -240,6 +240,7 @@ void CloudWarmUpManager::handle_jobs() {
std::make_shared<bthread::CountdownEvent>(0);
for (int64_t tablet_id : cur_job->tablet_ids) {
+ VLOG_DEBUG << "Warm up tablet " << tablet_id << " stack: " <<
get_stack_trace();
if (_cur_job_id == 0) { // The job is canceled
break;
}
diff --git a/be/src/io/cache/block_file_cache.cpp
b/be/src/io/cache/block_file_cache.cpp
index 7ba2444ae43..19a4264a851 100644
--- a/be/src/io/cache/block_file_cache.cpp
+++ b/be/src/io/cache/block_file_cache.cpp
@@ -1037,6 +1037,9 @@ size_t BlockFileCache::try_release() {
std::lock_guard lc(cell->file_block->_mutex);
remove_size += file_block->range().size();
remove(file_block, cache_lock, lc);
+ VLOG_DEBUG << "try_release " << _cache_base_path
+ << " hash=" << file_block->get_hash_value().to_string()
+ << " offset=" << file_block->offset();
}
*_evict_by_try_release << remove_size;
LOG(INFO) << "Released " << trash.size() << " blocks in file cache " <<
_cache_base_path;
@@ -1076,12 +1079,16 @@ const LRUQueue& BlockFileCache::get_queue(FileCacheType
type) const {
}
void BlockFileCache::remove_file_blocks(std::vector<FileBlockCell*>& to_evict,
- std::lock_guard<std::mutex>&
cache_lock, bool sync) {
+ std::lock_guard<std::mutex>&
cache_lock, bool sync,
+ std::string& reason) {
auto remove_file_block_if = [&](FileBlockCell* cell) {
FileBlockSPtr file_block = cell->file_block;
if (file_block) {
std::lock_guard block_lock(file_block->_mutex);
remove(file_block, cache_lock, block_lock, sync);
+ VLOG_DEBUG << "remove_file_blocks"
+ << " hash=" << file_block->get_hash_value().to_string()
+ << " offset=" << file_block->offset() << " reason=" <<
reason;
}
};
std::for_each(to_evict.begin(), to_evict.end(), remove_file_block_if);
@@ -1242,6 +1249,7 @@ void BlockFileCache::try_evict_in_advance(size_t size,
std::lock_guard<std::mute
// remove specific cache synchronously, for critical operations
// if in use, cache meta will be deleted after use and the block file is then
deleted asynchronously
void BlockFileCache::remove_if_cached(const UInt128Wrapper& file_key) {
+ std::string reason = "remove_if_cached";
SCOPED_CACHE_LOCK(_mutex, this);
auto iter = _files.find(file_key);
std::vector<FileBlockCell*> to_remove;
@@ -1253,14 +1261,15 @@ void BlockFileCache::remove_if_cached(const
UInt128Wrapper& file_key) {
cell.file_block->set_deleting();
}
}
+ remove_file_blocks(to_remove, cache_lock, true, reason);
}
- remove_file_blocks(to_remove, cache_lock, true);
}
// the async version of remove_if_cached, for background operations
// cache meta is deleted synchronously if not in use, and the block file is
deleted asynchronously
// if in use, cache meta will be deleted after use and the block file is then
deleted asynchronously
void BlockFileCache::remove_if_cached_async(const UInt128Wrapper& file_key) {
+ std::string reason = "remove_if_cached_async";
SCOPED_CACHE_LOCK(_mutex, this);
auto iter = _files.find(file_key);
@@ -1275,8 +1284,8 @@ void BlockFileCache::remove_if_cached_async(const
UInt128Wrapper& file_key) {
cell.file_block->set_deleting();
}
}
+ remove_file_blocks(to_remove, cache_lock, false, reason);
}
- remove_file_blocks(to_remove, cache_lock, false);
}
std::vector<FileCacheType> BlockFileCache::get_other_cache_type_without_ttl(
@@ -1378,7 +1387,9 @@ bool
BlockFileCache::try_reserve_from_other_queue_by_time_interval(
*(_evict_by_time_metrics_matrix[cache_type][cur_type]) <<
remove_size_per_type;
}
bool is_sync_removal = !evict_in_advance;
- remove_file_blocks(to_evict, cache_lock, is_sync_removal);
+ std::string reason = std::string("try_reserve_by_time ") +
+ " evict_in_advance=" + (evict_in_advance ? "true" :
"false");
+ remove_file_blocks(to_evict, cache_lock, is_sync_removal, reason);
return !is_overflow(removed_size, size, cur_cache_size, evict_in_advance);
}
@@ -1421,7 +1432,9 @@ bool BlockFileCache::try_reserve_from_other_queue_by_size(
*(_evict_by_size_metrics_matrix[cache_type][cur_type]) <<
cur_removed_size;
}
bool is_sync_removal = !evict_in_advance;
- remove_file_blocks(to_evict, cache_lock, is_sync_removal);
+ std::string reason = std::string("try_reserve_by_size") +
+ " evict_in_advance=" + (evict_in_advance ? "true" :
"false");
+ remove_file_blocks(to_evict, cache_lock, is_sync_removal, reason);
return !is_overflow(removed_size, size, cur_cache_size, evict_in_advance);
}
@@ -1468,7 +1481,10 @@ bool BlockFileCache::try_reserve_for_lru(const
UInt128Wrapper& hash,
find_evict_candidates(queue, size, cur_cache_size, removed_size,
to_evict, cache_lock,
cur_removed_size, evict_in_advance);
bool is_sync_removal = !evict_in_advance;
- remove_file_blocks(to_evict, cache_lock, is_sync_removal);
+ std::string reason = std::string("try_reserve for cache type ") +
+ cache_type_to_string(context.cache_type) +
+ " evict_in_advance=" + (evict_in_advance ? "true"
: "false");
+ remove_file_blocks(to_evict, cache_lock, is_sync_removal, reason);
*(_evict_by_self_lru_metrics_matrix[context.cache_type]) <<
cur_removed_size;
if (is_overflow(removed_size, size, cur_cache_size, evict_in_advance))
{
@@ -1534,6 +1550,11 @@ void BlockFileCache::remove(FileBlockSPtr file_block, T&
cache_lock, U& block_lo
*_queue_evict_size_metrics[file_cache_type_index(file_block->cache_type())]
<< file_block->range().size();
*_total_evict_size_metrics << file_block->range().size();
+
+ VLOG_DEBUG << "Removing file block from cache. hash: " << hash.to_string()
+ << ", offset: " << offset << ", size: " <<
file_block->range().size()
+ << ", type: " << cache_type_to_string(type);
+
if (file_block->state_unlock(block_lock) == FileBlock::State::DOWNLOADED) {
FileCacheKey key;
key.hash = hash;
@@ -2246,7 +2267,8 @@ bool BlockFileCache::try_reserve_during_async_load(size_t
size,
if (index_queue_size != 0) {
collect_eliminate_fragments(get_queue(FileCacheType::INDEX));
}
- remove_file_blocks(to_evict, cache_lock, true);
+ std::string reason = "async load";
+ remove_file_blocks(to_evict, cache_lock, true, reason);
return !_disk_resource_limit_mode || removed_size >= size;
}
diff --git a/be/src/io/cache/block_file_cache.h
b/be/src/io/cache/block_file_cache.h
index 5ca68fe7f7c..849ea72f16f 100644
--- a/be/src/io/cache/block_file_cache.h
+++ b/be/src/io/cache/block_file_cache.h
@@ -488,7 +488,8 @@ private:
bool is_overflow(size_t removed_size, size_t need_size, size_t
cur_cache_size,
bool evict_in_advance) const;
- void remove_file_blocks(std::vector<FileBlockCell*>&,
std::lock_guard<std::mutex>&, bool sync);
+ void remove_file_blocks(std::vector<FileBlockCell*>&,
std::lock_guard<std::mutex>&, bool sync,
+ std::string& reason);
void find_evict_candidates(LRUQueue& queue, size_t size, size_t
cur_cache_size,
size_t& removed_size,
std::vector<FileBlockCell*>& to_evict,
diff --git a/be/src/io/fs/s3_file_reader.cpp b/be/src/io/fs/s3_file_reader.cpp
index 70e34ced6d2..4eaa10f3311 100644
--- a/be/src/io/fs/s3_file_reader.cpp
+++ b/be/src/io/fs/s3_file_reader.cpp
@@ -117,6 +117,9 @@ Status S3FileReader::read_at_impl(size_t offset, Slice
result, size_t* bytes_rea
size_t bytes_req = result.size;
char* to = result.data;
bytes_req = std::min(bytes_req, _file_size - offset);
+ VLOG_DEBUG << fmt::format("S3FileReader::read_at_impl offset={} size={}
path={} hash={}",
+ offset, result.size, _path.native(),
+
io::BlockFileCache::hash(_path.native()).to_string());
VLOG_DEBUG << "enter s3 read_at_impl, off=" << offset << " n=" << bytes_req
<< " req=" << result.size << " file size=" << _file_size;
if (UNLIKELY(bytes_req == 0)) {
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
