From 3e9c5a35237d0ae5d1d8b0499b4dd8844e0ec56d Mon Sep 17 00:00:00 2001 From: haoyuhuang Date: Fri, 12 Jul 2019 16:52:15 -0700 Subject: [PATCH] Block cache analyzer: Add more stats (#5516) Summary: This PR provides more command line options for block cache analyzer to better understand block cache access pattern. -analyze_bottom_k_access_count_blocks -analyze_top_k_access_count_blocks -reuse_lifetime_labels -reuse_lifetime_buckets -analyze_callers -access_count_buckets -analyze_blocks_reuse_k_reuse_window Pull Request resolved: https://github.com/facebook/rocksdb/pull/5516 Test Plan: make clean && COMPILE_WITH_ASAN=1 make check -j32 Differential Revision: D16037440 Pulled By: HaoyuHuang fbshipit-source-id: b9a4ac0d4712053fab910732077a4d4b91400bc8 --- tools/block_cache_trace_analyzer.cc | 1255 +++++++++++++++++----- tools/block_cache_trace_analyzer.h | 134 ++- tools/block_cache_trace_analyzer_test.cc | 262 ++++- trace_replay/block_cache_tracer.cc | 2 + trace_replay/block_cache_tracer.h | 3 + 5 files changed, 1320 insertions(+), 336 deletions(-) diff --git a/tools/block_cache_trace_analyzer.cc b/tools/block_cache_trace_analyzer.cc index bd8d8971b..766338462 100644 --- a/tools/block_cache_trace_analyzer.cc +++ b/tools/block_cache_trace_analyzer.cc @@ -44,20 +44,14 @@ DEFINE_bool(print_data_block_access_count_stats, false, DEFINE_int32(cache_sim_warmup_seconds, 0, "The number of seconds to warmup simulated caches. The hit/miss " "counters are reset after the warmup completes."); -DEFINE_string( - block_cache_analysis_result_dir, "", - "The directory that saves block cache analysis results. It contains 1) a " - "mrc file that saves the computed miss ratios for simulated caches. Its " - "format is " - "cache_name,num_shard_bits,capacity,miss_ratio,total_accesses. 2) Several " - "\"label_access_timeline\" files that contain number of accesses per " - "second grouped by the label. File format: " - "time,label_1_access_per_second,label_2_access_per_second,...,label_N_" - "access_per_second where N is the number of unique labels found in the " - "trace. 3) Several \"label_reuse_distance\" and \"label_reuse_interval\" " - "csv files that contain the reuse distance/interval grouped by label. File " - "format: bucket,label_1,label_2,...,label_N. The first N buckets are " - "absolute values. The second N buckets are percentage values."); +DEFINE_int32(analyze_bottom_k_access_count_blocks, 0, + "Print out detailed access information for blocks with their " + "number of accesses are the bottom k among all blocks."); +DEFINE_int32(analyze_top_k_access_count_blocks, 0, + "Print out detailed access information for blocks with their " + "number of accesses are the top k among all blocks."); +DEFINE_string(block_cache_analysis_result_dir, "", + "The directory that saves block cache analysis results."); DEFINE_string( timeline_labels, "", "Group the number of accesses per block per second using these labels. " @@ -92,6 +86,42 @@ DEFINE_string( "seconds, between 10 seconds and 100 seconds, respectively. The last " "bucket contains the number of blocks with reuse interval longer than 100 " "seconds."); +DEFINE_string( + reuse_lifetime_labels, "", + "Group the reuse lifetime of a block using these labels. Reuse " + "lifetime is defined as the time interval between the first access on a " + "block and the last access on the same block. For blocks that are only " + "accessed once, its lifetime is set to kMaxUint64."); +DEFINE_string( + reuse_lifetime_buckets, "", + "Group blocks by their reuse lifetime given these buckets. For " + "example, if 'reuse_lifetime_buckets' is '1,10,100', we will " + "create four buckets. The first three buckets contain the number of " + "blocks with reuse lifetime less than 1 second, between 1 second and 10 " + "seconds, between 10 seconds and 100 seconds, respectively. The last " + "bucket contains the number of blocks with reuse lifetime longer than 100 " + "seconds."); +DEFINE_string( + analyze_callers, "", + "The list of callers to perform a detailed analysis on. If speicfied, the " + "analyzer will output a detailed percentage of accesses for each caller " + "break down by column family, level, and block type. A list of available " + "callers are: Get, MultiGet, Iterator, ApproximateSize, VerifyChecksum, " + "SSTDumpTool, ExternalSSTIngestion, Repair, Prefetch, Compaction, " + "CompactionRefill, Flush, SSTFileReader, Uncategorized."); +DEFINE_string(access_count_buckets, "", + "Group number of blocks by their access count given these " + "buckets. If specified, the analyzer will output a detailed " + "analysis on the number of blocks grouped by their access count " + "break down by block type and column family."); +DEFINE_int32(analyze_blocks_reuse_k_reuse_window, 0, + "Analyze the percentage of blocks that are accessed in the " + "[k, 2*k] seconds are accessed again in the next [2*k, 3*k], " + "[3*k, 4*k],...,[k*(n-1), k*n] seconds. "); +DEFINE_string(analyze_get_spatial_locality_labels, "", + "Group data blocks using these labels."); +DEFINE_string(analyze_get_spatial_locality_buckets, "", + "Group data blocks by their statistics using these buckets."); namespace rocksdb { namespace { @@ -112,6 +142,24 @@ const std::string kSupportedCacheNames = "ghost_lru_hybrid lru_hybrid_no_insert_on_row_miss " "ghost_lru_hybrid_no_insert_on_row_miss "; +// The suffix for the generated csv files. +const std::string kFileNameSuffixAccessTimeline = "access_timeline"; +const std::string kFileNameSuffixAvgReuseIntervalNaccesses = + "avg_reuse_interval_naccesses"; +const std::string kFileNameSuffixAvgReuseInterval = "avg_reuse_interval"; +const std::string kFileNameSuffixReuseInterval = "access_reuse_interval"; +const std::string kFileNameSuffixReuseLifetime = "reuse_lifetime"; +const std::string kFileNameSuffixAccessReuseBlocksTimeline = + "reuse_blocks_timeline"; +const std::string kFileNameSuffixPercentOfAccessSummary = + "percentage_of_accesses_summary"; +const std::string kFileNameSuffixPercentRefKeys = "percent_ref_keys"; +const std::string kFileNameSuffixPercentDataSizeOnRefKeys = + "percent_data_size_on_ref_keys"; +const std::string kFileNameSuffixPercentAccessesOnRefKeys = + "percent_accesses_on_ref_keys"; +const std::string kFileNameSuffixAccessCountSummary = "access_count_summary"; + std::string block_type_to_string(TraceType type) { switch (type) { case kBlockTraceFilterBlock: @@ -168,6 +216,53 @@ std::string caller_to_string(TableReaderCaller caller) { return "InvalidCaller"; } +TableReaderCaller string_to_caller(std::string caller_str) { + if (caller_str == "Get") { + return kUserGet; + } else if (caller_str == "MultiGet") { + return kUserMultiGet; + } else if (caller_str == "Iterator") { + return kUserIterator; + } else if (caller_str == "ApproximateSize") { + return kUserApproximateSize; + } else if (caller_str == "VerifyChecksum") { + return kUserVerifyChecksum; + } else if (caller_str == "SSTDumpTool") { + return kSSTDumpTool; + } else if (caller_str == "ExternalSSTIngestion") { + return kExternalSSTIngestion; + } else if (caller_str == "Repair") { + return kRepair; + } else if (caller_str == "Prefetch") { + return kPrefetch; + } else if (caller_str == "Compaction") { + return kCompaction; + } else if (caller_str == "CompactionRefill") { + return kCompactionRefill; + } else if (caller_str == "Flush") { + return kFlush; + } else if (caller_str == "SSTFileReader") { + return kSSTFileReader; + } else if (caller_str == "Uncategorized") { + return kUncategorized; + } + return TableReaderCaller::kMaxBlockCacheLookupCaller; +} + +bool is_user_access(TableReaderCaller caller) { + switch (caller) { + case kUserGet: + case kUserMultiGet: + case kUserIterator: + case kUserApproximateSize: + case kUserVerifyChecksum: + return true; + default: + break; + } + return false; +} + const char kBreakLine[] = "***************************************************************\n"; @@ -248,7 +343,7 @@ std::set BlockCacheTraceAnalyzer::ParseLabelStr( std::string BlockCacheTraceAnalyzer::BuildLabel( const std::set& labels, const std::string& cf_name, uint64_t fd, uint32_t level, TraceType type, TableReaderCaller caller, - const std::string& block_key) const { + uint64_t block_key) const { std::map label_value_map; label_value_map[kGroupbyAll] = kGroupbyAll; label_value_map[kGroupbyLevel] = std::to_string(level); @@ -256,7 +351,7 @@ std::string BlockCacheTraceAnalyzer::BuildLabel( label_value_map[kGroupbySSTFile] = std::to_string(fd); label_value_map[kGroupbyBlockType] = block_type_to_string(type); label_value_map[kGroupbyColumnFamily] = cf_name; - label_value_map[kGroupbyBlock] = block_key; + label_value_map[kGroupbyBlock] = std::to_string(block_key); // Concatenate the label values. std::string label; for (auto const& l : labels) { @@ -269,12 +364,14 @@ std::string BlockCacheTraceAnalyzer::BuildLabel( return label; } -void BlockCacheTraceAnalyzer::WriteAccessTimeline( - const std::string& label_str) const { - std::set labels = ParseLabelStr(label_str); - uint64_t start_time = port::kMaxUint64; - uint64_t end_time = 0; - std::map> label_access_timeline; +void BlockCacheTraceAnalyzer::TraverseBlocks( + std::function + block_callback) const { + uint64_t block_id = 0; for (auto const& cf_aggregates : cf_aggregates_map_) { // Stats per column family. const std::string& cf_name = cf_aggregates.first; @@ -289,42 +386,161 @@ void BlockCacheTraceAnalyzer::WriteAccessTimeline( for (auto const& block_access_info : block_type_aggregates.second.block_access_info_map) { // Stats per block. - for (auto const& timeline : - block_access_info.second.caller_num_accesses_timeline) { - const TableReaderCaller caller = timeline.first; - const std::string& block_key = block_access_info.first; - const std::string label = - BuildLabel(labels, cf_name, fd, level, type, caller, block_key); - for (auto const& naccess : timeline.second) { - const uint64_t timestamp = naccess.first; - const uint64_t num = naccess.second; - label_access_timeline[label][timestamp] += num; - start_time = std::min(start_time, timestamp); - end_time = std::max(end_time, timestamp); - } - } + block_callback(cf_name, fd, level, type, block_access_info.first, + block_id, block_access_info.second); + block_id++; } } } } +} + +void BlockCacheTraceAnalyzer::WriteGetSpatialLocality( + const std::string& label_str, + const std::vector& percent_buckets) const { + std::set labels = ParseLabelStr(label_str); + std::map> label_pnrefkeys_nblocks; + std::map> label_pnrefs_nblocks; + std::map> label_pndatasize_nblocks; + uint64_t nblocks = 0; + auto block_callback = [&](const std::string& cf_name, uint64_t fd, + uint32_t level, TraceType /*block_type*/, + const std::string& /*block_key*/, + uint64_t /*block_key_id*/, + const BlockAccessInfo& block) { + if (block.num_keys == 0) { + return; + } + uint64_t naccesses = 0; + for (auto const& key_access : block.key_num_access_map) { + for (auto const& caller_access : key_access.second) { + if (caller_access.first == TableReaderCaller::kUserGet) { + naccesses += caller_access.second; + } + } + } + const std::string label = + BuildLabel(labels, cf_name, fd, level, TraceType::kBlockTraceDataBlock, + TableReaderCaller::kUserGet, /*block_id=*/0); + + const uint64_t percent_referenced_for_existing_keys = + static_cast(std::max( + percent(block.key_num_access_map.size(), block.num_keys), 0.0)); + const uint64_t percent_accesses_for_existing_keys = + static_cast(std::max( + percent(block.num_referenced_key_exist_in_block, naccesses), 0.0)); + const uint64_t percent_referenced_data_size = static_cast( + std::max(percent(block.referenced_data_size, block.block_size), 0.0)); + if (label_pnrefkeys_nblocks.find(label) == label_pnrefkeys_nblocks.end()) { + for (auto const& percent_bucket : percent_buckets) { + label_pnrefkeys_nblocks[label][percent_bucket] = 0; + label_pnrefs_nblocks[label][percent_bucket] = 0; + label_pndatasize_nblocks[label][percent_bucket] = 0; + } + } + label_pnrefkeys_nblocks[label] + .upper_bound(percent_referenced_for_existing_keys) + ->second += 1; + label_pnrefs_nblocks[label] + .upper_bound(percent_accesses_for_existing_keys) + ->second += 1; + label_pndatasize_nblocks[label] + .upper_bound(percent_referenced_data_size) + ->second += 1; + nblocks += 1; + }; + TraverseBlocks(block_callback); + WriteStatsToFile(label_str, percent_buckets, kFileNameSuffixPercentRefKeys, + label_pnrefkeys_nblocks, nblocks); + WriteStatsToFile(label_str, percent_buckets, + kFileNameSuffixPercentAccessesOnRefKeys, + label_pnrefs_nblocks, nblocks); + WriteStatsToFile(label_str, percent_buckets, + kFileNameSuffixPercentDataSizeOnRefKeys, + label_pndatasize_nblocks, nblocks); +} + +void BlockCacheTraceAnalyzer::WriteAccessTimeline(const std::string& label_str, + uint64_t time_unit, + bool user_access_only) const { + std::set labels = ParseLabelStr(label_str); + uint64_t start_time = port::kMaxUint64; + uint64_t end_time = 0; + std::map> label_access_timeline; + std::map> access_count_block_id_map; + + auto block_callback = [&](const std::string& cf_name, uint64_t fd, + uint32_t level, TraceType type, + const std::string& /*block_key*/, uint64_t block_id, + const BlockAccessInfo& block) { + uint64_t naccesses = 0; + for (auto const& timeline : block.caller_num_accesses_timeline) { + const TableReaderCaller caller = timeline.first; + if (user_access_only && !is_user_access(caller)) { + continue; + } + const std::string label = + BuildLabel(labels, cf_name, fd, level, type, caller, block_id); + for (auto const& naccess : timeline.second) { + const uint64_t timestamp = naccess.first / time_unit; + const uint64_t num = naccess.second; + label_access_timeline[label][timestamp] += num; + start_time = std::min(start_time, timestamp); + end_time = std::max(end_time, timestamp); + naccesses += num; + } + } + if (naccesses > 0) { + access_count_block_id_map[naccesses].push_back(std::to_string(block_id)); + } + }; + TraverseBlocks(block_callback); // We have label_access_timeline now. Write them into a file. - const std::string output_path = - output_dir_ + "/" + label_str + "_access_timeline"; + const std::string user_access_prefix = + user_access_only ? "user_access_only_" : "all_access_"; + const std::string output_path = output_dir_ + "/" + user_access_prefix + + label_str + "_" + std::to_string(time_unit) + + "_" + kFileNameSuffixAccessTimeline; std::ofstream out(output_path); if (!out.is_open()) { return; } std::string header("time"); - for (auto const& label : label_access_timeline) { + if (labels.find("block") != labels.end()) { + for (uint64_t now = start_time; now <= end_time; now++) { + header += ","; + header += std::to_string(now); + } + out << header << std::endl; + // Write the most frequently accessed blocks first. + for (auto naccess_it = access_count_block_id_map.rbegin(); + naccess_it != access_count_block_id_map.rend(); naccess_it++) { + for (auto& block_id_it : naccess_it->second) { + std::string row(block_id_it); + for (uint64_t now = start_time; now <= end_time; now++) { + auto it = label_access_timeline[block_id_it].find(now); + row += ","; + if (it != label_access_timeline[block_id_it].end()) { + row += std::to_string(it->second); + } else { + row += "0"; + } + } + out << row << std::endl; + } + } + out.close(); + return; + } + for (uint64_t now = start_time; now <= end_time; now++) { header += ","; - header += label.first; + header += std::to_string(now); } out << header << std::endl; - std::string row; - for (uint64_t now = start_time; now <= end_time; now++) { - row = std::to_string(now); - for (auto const& label : label_access_timeline) { + for (auto const& label : label_access_timeline) { + std::string row(label.first); + for (uint64_t now = start_time; now <= end_time; now++) { auto it = label.second.find(now); row += ","; if (it != label.second.end()) { @@ -335,52 +551,38 @@ void BlockCacheTraceAnalyzer::WriteAccessTimeline( } out << row << std::endl; } + out.close(); } void BlockCacheTraceAnalyzer::WriteReuseDistance( const std::string& label_str, - const std::set& distance_buckets) const { + const std::vector& distance_buckets) const { std::set labels = ParseLabelStr(label_str); std::map> label_distance_num_reuses; uint64_t total_num_reuses = 0; - for (auto const& cf_aggregates : cf_aggregates_map_) { - // Stats per column family. - const std::string& cf_name = cf_aggregates.first; - for (auto const& file_aggregates : cf_aggregates.second.fd_aggregates_map) { - // Stats per SST file. - const uint64_t fd = file_aggregates.first; - const uint32_t level = file_aggregates.second.level; - for (auto const& block_type_aggregates : - file_aggregates.second.block_type_aggregates_map) { - // Stats per block type. - const TraceType type = block_type_aggregates.first; - for (auto const& block_access_info : - block_type_aggregates.second.block_access_info_map) { - // Stats per block. - const std::string& block_key = block_access_info.first; - const std::string label = BuildLabel( - labels, cf_name, fd, level, type, - TableReaderCaller::kMaxBlockCacheLookupCaller, block_key); - if (label_distance_num_reuses.find(label) == - label_distance_num_reuses.end()) { - // The first time we encounter this label. - for (auto const& distance_bucket : distance_buckets) { - label_distance_num_reuses[label][distance_bucket] = 0; - } - } - for (auto const& reuse_distance : - block_access_info.second.reuse_distance_count) { - label_distance_num_reuses[label] - .upper_bound(reuse_distance.first) - ->second += reuse_distance.second; - total_num_reuses += reuse_distance.second; - } - } + auto block_callback = [&](const std::string& cf_name, uint64_t fd, + uint32_t level, TraceType type, + const std::string& /*block_key*/, uint64_t block_id, + const BlockAccessInfo& block) { + const std::string label = + BuildLabel(labels, cf_name, fd, level, type, + TableReaderCaller::kMaxBlockCacheLookupCaller, block_id); + if (label_distance_num_reuses.find(label) == + label_distance_num_reuses.end()) { + // The first time we encounter this label. + for (auto const& distance_bucket : distance_buckets) { + label_distance_num_reuses[label][distance_bucket] = 0; } } - } - + for (auto const& reuse_distance : block.reuse_distance_count) { + label_distance_num_reuses[label] + .upper_bound(reuse_distance.first) + ->second += reuse_distance.second; + total_num_reuses += reuse_distance.second; + } + }; + TraverseBlocks(block_callback); // We have label_naccesses and label_distance_num_reuses now. Write them into // a file. const std::string output_path = @@ -395,18 +597,6 @@ void BlockCacheTraceAnalyzer::WriteReuseDistance( header += label_it.first; } out << header << std::endl; - // Absolute values. - for (auto const& bucket : distance_buckets) { - std::string row(std::to_string(bucket)); - for (auto const& label_it : label_distance_num_reuses) { - auto const& it = label_it.second.find(bucket); - assert(it != label_it.second.end()); - row += ","; - row += std::to_string(it->second); - } - out << row << std::endl; - } - // Percentage values. for (auto const& bucket : distance_buckets) { std::string row(std::to_string(bucket)); for (auto const& label_it : label_distance_num_reuses) { @@ -421,7 +611,7 @@ void BlockCacheTraceAnalyzer::WriteReuseDistance( } void BlockCacheTraceAnalyzer::UpdateReuseIntervalStats( - const std::string& label, const std::set& time_buckets, + const std::string& label, const std::vector& time_buckets, const std::map timeline, std::map>* label_time_num_reuses, uint64_t* total_num_reuses) const { @@ -434,119 +624,434 @@ void BlockCacheTraceAnalyzer::UpdateReuseIntervalStats( } } auto it = timeline.begin(); - const uint64_t prev_timestamp = it->first; + uint64_t prev_timestamp = it->first; const uint64_t prev_num = it->second; it++; // Reused within one second. if (prev_num > 1) { - (*label_time_num_reuses)[label].upper_bound(1)->second += prev_num - 1; + (*label_time_num_reuses)[label].upper_bound(0)->second += prev_num - 1; *total_num_reuses += prev_num - 1; } while (it != timeline.end()) { const uint64_t timestamp = it->first; const uint64_t num = it->second; const uint64_t reuse_interval = timestamp - prev_timestamp; - (*label_time_num_reuses)[label].upper_bound(reuse_interval)->second += num; + (*label_time_num_reuses)[label].upper_bound(reuse_interval)->second += 1; + if (num > 1) { + (*label_time_num_reuses)[label].upper_bound(0)->second += num - 1; + } + prev_timestamp = timestamp; *total_num_reuses += num; + it++; } } -void BlockCacheTraceAnalyzer::WriteReuseInterval( - const std::string& label_str, - const std::set& time_buckets) const { - std::set labels = ParseLabelStr(label_str); - std::map> label_time_num_reuses; - uint64_t total_num_reuses = 0; - for (auto const& cf_aggregates : cf_aggregates_map_) { - // Stats per column family. - const std::string& cf_name = cf_aggregates.first; - for (auto const& file_aggregates : cf_aggregates.second.fd_aggregates_map) { - // Stats per SST file. - const uint64_t fd = file_aggregates.first; - const uint32_t level = file_aggregates.second.level; - for (auto const& block_type_aggregates : - file_aggregates.second.block_type_aggregates_map) { - // Stats per block type. - const TraceType type = block_type_aggregates.first; - for (auto const& block_access_info : - block_type_aggregates.second.block_access_info_map) { - // Stats per block. - const std::string& block_key = block_access_info.first; - if (labels.find(kGroupbyCaller) != labels.end()) { - for (auto const& timeline : - block_access_info.second.caller_num_accesses_timeline) { - const TableReaderCaller caller = timeline.first; - const std::string label = BuildLabel(labels, cf_name, fd, level, - type, caller, block_key); - UpdateReuseIntervalStats(label, time_buckets, timeline.second, - &label_time_num_reuses, - &total_num_reuses); - } - continue; - } - // Does not group by caller so we need to flatten the access timeline. - const std::string label = BuildLabel( - labels, cf_name, fd, level, type, - TableReaderCaller::kMaxBlockCacheLookupCaller, block_key); - std::map timeline; - for (auto const& caller_timeline : - block_access_info.second.caller_num_accesses_timeline) { - for (auto const& time_naccess : caller_timeline.second) { - timeline[time_naccess.first] += time_naccess.second; - } - } - UpdateReuseIntervalStats(label, time_buckets, timeline, - &label_time_num_reuses, &total_num_reuses); - } - } - } - } - - // We have label_naccesses and label_interval_num_reuses now. Write them into - // a file. +void BlockCacheTraceAnalyzer::WriteStatsToFile( + const std::string& label_str, const std::vector& time_buckets, + const std::string& filename_suffix, + const std::map>& label_data, + uint64_t ntotal) const { const std::string output_path = - output_dir_ + "/" + label_str + "_reuse_interval"; + output_dir_ + "/" + label_str + "_" + filename_suffix; std::ofstream out(output_path); if (!out.is_open()) { return; } std::string header("bucket"); - for (auto const& label_it : label_time_num_reuses) { + for (auto const& label_it : label_data) { header += ","; header += label_it.first; } out << header << std::endl; - // Absolute values. for (auto const& bucket : time_buckets) { std::string row(std::to_string(bucket)); - for (auto const& label_it : label_time_num_reuses) { + for (auto const& label_it : label_data) { auto const& it = label_it.second.find(bucket); assert(it != label_it.second.end()); row += ","; - row += std::to_string(it->second); - } - out << row << std::endl; - } - // Percentage values. - for (auto const& bucket : time_buckets) { - std::string row(std::to_string(bucket)); - for (auto const& label_it : label_time_num_reuses) { - auto const& it = label_it.second.find(bucket); - assert(it != label_it.second.end()); - row += ","; - row += std::to_string(percent(it->second, total_num_reuses)); + row += std::to_string(percent(it->second, ntotal)); } out << row << std::endl; } out.close(); } +void BlockCacheTraceAnalyzer::WriteReuseInterval( + const std::string& label_str, + const std::vector& time_buckets) const { + std::set labels = ParseLabelStr(label_str); + std::map> label_time_num_reuses; + std::map> label_avg_reuse_nblocks; + std::map> label_avg_reuse_naccesses; + + uint64_t total_num_reuses = 0; + uint64_t total_nblocks = 0; + uint64_t total_accesses = 0; + auto block_callback = [&](const std::string& cf_name, uint64_t fd, + uint32_t level, TraceType type, + const std::string& /*block_key*/, uint64_t block_id, + const BlockAccessInfo& block) { + total_nblocks++; + total_accesses += block.num_accesses; + uint64_t avg_reuse_interval = 0; + if (block.num_accesses > 1) { + avg_reuse_interval = ((block.last_access_time - block.first_access_time) / + kMicrosInSecond) / + block.num_accesses; + } else { + avg_reuse_interval = port::kMaxUint64 - 1; + } + if (labels.find(kGroupbyCaller) != labels.end()) { + for (auto const& timeline : block.caller_num_accesses_timeline) { + const TableReaderCaller caller = timeline.first; + const std::string label = + BuildLabel(labels, cf_name, fd, level, type, caller, block_id); + UpdateReuseIntervalStats(label, time_buckets, timeline.second, + &label_time_num_reuses, &total_num_reuses); + } + return; + } + // Does not group by caller so we need to flatten the access timeline. + const std::string label = + BuildLabel(labels, cf_name, fd, level, type, + TableReaderCaller::kMaxBlockCacheLookupCaller, block_id); + std::map timeline; + for (auto const& caller_timeline : block.caller_num_accesses_timeline) { + for (auto const& time_naccess : caller_timeline.second) { + timeline[time_naccess.first] += time_naccess.second; + } + } + UpdateReuseIntervalStats(label, time_buckets, timeline, + &label_time_num_reuses, &total_num_reuses); + if (label_avg_reuse_nblocks.find(label) == label_avg_reuse_nblocks.end()) { + for (auto const& time_bucket : time_buckets) { + label_avg_reuse_nblocks[label][time_bucket] = 0; + label_avg_reuse_naccesses[label][time_bucket] = 0; + } + } + label_avg_reuse_nblocks[label].upper_bound(avg_reuse_interval)->second += 1; + label_avg_reuse_naccesses[label].upper_bound(avg_reuse_interval)->second += + block.num_accesses; + }; + TraverseBlocks(block_callback); + + // Write the stats into files. + WriteStatsToFile(label_str, time_buckets, kFileNameSuffixReuseInterval, + label_time_num_reuses, total_num_reuses); + WriteStatsToFile(label_str, time_buckets, kFileNameSuffixAvgReuseInterval, + label_avg_reuse_nblocks, total_nblocks); + WriteStatsToFile(label_str, time_buckets, + kFileNameSuffixAvgReuseIntervalNaccesses, + label_avg_reuse_naccesses, total_accesses); +} + +void BlockCacheTraceAnalyzer::WriteReuseLifetime( + const std::string& label_str, + const std::vector& time_buckets) const { + std::set labels = ParseLabelStr(label_str); + std::map> label_lifetime_nblocks; + uint64_t total_nblocks = 0; + auto block_callback = [&](const std::string& cf_name, uint64_t fd, + uint32_t level, TraceType type, + const std::string& /*block_key*/, uint64_t block_id, + const BlockAccessInfo& block) { + uint64_t lifetime = 0; + if (block.num_accesses > 1) { + lifetime = + (block.last_access_time - block.first_access_time) / kMicrosInSecond; + } else { + lifetime = port::kMaxUint64 - 1; + } + const std::string label = + BuildLabel(labels, cf_name, fd, level, type, + TableReaderCaller::kMaxBlockCacheLookupCaller, block_id); + + if (label_lifetime_nblocks.find(label) == label_lifetime_nblocks.end()) { + // The first time we encounter this label. + for (auto const& time_bucket : time_buckets) { + label_lifetime_nblocks[label][time_bucket] = 0; + } + } + label_lifetime_nblocks[label].upper_bound(lifetime)->second += 1; + total_nblocks += 1; + }; + TraverseBlocks(block_callback); + WriteStatsToFile(label_str, time_buckets, kFileNameSuffixReuseLifetime, + label_lifetime_nblocks, total_nblocks); +} + +void BlockCacheTraceAnalyzer::WriteBlockReuseTimeline( + uint64_t reuse_window, bool user_access_only, TraceType block_type) const { + // A map from block key to an array of bools that states whether a block is + // accessed in a time window. + std::map> block_accessed; + const uint64_t trace_duration = + trace_end_timestamp_in_seconds_ - trace_start_timestamp_in_seconds_; + const uint64_t reuse_vector_size = (trace_duration / reuse_window); + if (reuse_vector_size < 2) { + // The reuse window is less than 2. We cannot calculate the reused + // percentage of blocks. + return; + } + auto block_callback = [&](const std::string& /*cf_name*/, uint64_t /*fd*/, + uint32_t /*level*/, TraceType /*type*/, + const std::string& /*block_key*/, uint64_t block_id, + const BlockAccessInfo& block) { + if (block_accessed.find(block_id) == block_accessed.end()) { + block_accessed[block_id].resize(reuse_vector_size); + for (uint64_t i = 0; i < reuse_vector_size; i++) { + block_accessed[block_id][i] = false; + } + } + for (auto const& caller_num : block.caller_num_accesses_timeline) { + const TableReaderCaller caller = caller_num.first; + for (auto const& timeline : caller_num.second) { + const uint64_t timestamp = timeline.first; + const uint64_t elapsed_time = + timestamp - trace_start_timestamp_in_seconds_; + if (!user_access_only || (user_access_only && is_user_access(caller))) { + uint64_t index = + std::min(elapsed_time / reuse_window, reuse_vector_size - 1); + block_accessed[block_id][index] = true; + } + } + } + }; + TraverseBlocks(block_callback); + + // A cell is the number of blocks accessed in a reuse window. + uint64_t reuse_table[reuse_vector_size][reuse_vector_size]; + for (uint64_t start_time = 0; start_time < reuse_vector_size; start_time++) { + // Initialize the reuse_table. + for (uint64_t i = 0; i < reuse_vector_size; i++) { + reuse_table[start_time][i] = 0; + } + // Examine all blocks. + for (auto const& block : block_accessed) { + for (uint64_t i = start_time; i < reuse_vector_size; i++) { + if (block.second[start_time] && block.second[i]) { + // This block is accessed at start time and at the current time. We + // increment reuse_table[start_time][i] since it is reused at the ith + // window. + reuse_table[start_time][i]++; + } + } + } + } + const std::string user_access_prefix = + user_access_only ? "_user_access_only_" : "_all_access_"; + const std::string output_path = + output_dir_ + "/" + block_type_to_string(block_type) + + user_access_prefix + std::to_string(reuse_window) + "_" + + kFileNameSuffixAccessReuseBlocksTimeline; + std::ofstream out(output_path); + if (!out.is_open()) { + return; + } + std::string header("start_time"); + for (uint64_t start_time = 0; start_time < reuse_vector_size; start_time++) { + header += ","; + header += std::to_string(start_time); + } + out << header << std::endl; + for (uint64_t start_time = 0; start_time < reuse_vector_size; start_time++) { + std::string row(std::to_string(start_time * reuse_window)); + for (uint64_t j = 0; j < reuse_vector_size; j++) { + row += ","; + if (j < start_time) { + row += "100.0"; + } else { + row += std::to_string(percent(reuse_table[start_time][j], + reuse_table[start_time][start_time])); + } + } + out << row << std::endl; + } + out.close(); +} + +std::string BlockCacheTraceAnalyzer::OutputPercentAccessStats( + uint64_t total_accesses, + const std::map& cf_access_count) const { + std::string row; + for (auto const& cf_aggregates : cf_aggregates_map_) { + const std::string& cf_name = cf_aggregates.first; + const auto& naccess = cf_access_count.find(cf_name); + row += ","; + if (naccess != cf_access_count.end()) { + row += std::to_string(percent(naccess->second, total_accesses)); + } else { + row += "0"; + } + } + return row; +} + +void BlockCacheTraceAnalyzer::WritePercentAccessSummaryStats() const { + std::map> + caller_cf_accesses; + uint64_t total_accesses = 0; + auto block_callback = + [&](const std::string& cf_name, uint64_t /*fd*/, uint32_t /*level*/, + TraceType /*type*/, const std::string& /*block_key*/, + uint64_t /*block_id*/, const BlockAccessInfo& block) { + for (auto const& caller_num : block.caller_num_access_map) { + const TableReaderCaller caller = caller_num.first; + const uint64_t naccess = caller_num.second; + caller_cf_accesses[caller][cf_name] += naccess; + total_accesses += naccess; + } + }; + TraverseBlocks(block_callback); + + const std::string output_path = + output_dir_ + "/" + kFileNameSuffixPercentOfAccessSummary; + std::ofstream out(output_path); + if (!out.is_open()) { + return; + } + std::string header("caller"); + for (auto const& cf_name : cf_aggregates_map_) { + header += ","; + header += cf_name.first; + } + out << header << std::endl; + for (auto const& cf_naccess_it : caller_cf_accesses) { + const TableReaderCaller caller = cf_naccess_it.first; + std::string row; + row += caller_to_string(caller); + row += OutputPercentAccessStats(total_accesses, cf_naccess_it.second); + out << row << std::endl; + } + out.close(); +} + +void BlockCacheTraceAnalyzer::WriteDetailedPercentAccessSummaryStats( + TableReaderCaller analyzing_caller) const { + std::map> level_cf_accesses; + std::map> bt_cf_accesses; + uint64_t total_accesses = 0; + auto block_callback = + [&](const std::string& cf_name, uint64_t /*fd*/, uint32_t level, + TraceType type, const std::string& /*block_key*/, + uint64_t /*block_id*/, const BlockAccessInfo& block) { + for (auto const& caller_num : block.caller_num_access_map) { + const TableReaderCaller caller = caller_num.first; + if (caller == analyzing_caller) { + const uint64_t naccess = caller_num.second; + level_cf_accesses[level][cf_name] += naccess; + bt_cf_accesses[type][cf_name] += naccess; + total_accesses += naccess; + } + } + }; + TraverseBlocks(block_callback); + { + const std::string output_path = + output_dir_ + "/" + caller_to_string(analyzing_caller) + "_level_" + + kFileNameSuffixPercentOfAccessSummary; + std::ofstream out(output_path); + if (!out.is_open()) { + return; + } + std::string header("level"); + for (auto const& cf_name : cf_aggregates_map_) { + header += ","; + header += cf_name.first; + } + out << header << std::endl; + for (auto const& level_naccess_it : level_cf_accesses) { + const uint32_t level = level_naccess_it.first; + std::string row; + row += std::to_string(level); + row += OutputPercentAccessStats(total_accesses, level_naccess_it.second); + out << row << std::endl; + } + out.close(); + } + { + const std::string output_path = + output_dir_ + "/" + caller_to_string(analyzing_caller) + "_bt_" + + kFileNameSuffixPercentOfAccessSummary; + std::ofstream out(output_path); + if (!out.is_open()) { + return; + } + std::string header("bt"); + for (auto const& cf_name : cf_aggregates_map_) { + header += ","; + header += cf_name.first; + } + out << header << std::endl; + for (auto const& bt_naccess_it : bt_cf_accesses) { + const TraceType bt = bt_naccess_it.first; + std::string row; + row += block_type_to_string(bt); + row += OutputPercentAccessStats(total_accesses, bt_naccess_it.second); + out << row << std::endl; + } + out.close(); + } +} + +void BlockCacheTraceAnalyzer::WriteAccessCountSummaryStats( + const std::vector& access_count_buckets, + bool user_access_only) const { + // x: buckets. + // y: # of accesses. + std::map> bt_access_nblocks; + std::map> cf_access_nblocks; + uint64_t total_nblocks = 0; + auto block_callback = + [&](const std::string& cf_name, uint64_t /*fd*/, uint32_t /*level*/, + TraceType type, const std::string& /*block_key*/, + uint64_t /*block_id*/, const BlockAccessInfo& block) { + const std::string type_str = block_type_to_string(type); + if (cf_access_nblocks.find(cf_name) == cf_access_nblocks.end()) { + // initialize. + for (auto& access : access_count_buckets) { + cf_access_nblocks[cf_name][access] = 0; + } + } + if (bt_access_nblocks.find(type_str) == bt_access_nblocks.end()) { + // initialize. + for (auto& access : access_count_buckets) { + bt_access_nblocks[type_str][access] = 0; + } + } + uint64_t naccesses = 0; + for (auto const& caller_access : block.caller_num_access_map) { + if (!user_access_only || + (user_access_only && is_user_access(caller_access.first))) { + naccesses += caller_access.second; + } + } + if (naccesses == 0) { + return; + } + total_nblocks += 1; + bt_access_nblocks[type_str].upper_bound(naccesses)->second += 1; + cf_access_nblocks[cf_name].upper_bound(naccesses)->second += 1; + }; + TraverseBlocks(block_callback); + const std::string user_access_prefix = + user_access_only ? "user_access_only_" : "all_access_"; + WriteStatsToFile("cf", access_count_buckets, + user_access_prefix + kFileNameSuffixAccessCountSummary, + cf_access_nblocks, total_nblocks); + WriteStatsToFile("bt", access_count_buckets, + user_access_prefix + kFileNameSuffixAccessCountSummary, + bt_access_nblocks, total_nblocks); +} + BlockCacheTraceAnalyzer::BlockCacheTraceAnalyzer( const std::string& trace_file_path, const std::string& output_dir, + bool compute_reuse_distance, std::unique_ptr&& cache_simulator) : env_(rocksdb::Env::Default()), trace_file_path_(trace_file_path), output_dir_(output_dir), + compute_reuse_distance_(compute_reuse_distance), cache_simulator_(std::move(cache_simulator)) {} void BlockCacheTraceAnalyzer::ComputeReuseDistance( @@ -577,19 +1082,28 @@ void BlockCacheTraceAnalyzer::RecordAccess( file_aggr.block_type_aggregates_map[access.block_type]; BlockAccessInfo& block_access_info = block_type_aggr.block_access_info_map[access.block_key]; - ComputeReuseDistance(&block_access_info); + if (compute_reuse_distance_) { + ComputeReuseDistance(&block_access_info); + } block_access_info.AddAccess(access); block_info_map_[access.block_key] = &block_access_info; + if (trace_start_timestamp_in_seconds_ == 0) { + trace_start_timestamp_in_seconds_ = + access.access_timestamp / kMicrosInSecond; + } + trace_end_timestamp_in_seconds_ = access.access_timestamp / kMicrosInSecond; - // Add this block to all existing blocks. - for (auto& cf_aggregates : cf_aggregates_map_) { - for (auto& file_aggregates : cf_aggregates.second.fd_aggregates_map) { - for (auto& block_type_aggregates : - file_aggregates.second.block_type_aggregates_map) { - for (auto& existing_block : - block_type_aggregates.second.block_access_info_map) { - existing_block.second.unique_blocks_since_last_access.insert( - access.block_key); + if (compute_reuse_distance_) { + // Add this block to all existing blocks. + for (auto& cf_aggregates : cf_aggregates_map_) { + for (auto& file_aggregates : cf_aggregates.second.fd_aggregates_map) { + for (auto& block_type_aggregates : + file_aggregates.second.block_type_aggregates_map) { + for (auto& existing_block : + block_type_aggregates.second.block_access_info_map) { + existing_block.second.unique_blocks_since_last_access.insert( + access.block_key); + } } } } @@ -608,6 +1122,9 @@ Status BlockCacheTraceAnalyzer::Analyze() { if (!s.ok()) { return s; } + uint64_t start = env_->NowMicros(); + uint64_t processed_records = 0; + uint64_t time_interval = 0; while (s.ok()) { BlockCacheTraceRecord access; s = reader.ReadAccess(&access); @@ -618,6 +1135,17 @@ Status BlockCacheTraceAnalyzer::Analyze() { if (cache_simulator_) { cache_simulator_->Access(access); } + processed_records++; + uint64_t now = env_->NowMicros(); + uint64_t duration = (now - start) / kMicrosInSecond; + if (duration > 10 * time_interval) { + fprintf(stdout, + "Running for %" PRIu64 " seconds: Processed %" PRIu64 + " records/second\n", + duration, processed_records / duration); + processed_records = 0; + time_interval++; + } } return Status::OK(); } @@ -626,26 +1154,21 @@ void BlockCacheTraceAnalyzer::PrintBlockSizeStats() const { HistogramStat bs_stats; std::map bt_stats_map; std::map> cf_bt_stats_map; - for (auto const& cf_aggregates : cf_aggregates_map_) { - // Stats per column family. - const std::string& cf_name = cf_aggregates.first; - for (auto const& file_aggregates : cf_aggregates.second.fd_aggregates_map) { - // Stats per SST file. - for (auto const& block_type_aggregates : - file_aggregates.second.block_type_aggregates_map) { - // Stats per block type. - const TraceType type = block_type_aggregates.first; - for (auto const& block_access_info : - block_type_aggregates.second.block_access_info_map) { - // Stats per block. - bs_stats.Add(block_access_info.second.block_size); - bt_stats_map[type].Add(block_access_info.second.block_size); - cf_bt_stats_map[cf_name][type].Add( - block_access_info.second.block_size); + auto block_callback = + [&](const std::string& cf_name, uint64_t /*fd*/, uint32_t /*level*/, + TraceType type, const std::string& /*block_key*/, + uint64_t /*block_id*/, const BlockAccessInfo& block) { + if (block.block_size == 0) { + // Block size may be 0 when 1) compaction observes a cache miss and + // does not insert the missing block into the cache again. 2) + // fetching filter blocks in SST files at the last level. + return; } - } - } - } + bs_stats.Add(block.block_size); + bt_stats_map[type].Add(block.block_size); + cf_bt_stats_map[cf_name][type].Add(block.block_size); + }; + TraverseBlocks(block_callback); fprintf(stdout, "Block size stats: \n%s", bs_stats.ToString().c_str()); for (auto const& bt_stats : bt_stats_map) { print_break_lines(/*num_break_lines=*/1); @@ -665,33 +1188,151 @@ void BlockCacheTraceAnalyzer::PrintBlockSizeStats() const { } } -void BlockCacheTraceAnalyzer::PrintAccessCountStats() const { +void BlockCacheTraceAnalyzer::PrintAccessCountStats(bool user_access_only, + uint32_t bottom_k, + uint32_t top_k) const { HistogramStat access_stats; std::map bt_stats_map; std::map> cf_bt_stats_map; - for (auto const& cf_aggregates : cf_aggregates_map_) { - // Stats per column family. - const std::string& cf_name = cf_aggregates.first; - for (auto const& file_aggregates : cf_aggregates.second.fd_aggregates_map) { - // Stats per SST file. - for (auto const& block_type_aggregates : - file_aggregates.second.block_type_aggregates_map) { - // Stats per block type. - const TraceType type = block_type_aggregates.first; - for (auto const& block_access_info : - block_type_aggregates.second.block_access_info_map) { - // Stats per block. - access_stats.Add(block_access_info.second.num_accesses); - bt_stats_map[type].Add(block_access_info.second.num_accesses); - cf_bt_stats_map[cf_name][type].Add( - block_access_info.second.num_accesses); + std::map> access_count_blocks; + auto block_callback = [&](const std::string& cf_name, uint64_t /*fd*/, + uint32_t /*level*/, TraceType type, + const std::string& block_key, uint64_t /*block_id*/, + const BlockAccessInfo& block) { + uint64_t naccesses = 0; + for (auto const& caller_access : block.caller_num_access_map) { + if (!user_access_only || + (user_access_only && is_user_access(caller_access.first))) { + naccesses += caller_access.second; + } + } + if (naccesses == 0) { + return; + } + if (type == TraceType::kBlockTraceDataBlock) { + access_count_blocks[naccesses].push_back(block_key); + } + access_stats.Add(naccesses); + bt_stats_map[type].Add(naccesses); + cf_bt_stats_map[cf_name][type].Add(naccesses); + }; + TraverseBlocks(block_callback); + fprintf(stdout, + "Block access count stats: The number of accesses per block. %s\n%s", + user_access_only ? "User accesses only" : "All accesses", + access_stats.ToString().c_str()); + uint32_t bottom_k_index = 0; + for (auto naccess_it = access_count_blocks.begin(); + naccess_it != access_count_blocks.end(); naccess_it++) { + bottom_k_index++; + if (bottom_k_index >= bottom_k) { + break; + } + std::map caller_naccesses; + uint64_t naccesses = 0; + for (auto const& block_id : naccess_it->second) { + BlockAccessInfo* block = block_info_map_.find(block_id)->second; + for (auto const& caller_access : block->caller_num_access_map) { + if (!user_access_only || + (user_access_only && is_user_access(caller_access.first))) { + caller_naccesses[caller_access.first] += caller_access.second; + naccesses += caller_access.second; } } } + std::string statistics("Caller:"); + for (auto const& caller_naccessess_it : caller_naccesses) { + statistics += caller_to_string(caller_naccessess_it.first); + statistics += ":"; + statistics += + std::to_string(percent(caller_naccessess_it.second, naccesses)); + statistics += ","; + } + fprintf(stdout, + "Bottom %" PRIu32 " access count. Access count=%" PRIu64 + " nblocks=%" PRIu64 " %s\n", + bottom_k, naccess_it->first, naccess_it->second.size(), + statistics.c_str()); } - fprintf(stdout, - "Block access count stats: The number of accesses per block.\n%s", - access_stats.ToString().c_str()); + + uint32_t top_k_index = 0; + for (auto naccess_it = access_count_blocks.rbegin(); + naccess_it != access_count_blocks.rend(); naccess_it++) { + top_k_index++; + if (top_k_index >= top_k) { + break; + } + for (auto const& block_id : naccess_it->second) { + BlockAccessInfo* block = block_info_map_.find(block_id)->second; + std::string statistics("Caller:"); + uint64_t naccesses = 0; + for (auto const& caller_access : block->caller_num_access_map) { + if (!user_access_only || + (user_access_only && is_user_access(caller_access.first))) { + naccesses += caller_access.second; + } + } + assert(naccesses > 0); + for (auto const& caller_access : block->caller_num_access_map) { + if (!user_access_only || + (user_access_only && is_user_access(caller_access.first))) { + statistics += ","; + statistics += caller_to_string(caller_access.first); + statistics += ":"; + statistics += + std::to_string(percent(caller_access.second, naccesses)); + } + } + uint64_t ref_keys_accesses = 0; + uint64_t ref_keys_does_not_exist_accesses = 0; + for (auto const& ref_key_caller_access : block->key_num_access_map) { + for (auto const& caller_access : ref_key_caller_access.second) { + if (!user_access_only || + (user_access_only && is_user_access(caller_access.first))) { + ref_keys_accesses += caller_access.second; + } + } + } + for (auto const& ref_key_caller_access : + block->non_exist_key_num_access_map) { + for (auto const& caller_access : ref_key_caller_access.second) { + if (!user_access_only || + (user_access_only && is_user_access(caller_access.first))) { + ref_keys_does_not_exist_accesses += caller_access.second; + } + } + } + statistics += ",nkeys="; + statistics += std::to_string(block->num_keys); + statistics += ",block_size="; + statistics += std::to_string(block->block_size); + statistics += ",num_ref_keys="; + statistics += std::to_string(block->key_num_access_map.size()); + statistics += ",percent_access_ref_keys="; + statistics += std::to_string(percent(ref_keys_accesses, naccesses)); + statistics += ",num_ref_keys_does_not_exist="; + statistics += std::to_string(block->non_exist_key_num_access_map.size()); + statistics += ",percent_access_ref_keys_does_not_exist="; + statistics += + std::to_string(percent(ref_keys_does_not_exist_accesses, naccesses)); + statistics += ",ref_data_size="; + statistics += std::to_string(block->referenced_data_size); + fprintf(stdout, + "Top %" PRIu32 " access count blocks access_count=%" PRIu64 + " %s\n", + top_k, naccess_it->first, statistics.c_str()); + // if (block->referenced_data_size > block->block_size) { + // for (auto const& ref_key_it : block->key_num_access_map) { + // ParsedInternalKey internal_key; + // ParseInternalKey(ref_key_it.first, &internal_key); + // printf("######%lu %lu %d %s\n", block->referenced_data_size, + // block->block_size, internal_key.type, + // internal_key.user_key.ToString().c_str()); + // } + // } + } + } + for (auto const& bt_stats : bt_stats_map) { print_break_lines(/*num_break_lines=*/1); fprintf(stdout, "Break down by block type %s: \n%s", @@ -727,62 +1368,49 @@ void BlockCacheTraceAnalyzer::PrintDataBlockAccessStats() const { HistogramStat stdev_naccesses_per_key_in_a_data_block; std::map cf_stdev_naccesses_per_key_in_a_data_block; - - for (auto const& cf_aggregates : cf_aggregates_map_) { - // Stats per column family. - const std::string& cf_name = cf_aggregates.first; - for (auto const& file_aggregates : cf_aggregates.second.fd_aggregates_map) { - // Stats per SST file. - for (auto const& block_type_aggregates : - file_aggregates.second.block_type_aggregates_map) { - // Stats per block type. - for (auto const& block_access_info : - block_type_aggregates.second.block_access_info_map) { - // Stats per block. - if (block_access_info.second.num_keys == 0) { - continue; - } - // Use four decimal points. - uint64_t percent_referenced_for_existing_keys = (uint64_t)( - ((double)block_access_info.second.key_num_access_map.size() / - (double)block_access_info.second.num_keys) * - 10000.0); - uint64_t percent_referenced_for_non_existing_keys = - (uint64_t)(((double)block_access_info.second - .non_exist_key_num_access_map.size() / - (double)block_access_info.second.num_keys) * - 10000.0); - uint64_t percent_accesses_for_existing_keys = (uint64_t)( - ((double) - block_access_info.second.num_referenced_key_exist_in_block / - (double)block_access_info.second.num_accesses) * - 10000.0); - - HistogramStat hist_naccess_per_key; - for (auto const& key_access : - block_access_info.second.key_num_access_map) { - hist_naccess_per_key.Add(key_access.second); - } - uint64_t avg_accesses = hist_naccess_per_key.Average(); - uint64_t stdev_accesses = hist_naccess_per_key.StandardDeviation(); - avg_naccesses_per_key_in_a_data_block.Add(avg_accesses); - cf_avg_naccesses_per_key_in_a_data_block[cf_name].Add(avg_accesses); - stdev_naccesses_per_key_in_a_data_block.Add(stdev_accesses); - cf_stdev_naccesses_per_key_in_a_data_block[cf_name].Add( - stdev_accesses); - - existing_keys_stats.Add(percent_referenced_for_existing_keys); - cf_existing_keys_stats_map[cf_name].Add( - percent_referenced_for_existing_keys); - non_existing_keys_stats.Add(percent_referenced_for_non_existing_keys); - cf_non_existing_keys_stats_map[cf_name].Add( - percent_referenced_for_non_existing_keys); - block_access_stats.Add(percent_accesses_for_existing_keys); - cf_block_access_info[cf_name].Add(percent_accesses_for_existing_keys); + auto block_callback = + [&](const std::string& cf_name, uint64_t /*fd*/, uint32_t /*level*/, + TraceType /*type*/, const std::string& /*block_key*/, + uint64_t /*block_id*/, const BlockAccessInfo& block) { + if (block.num_keys == 0) { + return; } - } - } - } + // Use four decimal points. + uint64_t percent_referenced_for_existing_keys = (uint64_t)( + ((double)block.key_num_access_map.size() / (double)block.num_keys) * + 10000.0); + uint64_t percent_referenced_for_non_existing_keys = + (uint64_t)(((double)block.non_exist_key_num_access_map.size() / + (double)block.num_keys) * + 10000.0); + uint64_t percent_accesses_for_existing_keys = + (uint64_t)(((double)block.num_referenced_key_exist_in_block / + (double)block.num_accesses) * + 10000.0); + + HistogramStat hist_naccess_per_key; + for (auto const& key_access : block.key_num_access_map) { + for (auto const& caller_access : key_access.second) { + hist_naccess_per_key.Add(caller_access.second); + } + } + uint64_t avg_accesses = hist_naccess_per_key.Average(); + uint64_t stdev_accesses = hist_naccess_per_key.StandardDeviation(); + avg_naccesses_per_key_in_a_data_block.Add(avg_accesses); + cf_avg_naccesses_per_key_in_a_data_block[cf_name].Add(avg_accesses); + stdev_naccesses_per_key_in_a_data_block.Add(stdev_accesses); + cf_stdev_naccesses_per_key_in_a_data_block[cf_name].Add(stdev_accesses); + + existing_keys_stats.Add(percent_referenced_for_existing_keys); + cf_existing_keys_stats_map[cf_name].Add( + percent_referenced_for_existing_keys); + non_existing_keys_stats.Add(percent_referenced_for_non_existing_keys); + cf_non_existing_keys_stats_map[cf_name].Add( + percent_referenced_for_non_existing_keys); + block_access_stats.Add(percent_accesses_for_existing_keys); + cf_block_access_info[cf_name].Add(percent_accesses_for_existing_keys); + }; + TraverseBlocks(block_callback); fprintf(stdout, "Histogram on the number of referenced keys existing in a block over " "the total number of keys in a block: \n%s", @@ -1032,15 +1660,15 @@ std::vector parse_cache_config_file( return configs; } -std::set parse_buckets(const std::string& bucket_str) { - std::set buckets; +std::vector parse_buckets(const std::string& bucket_str) { + std::vector buckets; std::stringstream ss(bucket_str); while (ss.good()) { std::string bucket; getline(ss, bucket, ','); - buckets.insert(ParseUint64(bucket)); + buckets.push_back(ParseUint64(bucket)); } - buckets.insert(port::kMaxUint64); + buckets.push_back(port::kMaxUint64); return buckets; } @@ -1068,20 +1696,27 @@ int block_cache_trace_analyzer_tool(int argc, char** argv) { exit(1); } } - BlockCacheTraceAnalyzer analyzer(FLAGS_block_cache_trace_path, - FLAGS_block_cache_analysis_result_dir, - std::move(cache_simulator)); + BlockCacheTraceAnalyzer analyzer( + FLAGS_block_cache_trace_path, FLAGS_block_cache_analysis_result_dir, + !FLAGS_reuse_distance_labels.empty(), std::move(cache_simulator)); Status s = analyzer.Analyze(); if (!s.IsIncomplete()) { // Read all traces. fprintf(stderr, "Cannot process the trace %s\n", s.ToString().c_str()); exit(1); } + fprintf(stdout, "Status: %s\n", s.ToString().c_str()); analyzer.PrintStatsSummary(); if (FLAGS_print_access_count_stats) { print_break_lines(/*num_break_lines=*/3); - analyzer.PrintAccessCountStats(); + analyzer.PrintAccessCountStats( + /*user_access_only=*/false, FLAGS_analyze_bottom_k_access_count_blocks, + FLAGS_analyze_top_k_access_count_blocks); + print_break_lines(/*num_break_lines=*/3); + analyzer.PrintAccessCountStats( + /*user_access_only=*/true, FLAGS_analyze_bottom_k_access_count_blocks, + FLAGS_analyze_top_k_access_count_blocks); } if (FLAGS_print_block_size_stats) { print_break_lines(/*num_break_lines=*/3); @@ -1099,13 +1734,36 @@ int block_cache_trace_analyzer_tool(int argc, char** argv) { while (ss.good()) { std::string label; getline(ss, label, ','); - analyzer.WriteAccessTimeline(label); + if (label.find("block") != std::string::npos) { + analyzer.WriteAccessTimeline(label, kSecondInMinute, true); + analyzer.WriteAccessTimeline(label, kSecondInMinute, false); + analyzer.WriteAccessTimeline(label, kSecondInHour, true); + analyzer.WriteAccessTimeline(label, kSecondInHour, false); + } else { + analyzer.WriteAccessTimeline(label, kSecondInMinute, false); + } } } + if (!FLAGS_analyze_callers.empty()) { + analyzer.WritePercentAccessSummaryStats(); + std::stringstream ss(FLAGS_analyze_callers); + while (ss.good()) { + std::string caller; + getline(ss, caller, ','); + analyzer.WriteDetailedPercentAccessSummaryStats(string_to_caller(caller)); + } + } + + if (!FLAGS_access_count_buckets.empty()) { + std::vector buckets = parse_buckets(FLAGS_access_count_buckets); + analyzer.WriteAccessCountSummaryStats(buckets, /*user_access_only=*/true); + analyzer.WriteAccessCountSummaryStats(buckets, /*user_access_only=*/false); + } + if (!FLAGS_reuse_distance_labels.empty() && !FLAGS_reuse_distance_buckets.empty()) { - std::set buckets = parse_buckets(FLAGS_reuse_distance_buckets); + std::vector buckets = parse_buckets(FLAGS_reuse_distance_buckets); std::stringstream ss(FLAGS_reuse_distance_labels); while (ss.good()) { std::string label; @@ -1116,7 +1774,7 @@ int block_cache_trace_analyzer_tool(int argc, char** argv) { if (!FLAGS_reuse_interval_labels.empty() && !FLAGS_reuse_interval_buckets.empty()) { - std::set buckets = parse_buckets(FLAGS_reuse_interval_buckets); + std::vector buckets = parse_buckets(FLAGS_reuse_interval_buckets); std::stringstream ss(FLAGS_reuse_interval_labels); while (ss.good()) { std::string label; @@ -1124,6 +1782,43 @@ int block_cache_trace_analyzer_tool(int argc, char** argv) { analyzer.WriteReuseInterval(label, buckets); } } + + if (!FLAGS_reuse_lifetime_labels.empty() && + !FLAGS_reuse_lifetime_buckets.empty()) { + std::vector buckets = parse_buckets(FLAGS_reuse_lifetime_buckets); + std::stringstream ss(FLAGS_reuse_lifetime_labels); + while (ss.good()) { + std::string label; + getline(ss, label, ','); + analyzer.WriteReuseLifetime(label, buckets); + } + } + + if (FLAGS_analyze_blocks_reuse_k_reuse_window != 0) { + std::vector block_types{TraceType::kBlockTraceIndexBlock, + TraceType::kBlockTraceDataBlock, + TraceType::kBlockTraceFilterBlock}; + for (auto block_type : block_types) { + analyzer.WriteBlockReuseTimeline( + FLAGS_analyze_blocks_reuse_k_reuse_window, + /*user_access_only=*/true, block_type); + analyzer.WriteBlockReuseTimeline( + FLAGS_analyze_blocks_reuse_k_reuse_window, + /*user_access_only=*/false, block_type); + } + } + + if (!FLAGS_analyze_get_spatial_locality_labels.empty() && + !FLAGS_analyze_get_spatial_locality_buckets.empty()) { + std::vector buckets = + parse_buckets(FLAGS_analyze_get_spatial_locality_buckets); + std::stringstream ss(FLAGS_analyze_get_spatial_locality_labels); + while (ss.good()) { + std::string label; + getline(ss, label, ','); + analyzer.WriteGetSpatialLocality(label, buckets); + } + } return 0; } diff --git a/tools/block_cache_trace_analyzer.h b/tools/block_cache_trace_analyzer.h index 617b90280..feb7c21f2 100644 --- a/tools/block_cache_trace_analyzer.h +++ b/tools/block_cache_trace_analyzer.h @@ -9,13 +9,13 @@ #include #include +#include "db/dbformat.h" #include "rocksdb/env.h" #include "rocksdb/utilities/sim_cache.h" #include "trace_replay/block_cache_tracer.h" #include "utilities/simulator_cache/cache_simulator.h" namespace rocksdb { - // Statistics of a block. struct BlockAccessInfo { uint64_t num_accesses = 0; @@ -23,11 +23,12 @@ struct BlockAccessInfo { uint64_t first_access_time = 0; uint64_t last_access_time = 0; uint64_t num_keys = 0; - std::map + std::map> key_num_access_map; // for keys exist in this block. - std::map + std::map> non_exist_key_num_access_map; // for keys do not exist in this block. uint64_t num_referenced_key_exist_in_block = 0; + uint64_t referenced_data_size = 0; std::map caller_num_access_map; // caller:timestamp:number_of_accesses. The granularity of the timestamp is // seconds. @@ -39,6 +40,12 @@ struct BlockAccessInfo { std::map reuse_distance_count; void AddAccess(const BlockCacheTraceRecord& access) { + if (block_size != 0 && access.block_size != 0) { + assert(block_size == access.block_size); + } + if (num_keys != 0 && access.num_keys_in_block != 0) { + assert(num_keys == access.num_keys_in_block); + } if (first_access_time == 0) { first_access_time = access.access_timestamp; } @@ -54,10 +61,18 @@ struct BlockAccessInfo { access.caller)) { num_keys = access.num_keys_in_block; if (access.referenced_key_exist_in_block == Boolean::kTrue) { - key_num_access_map[access.referenced_key]++; + if (key_num_access_map.find(access.referenced_key) == + key_num_access_map.end()) { + referenced_data_size += access.referenced_data_size; + } + key_num_access_map[access.referenced_key][access.caller]++; num_referenced_key_exist_in_block++; + if (referenced_data_size > block_size && block_size != 0) { + ParsedInternalKey internal_key; + ParseInternalKey(access.referenced_key, &internal_key); + } } else { - non_exist_key_num_access_map[access.referenced_key]++; + non_exist_key_num_access_map[access.referenced_key][access.caller]++; } } } @@ -83,6 +98,7 @@ class BlockCacheTraceAnalyzer { public: BlockCacheTraceAnalyzer( const std::string& trace_file_path, const std::string& output_dir, + bool compute_reuse_distance, std::unique_ptr&& cache_simulator); ~BlockCacheTraceAnalyzer() = default; // No copy and move. @@ -122,7 +138,8 @@ class BlockCacheTraceAnalyzer { // Print access count distribution and the distribution break down by block // type and column family. - void PrintAccessCountStats() const; + void PrintAccessCountStats(bool user_access_only, uint32_t bottom_k, + uint32_t top_k) const; // Print data block accesses by user Get and Multi-Get. // It prints out 1) A histogram on the percentage of keys accessed in a data @@ -131,24 +148,93 @@ class BlockCacheTraceAnalyzer { // accesses on keys exist in a data block and its break down by column family. void PrintDataBlockAccessStats() const; + // Write the percentage of accesses break down by column family into a csv + // file saved in 'output_dir'. + // + // The file is named "percentage_of_accesses_summary". The file format is + // caller,cf_0,cf_1,...,cf_n where the cf_i is the column family name found in + // the trace. + void WritePercentAccessSummaryStats() const; + + // Write the percentage of accesses for the given caller break down by column + // family, level, and block type into a csv file saved in 'output_dir'. + // + // It generates two files: 1) caller_level_percentage_of_accesses_summary and + // 2) caller_bt_percentage_of_accesses_summary which break down by the level + // and block type, respectively. The file format is + // level/bt,cf_0,cf_1,...,cf_n where cf_i is the column family name found in + // the trace. + void WriteDetailedPercentAccessSummaryStats(TableReaderCaller caller) const; + + // Write the access count summary into a csv file saved in 'output_dir'. + // It groups blocks by their access count. + // + // It generates two files: 1) cf_access_count_summary and 2) + // bt_access_count_summary which break down the access count by column family + // and block type, respectively. The file format is + // cf/bt,bucket_0,bucket_1,...,bucket_N. + void WriteAccessCountSummaryStats( + const std::vector& access_count_buckets, + bool user_access_only) const; + // Write miss ratio curves of simulated cache configurations into a csv file - // saved in 'output_dir'. + // named "mrc" saved in 'output_dir'. + // + // The file format is + // "cache_name,num_shard_bits,capacity,miss_ratio,total_accesses". void WriteMissRatioCurves() const; // Write the access timeline into a csv file saved in 'output_dir'. - void WriteAccessTimeline(const std::string& label) const; + // + // The file is named "label_access_timeline".The file format is + // "time,label_1_access_per_second,label_2_access_per_second,...,label_N_access_per_second" + // where N is the number of unique labels found in the trace. + void WriteAccessTimeline(const std::string& label, uint64_t time_unit, + bool user_access_only) const; // Write the reuse distance into a csv file saved in 'output_dir'. Reuse // distance is defined as the cumulated size of unique blocks read between two // consective accesses on the same block. + // + // The file is named "label_reuse_distance". The file format is + // bucket,label_1,label_2,...,label_N. void WriteReuseDistance(const std::string& label_str, - const std::set& distance_buckets) const; + const std::vector& distance_buckets) const; // Write the reuse interval into a csv file saved in 'output_dir'. Reuse // interval is defined as the time between two consecutive accesses on the - // same block.. + // same block. + // + // The file is named "label_reuse_interval". The file format is + // bucket,label_1,label_2,...,label_N. void WriteReuseInterval(const std::string& label_str, - const std::set& time_buckets) const; + const std::vector& time_buckets) const; + + // Write the reuse lifetime into a csv file saved in 'output_dir'. Reuse + // lifetime is defined as the time interval between the first access of a + // block and its last access. + // + // The file is named "label_reuse_lifetime". The file format is + // bucket,label_1,label_2,...,label_N. + void WriteReuseLifetime(const std::string& label_str, + const std::vector& time_buckets) const; + + // Write the reuse timeline into a csv file saved in 'output_dir'. + // + // The file is named + // "block_type_user_access_only_reuse_window_reuse_timeline". The file format + // is start_time,0,1,...,N where N equals trace_duration / reuse_window. + void WriteBlockReuseTimeline(uint64_t reuse_window, bool user_access_only, + TraceType block_type) const; + + // Write the Get spatical locality into csv files saved in 'output_dir'. + // + // It generates three csv files. label_percent_ref_keys, + // label_percent_accesses_on_ref_keys, and + // label_percent_data_size_on_ref_keys. + void WriteGetSpatialLocality( + const std::string& label_str, + const std::vector& percent_buckets) const; const std::map& TEST_cf_aggregates_map() const { @@ -161,28 +247,48 @@ class BlockCacheTraceAnalyzer { std::string BuildLabel(const std::set& labels, const std::string& cf_name, uint64_t fd, uint32_t level, TraceType type, - TableReaderCaller caller, - const std::string& block_key) const; + TableReaderCaller caller, uint64_t block_key) const; void ComputeReuseDistance(BlockAccessInfo* info) const; void RecordAccess(const BlockCacheTraceRecord& access); void UpdateReuseIntervalStats( - const std::string& label, const std::set& time_buckets, + const std::string& label, const std::vector& time_buckets, const std::map timeline, std::map>* label_time_num_reuses, uint64_t* total_num_reuses) const; + std::string OutputPercentAccessStats( + uint64_t total_accesses, + const std::map& cf_access_count) const; + + void WriteStatsToFile( + const std::string& label_str, const std::vector& time_buckets, + const std::string& filename_suffix, + const std::map>& label_data, + uint64_t ntotal) const; + + void TraverseBlocks( + std::function + block_callback) const; + rocksdb::Env* env_; const std::string trace_file_path_; const std::string output_dir_; + const bool compute_reuse_distance_; BlockCacheTraceHeader header_; std::unique_ptr cache_simulator_; std::map cf_aggregates_map_; std::map block_info_map_; + uint64_t trace_start_timestamp_in_seconds_ = 0; + uint64_t trace_end_timestamp_in_seconds_ = 0; }; int block_cache_trace_analyzer_tool(int argc, char** argv); diff --git a/tools/block_cache_trace_analyzer_test.cc b/tools/block_cache_trace_analyzer_test.cc index efb202cb4..45ef99eee 100644 --- a/tools/block_cache_trace_analyzer_test.cc +++ b/tools/block_cache_trace_analyzer_test.cc @@ -56,6 +56,12 @@ class BlockCacheTracerTest : public testing::Test { reuse_distance_buckets_ = "1,1K,1M,1G"; reuse_interval_labels_ = "block,all,cf,sst,level,bt,cf_sst,cf_level,cf_bt"; reuse_interval_buckets_ = "1,10,100,1000"; + reuse_lifetime_labels_ = "block,all,cf,sst,level,bt,cf_sst,cf_level,cf_bt"; + reuse_lifetime_buckets_ = "1,10,100,1000"; + analyzing_callers_ = "Get,Iterator"; + access_count_buckets_ = "2,3,4,5,10"; + analyze_get_spatial_locality_labels_ = "all"; + analyze_get_spatial_locality_buckets_ = "10,20,30,40,50,60,70,80,90,100"; } ~BlockCacheTracerTest() override { @@ -158,12 +164,22 @@ class BlockCacheTracerTest : public testing::Test { "-print_access_count_stats", "-print_data_block_access_count_stats", "-cache_sim_warmup_seconds=0", + "-analyze_bottom_k_access_count_blocks=5", + "-analyze_top_k_access_count_blocks=5", + "-analyze_blocks_reuse_k_reuse_window=5", "-timeline_labels=" + timeline_labels_, "-reuse_distance_labels=" + reuse_distance_labels_, "-reuse_distance_buckets=" + reuse_distance_buckets_, "-reuse_interval_labels=" + reuse_interval_labels_, "-reuse_interval_buckets=" + reuse_interval_buckets_, - }; + "-reuse_lifetime_labels=" + reuse_lifetime_labels_, + "-reuse_lifetime_buckets=" + reuse_lifetime_buckets_, + "-analyze_callers=" + analyzing_callers_, + "-access_count_buckets=" + access_count_buckets_, + "-analyze_get_spatial_locality_labels=" + + analyze_get_spatial_locality_labels_, + "-analyze_get_spatial_locality_buckets=" + + analyze_get_spatial_locality_buckets_}; char arg_buffer[kArgBufferSize]; char* argv[kMaxArgCount]; int argc = 0; @@ -189,6 +205,12 @@ class BlockCacheTracerTest : public testing::Test { std::string reuse_distance_buckets_; std::string reuse_interval_labels_; std::string reuse_interval_buckets_; + std::string reuse_lifetime_labels_; + std::string reuse_lifetime_buckets_; + std::string analyzing_callers_; + std::string access_count_buckets_; + std::string analyze_get_spatial_locality_labels_; + std::string analyze_get_spatial_locality_buckets_; }; TEST_F(BlockCacheTracerTest, BlockCacheAnalyzer) { @@ -247,51 +269,65 @@ TEST_F(BlockCacheTracerTest, BlockCacheAnalyzer) { } { // Validate the timeline csv files. - const uint32_t expected_num_lines = 50; - std::stringstream ss(timeline_labels_); - while (ss.good()) { - std::string l; - ASSERT_TRUE(getline(ss, l, ',')); - const std::string timeline_file = - test_path_ + "/" + l + "_access_timeline"; - std::ifstream infile(timeline_file); - std::string line; - uint32_t nlines = 0; - ASSERT_TRUE(getline(infile, line)); - uint64_t expected_time = 1; - while (getline(infile, line)) { - std::stringstream ss_naccess(line); - uint32_t naccesses = 0; - std::string substr; - uint32_t time = 0; - while (ss_naccess.good()) { - ASSERT_TRUE(getline(ss_naccess, substr, ',')); - if (time == 0) { - time = ParseUint32(substr); - continue; + const std::vector time_units{"_60", "_3600"}; + const std::vector user_access_only_flags{"user_access_only_", + "all_access_"}; + for (auto const& user_access_only : user_access_only_flags) { + for (auto const& unit : time_units) { + std::stringstream ss(timeline_labels_); + while (ss.good()) { + std::string l; + ASSERT_TRUE(getline(ss, l, ',')); + if (l.find("block") == std::string::npos) { + if (unit != "_60" || user_access_only != "all_access_") { + continue; + } } - naccesses += ParseUint32(substr); + const std::string timeline_file = test_path_ + "/" + + user_access_only + l + unit + + "_access_timeline"; + std::ifstream infile(timeline_file); + std::string line; + const uint64_t expected_naccesses = 50; + const uint64_t expected_user_accesses = 30; + ASSERT_TRUE(getline(infile, line)) << timeline_file; + uint32_t naccesses = 0; + while (getline(infile, line)) { + std::stringstream ss_naccess(line); + std::string substr; + bool read_label = false; + while (ss_naccess.good()) { + ASSERT_TRUE(getline(ss_naccess, substr, ',')); + if (!read_label) { + read_label = true; + continue; + } + naccesses += ParseUint32(substr); + } + } + if (user_access_only == "user_access_only_") { + ASSERT_EQ(expected_user_accesses, naccesses) << timeline_file; + } else { + ASSERT_EQ(expected_naccesses, naccesses) << timeline_file; + } + ASSERT_OK(env_->DeleteFile(timeline_file)); } - nlines++; - ASSERT_EQ(1, naccesses); - ASSERT_EQ(expected_time, time); - expected_time += 1; } - ASSERT_EQ(expected_num_lines, nlines); - ASSERT_OK(env_->DeleteFile(timeline_file)); } } { // Validate the reuse_interval and reuse_distance csv files. std::map test_reuse_csv_files; - test_reuse_csv_files["_reuse_interval"] = reuse_interval_labels_; + test_reuse_csv_files["_access_reuse_interval"] = reuse_interval_labels_; test_reuse_csv_files["_reuse_distance"] = reuse_distance_labels_; + test_reuse_csv_files["_reuse_lifetime"] = reuse_lifetime_labels_; + test_reuse_csv_files["_avg_reuse_interval"] = reuse_interval_labels_; + test_reuse_csv_files["_avg_reuse_interval_naccesses"] = + reuse_interval_labels_; for (auto const& test : test_reuse_csv_files) { const std::string& file_suffix = test.first; const std::string& labels = test.second; - const uint32_t expected_num_rows = 10; - const uint32_t expected_num_rows_absolute_values = 5; - const uint32_t expected_reused_blocks = 0; + const uint32_t expected_num_rows = 5; std::stringstream ss(labels); while (ss.good()) { std::string l; @@ -300,7 +336,6 @@ TEST_F(BlockCacheTracerTest, BlockCacheAnalyzer) { std::ifstream infile(reuse_csv_file); std::string line; ASSERT_TRUE(getline(infile, line)); - uint32_t nblocks = 0; double npercentage = 0; uint32_t nrows = 0; while (getline(infile, line)) { @@ -314,20 +349,162 @@ TEST_F(BlockCacheTracerTest, BlockCacheAnalyzer) { label_read = true; continue; } - if (nrows < expected_num_rows_absolute_values) { - nblocks += ParseUint32(substr); - } else { - npercentage += ParseDouble(substr); - } + npercentage += ParseDouble(substr); } } ASSERT_EQ(expected_num_rows, nrows); - ASSERT_EQ(expected_reused_blocks, nblocks); - ASSERT_LT(npercentage, 0); + if ("_reuse_lifetime" == test.first || + "_avg_reuse_interval" == test.first || + "_avg_reuse_interval_naccesses" == test.first) { + ASSERT_EQ(100, npercentage) << reuse_csv_file; + } else { + ASSERT_LT(npercentage, 0); + } ASSERT_OK(env_->DeleteFile(reuse_csv_file)); } } } + + { + // Validate the percentage of accesses summary. + const std::string percent_access_summary_file = + test_path_ + "/percentage_of_accesses_summary"; + std::ifstream infile(percent_access_summary_file); + std::string line; + ASSERT_TRUE(getline(infile, line)); + std::set callers; + std::set expected_callers{"Get", "MultiGet", "Iterator", + "Prefetch", "Compaction"}; + while (getline(infile, line)) { + std::stringstream caller_percent(line); + std::string caller; + ASSERT_TRUE(getline(caller_percent, caller, ',')); + std::string percent; + ASSERT_TRUE(getline(caller_percent, percent, ',')); + ASSERT_FALSE(caller_percent.good()); + callers.insert(caller); + ASSERT_EQ(20, ParseDouble(percent)); + } + ASSERT_EQ(expected_callers.size(), callers.size()); + for (auto caller : callers) { + ASSERT_TRUE(expected_callers.find(caller) != expected_callers.end()); + } + ASSERT_OK(env_->DeleteFile(percent_access_summary_file)); + } + { + // Validate the percentage of accesses summary by analyzing callers. + std::stringstream analyzing_callers(analyzing_callers_); + while (analyzing_callers.good()) { + std::string caller; + ASSERT_TRUE(getline(analyzing_callers, caller, ',')); + std::vector breakdowns{"level", "bt"}; + for (auto breakdown : breakdowns) { + const std::string file_name = test_path_ + "/" + caller + "_" + + breakdown + + "_percentage_of_accesses_summary"; + std::ifstream infile(file_name); + std::string line; + ASSERT_TRUE(getline(infile, line)); + double sum = 0; + while (getline(infile, line)) { + std::stringstream label_percent(line); + std::string label; + ASSERT_TRUE(getline(label_percent, label, ',')); + std::string percent; + ASSERT_TRUE(getline(label_percent, percent, ',')); + ASSERT_FALSE(label_percent.good()); + sum += ParseDouble(percent); + } + ASSERT_EQ(100, sum); + ASSERT_OK(env_->DeleteFile(file_name)); + } + } + } + const std::vector access_types{"user_access_only", "all_access"}; + const std::vector prefix{"bt", "cf"}; + for (auto const& pre : prefix) { + for (auto const& access_type : access_types) { + { + // Validate the access count summary. + const std::string bt_access_count_summary = test_path_ + "/" + pre + + "_" + access_type + + "_access_count_summary"; + std::ifstream infile(bt_access_count_summary); + std::string line; + ASSERT_TRUE(getline(infile, line)); + double sum_percent = 0; + while (getline(infile, line)) { + std::stringstream bt_percent(line); + std::string bt; + ASSERT_TRUE(getline(bt_percent, bt, ',')); + std::string percent; + ASSERT_TRUE(getline(bt_percent, percent, ',')); + sum_percent += ParseDouble(percent); + } + ASSERT_EQ(100.0, sum_percent); + ASSERT_OK(env_->DeleteFile(bt_access_count_summary)); + } + } + } + for (auto const& access_type : access_types) { + std::vector block_types{"Index", "Data", "Filter"}; + for (auto block_type : block_types) { + // Validate reuse block timeline. + const std::string reuse_blocks_timeline = test_path_ + "/" + block_type + + "_" + access_type + + "_5_reuse_blocks_timeline"; + std::ifstream infile(reuse_blocks_timeline); + std::string line; + ASSERT_TRUE(getline(infile, line)) << reuse_blocks_timeline; + uint32_t index = 0; + while (getline(infile, line)) { + std::stringstream timeline(line); + bool start_time = false; + double sum = 0; + while (timeline.good()) { + std::string value; + ASSERT_TRUE(getline(timeline, value, ',')); + if (!start_time) { + start_time = true; + continue; + } + sum += ParseDouble(value); + } + index++; + ASSERT_LT(sum, 100.0 * index + 1) << reuse_blocks_timeline; + } + ASSERT_OK(env_->DeleteFile(reuse_blocks_timeline)); + } + } + + std::stringstream ss(analyze_get_spatial_locality_labels_); + while (ss.good()) { + std::string l; + ASSERT_TRUE(getline(ss, l, ',')); + const std::vector spatial_locality_files{ + "_percent_ref_keys", "_percent_accesses_on_ref_keys", + "_percent_data_size_on_ref_keys"}; + for (auto const& spatial_locality_file : spatial_locality_files) { + const std::string filename = test_path_ + "/" + l + spatial_locality_file; + std::ifstream infile(filename); + std::string line; + ASSERT_TRUE(getline(infile, line)); + double sum_percent = 0; + uint32_t nrows = 0; + while (getline(infile, line)) { + std::stringstream bt_percent(line); + std::string bt; + ASSERT_TRUE(getline(bt_percent, bt, ',')); + std::string percent; + ASSERT_TRUE(getline(bt_percent, percent, ',')); + sum_percent += ParseDouble(percent); + nrows++; + } + ASSERT_EQ(11, nrows); + ASSERT_EQ(100.0, sum_percent); + ASSERT_OK(env_->DeleteFile(filename)); + } + } ASSERT_OK(env_->DeleteFile(block_cache_sim_config_path_)); } @@ -366,6 +543,7 @@ TEST_F(BlockCacheTracerTest, MixedBlocks) { // Read blocks. BlockCacheTraceAnalyzer analyzer(trace_file_path_, /*output_miss_ratio_curve_path=*/"", + /*compute_reuse_distance=*/true, /*simulator=*/nullptr); // The analyzer ends when it detects an incomplete access record. ASSERT_EQ(Status::Incomplete(""), analyzer.Analyze()); diff --git a/trace_replay/block_cache_tracer.cc b/trace_replay/block_cache_tracer.cc index 62db94204..a74dc4d58 100644 --- a/trace_replay/block_cache_tracer.cc +++ b/trace_replay/block_cache_tracer.cc @@ -29,6 +29,8 @@ bool ShouldTrace(const Slice& block_key, const TraceOptions& trace_options) { } // namespace const uint64_t kMicrosInSecond = 1000 * 1000; +const uint64_t kSecondInMinute = 60; +const uint64_t kSecondInHour = 3600; const std::string BlockCacheTraceHelper::kUnknownColumnFamilyName = "UnknownColumnFamily"; const uint64_t BlockCacheTraceHelper::kReservedGetId = 0; diff --git a/trace_replay/block_cache_tracer.h b/trace_replay/block_cache_tracer.h index 66cbb5ade..3b26a18d6 100644 --- a/trace_replay/block_cache_tracer.h +++ b/trace_replay/block_cache_tracer.h @@ -17,6 +17,9 @@ namespace rocksdb { extern const uint64_t kMicrosInSecond; +extern const uint64_t kSecondInMinute; +extern const uint64_t kSecondInHour; + class BlockCacheTraceHelper { public: