Skip to content

Commit 733ee93

Browse files
committed
[test](be) Repeat and document async cache write benchmark
### What problem does this PR solve? Issue Number: None Related PR: #65658 Problem Summary: The asynchronous file-cache write microbenchmark previously emitted only one sample per case and did not establish the storage baseline of the cache filesystem. These short concurrent cases are sensitive to scheduler activity, page-cache state, filesystem metadata, and background writeback, so a single number can hide material variance and make worker-scaling conclusions unreliable. Run every selected reader, service, and inflight-index case five times by default and add the one-based repetition to each machine-readable RESULT line. Add an installed runner that can measure direct 1 MiB sequential QD1 and random QD16 writes on the same filesystem before starting the benchmark. The fio behavior is explicit and does not make fio a mandatory dependency: | RUN_FIO | fio available | Behavior | | --- | --- | --- | | auto (default) | Yes | Run both disk baselines, then run the cache benchmark | | auto (default) | No | Print DISK_BASELINE skipped and continue directly with the cache benchmark | | 1 | No | Fail because the caller explicitly required fio | | 0 | Any | Skip fio and run the cache benchmark | The runner uses a unique sibling directory under the selected cache path, unlinks fio data, and keeps direct I/O out of the page cache. The benchmark rejects non-empty cache paths instead of recursively clearing them, and suppresses INFO logging so merged stdout and stderr cannot corrupt RESULT records. Expand the tool README with the component flow, coverage and non-goals of each group, default workload, field semantics, fio controls, cache-path ownership, repetition methodology, and interpretation guidance. Median is the primary value and the observed minimum and maximum are retained. Release experiment configuration: /dev/nvme11n1 ext4, 1 MiB blocks, 64 KiB caller reads, 16 producers, 128 reader operations, 256 service attempts, and five repetitions. fio direct-I/O baseline: | Workload | Bandwidth | p95 completion latency | | --- | ---: | ---: | | 1 MiB sequential write, QD1 | 2513 MiB/s | 161 us | | 1 MiB random write, QD16 | 3106 MiB/s | 10.552 ms | CachedRemoteFileReader foreground results: | Write mode | Median ops/s | Minimum ops/s | Maximum ops/s | Median average latency | | --- | ---: | ---: | ---: | ---: | | Synchronous | 5645 | 5124 | 7649 | 1459 us | | Asynchronous | 6739 | 4739 | 8298 | 912 us | The asynchronous median was 19.4% higher in throughput and 37.5% lower in average latency. The overlapping ranges are retained because they show why a single run is insufficient. AsyncCacheWriteService verified completion results: | Workers | Median MiB/s | Minimum MiB/s | Maximum MiB/s | Median drain time | | ---: | ---: | ---: | ---: | ---: | | 1 | 798 | 730 | 968 | 0.300 s | | 4 | 1562 | 1260 | 1751 | 0.153 s | | 16 | 7825 | 5255 | 13203 | 0.014 s | These values measure buffered append and finalize completion without fsync. They are not durable-media throughput and are not directly comparable with the direct-I/O fio baseline. Bounded backpressure results: | Metric | Median | Minimum | Maximum | | --- | ---: | ---: | ---: | | Accepted tasks | 76 | 64 | 101 | | Rejected tasks | 180 | 155 | 192 | | Peak pending | 64 | 64 | 64 | | Peak queued | 48 | 48 | 48 | | Peak inflight | 65 | 65 | 67 | Every accepted task was verified as persisted, and peak pending stayed at the configured limit. InflightWriteBufferIndex lookup results: | Workload | Median ops/s | Minimum ops/s | Maximum ops/s | Median average latency | | --- | ---: | ---: | ---: | ---: | | Sharded miss | 5.531M | 4.028M | 6.621M | 2.688 us | | Sharded hit | 4.198M | 3.270M | 6.036M | 3.171 us | | Hot-key hit | 1.104M | 1.090M | 1.268M | 13.701 us | All 45 RESULT records were complete and parseable. All reader ranges and all accepted service tasks passed final BlockFileCache coverage verification. ### Release note None ### Check List (For Author) - Test: Manual test - ./build.sh --be --file-cache-microbench -j100 (Release) - ./output/be/bin/run-async-file-cache-write-microbench.sh --benchmark_mode=all --cache_path=./output/async_file_cache_write_microbench_repeat_5_clean --producer_threads=16 --reader_workers=16 --worker_counts=1,4,16 --repetitions=5 - Non-empty cache-path rejection with sentinel preservation - build-support/clang-format.sh - build-support/check-format.sh - bash -n and shellcheck for the runner - git diff --check - Behavior changed: No (benchmark tooling only) - Does this need documentation: No (tool README updated)
1 parent fbc5bcc commit 733ee93

4 files changed

Lines changed: 414 additions & 63 deletions

File tree

be/src/io/tools/async_file_cache_write_microbench.cpp

Lines changed: 105 additions & 44 deletions
Original file line numberDiff line numberDiff line change
@@ -81,6 +81,7 @@ DEFINE_int32(producer_threads, 16, "Concurrent foreground readers or task produc
8181
DEFINE_int32(reader_workers, 16, "Async write workers used by the reader comparison");
8282
DEFINE_string(worker_counts, "1,4,16",
8383
"Comma-separated async write worker counts used by service scaling cases");
84+
DEFINE_uint64(repetitions, 5, "Measured repetitions of every selected benchmark case");
8485
DEFINE_uint64(backpressure_pending_tasks, 64,
8586
"Pending-task limit used by the saturated service case");
8687
DEFINE_uint64(queue_sample_interval_us, 50,
@@ -215,7 +216,8 @@ Status validate_flags(const std::vector<std::string>& modes,
215216
if (FLAGS_service_task_size == 0 || FLAGS_service_task_size > FLAGS_block_size ||
216217
FLAGS_service_key_count == 0 || FLAGS_index_operations_per_thread == 0 ||
217218
FLAGS_index_key_count == 0 || FLAGS_backpressure_pending_tasks == 0 ||
218-
FLAGS_queue_sample_interval_us == 0 || FLAGS_timeout_seconds == 0) {
219+
FLAGS_queue_sample_interval_us == 0 || FLAGS_timeout_seconds == 0 ||
220+
FLAGS_repetitions == 0) {
219221
return Status::InvalidArgument(
220222
"operation counts, timeouts, and 0 < service_task_size <= block_size are required");
221223
}
@@ -390,7 +392,7 @@ class BenchmarkEnvironment {
390392
ExecEnv::GetInstance()->set_file_cache_factory(nullptr);
391393
_factory.reset();
392394
}
393-
if (!FLAGS_keep_cache) {
395+
if (_owns_cache_path && !FLAGS_keep_cache) {
394396
std::error_code error;
395397
std::filesystem::remove_all(FLAGS_cache_path, error);
396398
}
@@ -399,6 +401,55 @@ class BenchmarkEnvironment {
399401
/// Configure globals, create the cache, and wait for its asynchronous metadata open.
400402
/// @param cache_capacity Bytes reserved for the benchmark's normal queue.
401403
Status initialize(size_t cache_capacity) {
404+
std::error_code error;
405+
const auto cache_path =
406+
std::filesystem::absolute(FLAGS_cache_path, error).lexically_normal();
407+
if (error) {
408+
return Status::IOError("failed to resolve cache path {}: {}", FLAGS_cache_path,
409+
error.message());
410+
}
411+
const auto current_path = std::filesystem::current_path(error);
412+
if (error) {
413+
return Status::IOError("failed to resolve current directory: {}", error.message());
414+
}
415+
if (cache_path == cache_path.root_path() || cache_path == current_path) {
416+
return Status::InvalidArgument("cache path must be a dedicated subdirectory: {}",
417+
cache_path.string());
418+
}
419+
const bool cache_path_exists = std::filesystem::exists(cache_path, error);
420+
if (error) {
421+
return Status::IOError("failed to inspect cache path {}: {}", cache_path.string(),
422+
error.message());
423+
}
424+
if (cache_path_exists) {
425+
const bool cache_path_is_directory = std::filesystem::is_directory(cache_path, error);
426+
if (error) {
427+
return Status::IOError("failed to inspect cache path {}: {}", cache_path.string(),
428+
error.message());
429+
}
430+
if (!cache_path_is_directory) {
431+
return Status::InvalidArgument("cache path is not a directory: {}",
432+
cache_path.string());
433+
}
434+
const bool cache_path_is_empty = std::filesystem::is_empty(cache_path, error);
435+
if (error) {
436+
return Status::IOError("failed to inspect cache path {}: {}", cache_path.string(),
437+
error.message());
438+
}
439+
if (!cache_path_is_empty) {
440+
return Status::InvalidArgument(
441+
"cache path must not exist or must be an empty directory: {}",
442+
cache_path.string());
443+
}
444+
} else {
445+
std::filesystem::create_directories(cache_path, error);
446+
if (error) {
447+
return Status::IOError("failed to create cache path {}: {}", cache_path.string(),
448+
error.message());
449+
}
450+
}
451+
_owns_cache_path = true;
452+
402453
config::enable_async_file_cache_write = true;
403454
config::enable_async_file_cache_write_inflight_write_buffer_index = true;
404455
config::enable_read_cache_file_directly = false;
@@ -423,14 +474,6 @@ class BenchmarkEnvironment {
423474
_factory = std::make_unique<FileCacheFactory>();
424475
ExecEnv::GetInstance()->set_file_cache_factory(_factory.get());
425476

426-
std::error_code error;
427-
std::filesystem::remove_all(FLAGS_cache_path, error);
428-
std::filesystem::create_directories(FLAGS_cache_path, error);
429-
if (error) {
430-
return Status::IOError("failed to create cache path {}: {}", FLAGS_cache_path,
431-
error.message());
432-
}
433-
434477
FileCacheSettings settings;
435478
settings.capacity = cache_capacity;
436479
settings.max_file_block_size = FLAGS_block_size;
@@ -492,6 +535,7 @@ class BenchmarkEnvironment {
492535
private:
493536
std::unique_ptr<FileCacheFactory> _factory;
494537
BlockFileCache* _cache {nullptr};
538+
bool _owns_cache_path {false};
495539
};
496540

497541
/// Verify that a complete range can be resolved from the final cache state.
@@ -538,7 +582,8 @@ struct AsyncWriteResult {
538582

539583
/// Print one machine-readable line without hiding the foreground/drain distinction.
540584
/// @param result Completed benchmark result.
541-
void print_async_write_result(const AsyncWriteResult& result) {
585+
/// @param repetition One-based repetition index.
586+
void print_async_write_result(const AsyncWriteResult& result, size_t repetition) {
542587
const double foreground_ops_per_sec =
543588
static_cast<double>(result.operations) / result.foreground_seconds;
544589
const double persisted_mib_per_sec =
@@ -548,9 +593,10 @@ void print_async_write_result(const AsyncWriteResult& result) {
548593
: 0;
549594
std::cout << std::fixed << std::setprecision(3) << "RESULT"
550595
<< " benchmark=" << result.benchmark << " variant=" << result.variant
551-
<< " producers=" << result.producers << " workers=" << result.workers
552-
<< " operations=" << result.operations << " accepted=" << result.accepted
553-
<< " rejected=" << result.rejected << " persisted=" << result.persisted
596+
<< " repetition=" << repetition << " producers=" << result.producers
597+
<< " workers=" << result.workers << " operations=" << result.operations
598+
<< " accepted=" << result.accepted << " rejected=" << result.rejected
599+
<< " persisted=" << result.persisted
554600
<< " bytes_per_operation=" << result.bytes_per_operation
555601
<< " foreground_seconds=" << result.foreground_seconds
556602
<< " drain_seconds=" << result.drain_seconds
@@ -568,8 +614,9 @@ void print_async_write_result(const AsyncWriteResult& result) {
568614
/// @param environment Shared real cache, cleared before the case.
569615
/// @param mode Explicit write policy applied to every CachedRemoteFileReader.
570616
/// @param variant Stable output label.
571-
Status run_reader_case(BenchmarkEnvironment* environment, CacheWriteMode mode,
572-
std::string variant) {
617+
/// @param repetition One-based repetition index included in output.
618+
Status run_reader_case(BenchmarkEnvironment* environment, CacheWriteMode mode, std::string variant,
619+
size_t repetition) {
573620
DORIS_CHECK(environment != nullptr);
574621
RETURN_IF_ERROR(environment->clear_cache());
575622
RETURN_IF_ERROR(environment->configure_service(
@@ -684,7 +731,7 @@ Status run_reader_case(BenchmarkEnvironment* environment, CacheWriteMode mode,
684731
.peak_inflight = sampler.peak_inflight(),
685732
.latency = summarize_latencies(latencies),
686733
};
687-
print_async_write_result(result);
734+
print_async_write_result(result, repetition);
688735
return Status::OK();
689736
}
690737

@@ -700,8 +747,9 @@ struct ServiceTaskRecord {
700747
/// @param variant Stable output label.
701748
/// @param workers Active service consumers.
702749
/// @param max_pending Bounded pending-task limit.
750+
/// @param repetition One-based repetition index included in output.
703751
Status run_service_case(BenchmarkEnvironment* environment, std::string variant, size_t workers,
704-
size_t max_pending) {
752+
size_t max_pending, size_t repetition) {
705753
DORIS_CHECK(environment != nullptr);
706754
RETURN_IF_ERROR(environment->clear_cache());
707755
RETURN_IF_ERROR(environment->configure_service(workers, max_pending));
@@ -847,16 +895,18 @@ Status run_service_case(BenchmarkEnvironment* environment, std::string variant,
847895
.peak_inflight = sampler.peak_inflight(),
848896
.latency = summarize_latencies(latencies),
849897
};
850-
print_async_write_result(result);
898+
print_async_write_result(result, repetition);
851899
return Status::OK();
852900
}
853901

854902
/// Print one inflight-index result using the same latency field names as write cases.
855-
void print_index_result(std::string_view variant, size_t operations, double elapsed_seconds,
856-
const LatencySummary& latency) {
903+
/// @param repetition One-based repetition index.
904+
void print_index_result(std::string_view variant, size_t repetition, size_t operations,
905+
double elapsed_seconds, const LatencySummary& latency) {
857906
std::cout << std::fixed << std::setprecision(3) << "RESULT benchmark=index"
858-
<< " variant=" << variant << " producers=" << FLAGS_producer_threads
859-
<< " operations=" << operations << " elapsed_seconds=" << elapsed_seconds
907+
<< " variant=" << variant << " repetition=" << repetition
908+
<< " producers=" << FLAGS_producer_threads << " operations=" << operations
909+
<< " elapsed_seconds=" << elapsed_seconds
860910
<< " operations_per_sec=" << static_cast<double>(operations) / elapsed_seconds
861911
<< " avg_us=" << latency.average_us << " p50_us=" << latency.p50_us
862912
<< " p95_us=" << latency.p95_us << " p99_us=" << latency.p99_us
@@ -867,10 +917,12 @@ void print_index_result(std::string_view variant, size_t operations, double elap
867917
/// @param variant Stable output label.
868918
/// @param key_count Number of distinct cache hashes used by the workload.
869919
/// @param populate Whether every lookup should hit a pre-populated entry.
870-
Status run_index_case(std::string variant, size_t key_count, bool populate) {
920+
/// @param repetition One-based repetition index included in output.
921+
Status run_index_case(std::string variant, size_t key_count, bool populate, size_t repetition) {
871922
const size_t producer_count = static_cast<size_t>(FLAGS_producer_threads);
872923
const size_t operations_per_thread = static_cast<size_t>(FLAGS_index_operations_per_thread);
873-
InflightWriteBufferIndex index(64, FLAGS_cache_path + "_index_" + variant);
924+
InflightWriteBufferIndex index(
925+
64, FLAGS_cache_path + "_index_" + variant + "_" + std::to_string(repetition));
874926
std::vector<UInt128Wrapper> hashes;
875927
hashes.reserve(key_count);
876928
const uint64_t epoch = 1;
@@ -918,7 +970,7 @@ Status run_index_case(std::string variant, size_t key_count, bool populate) {
918970
}
919971

920972
const size_t total_operations = producer_count * operations_per_thread;
921-
print_index_result(variant, total_operations,
973+
print_index_result(variant, repetition, total_operations,
922974
std::chrono::duration<double>(end - start).count(),
923975
summarize_latencies(latencies));
924976
return Status::OK();
@@ -939,26 +991,33 @@ Status run_benchmarks(const std::vector<std::string>& modes,
939991
RETURN_IF_ERROR(environment.initialize(cache_capacity));
940992
std::cout << "CONFIG cache_path=" << FLAGS_cache_path << " cache_capacity=" << cache_capacity
941993
<< " block_size=" << FLAGS_block_size << " request_size=" << FLAGS_request_size
942-
<< " producer_threads=" << FLAGS_producer_threads << '\n';
943-
944-
if (mode_enabled(modes, "reader")) {
945-
RETURN_IF_ERROR(run_reader_case(&environment, CacheWriteMode::SYNC_WRITE, "sync_write"));
946-
RETURN_IF_ERROR(run_reader_case(&environment, CacheWriteMode::ASYNC_WRITE, "async_write"));
947-
}
948-
if (mode_enabled(modes, "service")) {
949-
for (size_t workers : worker_counts) {
994+
<< " producer_threads=" << FLAGS_producer_threads
995+
<< " repetitions=" << FLAGS_repetitions << '\n';
996+
997+
for (size_t repetition = 1; repetition <= FLAGS_repetitions; ++repetition) {
998+
if (mode_enabled(modes, "reader")) {
999+
RETURN_IF_ERROR(run_reader_case(&environment, CacheWriteMode::SYNC_WRITE, "sync_write",
1000+
repetition));
1001+
RETURN_IF_ERROR(run_reader_case(&environment, CacheWriteMode::ASYNC_WRITE,
1002+
"async_write", repetition));
1003+
}
1004+
if (mode_enabled(modes, "service")) {
1005+
for (size_t workers : worker_counts) {
1006+
RETURN_IF_ERROR(run_service_case(
1007+
&environment, "drain_workers_" + std::to_string(workers), workers,
1008+
static_cast<size_t>(FLAGS_service_operations + workers), repetition));
1009+
}
9501010
RETURN_IF_ERROR(run_service_case(
951-
&environment, "drain_workers_" + std::to_string(workers), workers,
952-
static_cast<size_t>(FLAGS_service_operations + workers)));
1011+
&environment, "backpressure", worker_counts.back(),
1012+
std::min<size_t>(FLAGS_backpressure_pending_tasks, FLAGS_service_operations),
1013+
repetition));
1014+
}
1015+
if (mode_enabled(modes, "index")) {
1016+
RETURN_IF_ERROR(
1017+
run_index_case("sharded_miss", FLAGS_index_key_count, false, repetition));
1018+
RETURN_IF_ERROR(run_index_case("sharded_hit", FLAGS_index_key_count, true, repetition));
1019+
RETURN_IF_ERROR(run_index_case("hot_key_hit", 1, true, repetition));
9531020
}
954-
RETURN_IF_ERROR(run_service_case(
955-
&environment, "backpressure", worker_counts.back(),
956-
std::min<size_t>(FLAGS_backpressure_pending_tasks, FLAGS_service_operations)));
957-
}
958-
if (mode_enabled(modes, "index")) {
959-
RETURN_IF_ERROR(run_index_case("sharded_miss", FLAGS_index_key_count, false));
960-
RETURN_IF_ERROR(run_index_case("sharded_hit", FLAGS_index_key_count, true));
961-
RETURN_IF_ERROR(run_index_case("hot_key_hit", 1, true));
9621021
}
9631022
return Status::OK();
9641023
}
@@ -969,6 +1028,8 @@ Status run_benchmarks(const std::vector<std::string>& modes,
9691028
int main(int argc, char** argv) {
9701029
google::ParseCommandLineFlags(&argc, &argv, true);
9711030
FLAGS_logtostderr = true;
1031+
// Keep RESULT lines parseable when the documented runner merges stdout and stderr.
1032+
FLAGS_minloglevel = google::GLOG_ERROR;
9721033
google::InitGoogleLogging(argv[0]);
9731034

9741035
// Doris configuration defaults contain ${DORIS_HOME}; a standalone benchmark has no launcher

0 commit comments

Comments
 (0)