[Profile](scan) Add profile to detail the scan

apache · Dec 27, 2024 · 4d0bd4d · 4d0bd4d
1 parent fdff4a6
commit 4d0bd4d
Show file tree

Hide file tree

Showing 7 changed files with 53 additions and 6 deletions.
diff --git a/be/src/olap/olap_common.h b/be/src/olap/olap_common.h
@@ -278,6 +278,8 @@ struct OlapReaderStatistics {
     int64_t decompress_ns = 0;
     int64_t uncompressed_bytes_read = 0;
 
+    int64_t tablet_read_timer = 0;
+
     // total read bytes in memory
     int64_t bytes_read = 0;
 
@@ -365,6 +367,12 @@ struct OlapReaderStatistics {
     int64_t inverted_index_searcher_cache_hit = 0;
     int64_t inverted_index_searcher_cache_miss = 0;
 
+    int64_t rowset_reader_get_segment_iterators_timer_ns = 0;
+    int64_t rowset_reader_create_iterators_timer_ns = 0;
+    int64_t rowset_reader_init_iterators_timer_ns = 0;
+    int64_t rowset_reader_load_segments_timer_ns = 0;
+    int64_t segment_load_index_timer_ns = 0;
+
     int64_t output_index_result_column_timer = 0;
     // number of segment filtered by column stat when creating seg iterator
     int64_t filtered_segment_number = 0;

diff --git a/be/src/olap/rowset/beta_rowset_reader.cpp b/be/src/olap/rowset/beta_rowset_reader.cpp
@@ -77,7 +77,6 @@ bool BetaRowsetReader::update_profile(RuntimeProfile* profile) {
 Status BetaRowsetReader::get_segment_iterators(RowsetReaderContext* read_context,
                                                std::vector<RowwiseIteratorUPtr>* out_iters,
                                                bool use_cache) {
-    RETURN_IF_ERROR(_rowset->load());
     _read_context = read_context;
     // The segment iterator is created with its own statistics,
     // and the member variable '_stats'  is initialized by '_stats(&owned_stats)'.
@@ -92,6 +91,9 @@ Status BetaRowsetReader::get_segment_iterators(RowsetReaderContext* read_context
         _stats = _read_context->stats;
     }
 
+    SCOPED_RAW_TIMER(&_stats->rowset_reader_get_segment_iterators_timer_ns);
+    RETURN_IF_ERROR(_rowset->load());
+
     // convert RowsetReaderContext to StorageReadOptions
     _read_options.block_row_max = read_context->batch_size;
     _read_options.stats = _stats;
@@ -218,8 +220,11 @@ Status BetaRowsetReader::get_segment_iterators(RowsetReaderContext* read_context
 
     // load segments
     bool should_use_cache = use_cache || _read_context->reader_type == ReaderType::READER_QUERY;
-    RETURN_IF_ERROR(SegmentLoader::instance()->load_segments(_rowset, &_segment_cache_handle,
-                                                             should_use_cache));
+    {
+        SCOPED_RAW_TIMER(&_stats->rowset_reader_load_segments_timer_ns);
+        RETURN_IF_ERROR(SegmentLoader::instance()->load_segments(_rowset, &_segment_cache_handle,
+                                                                 should_use_cache));
+    }
 
     // create iterator for each segment
     auto& segments = _segment_cache_handle.get_segments();
@@ -229,6 +234,7 @@ Status BetaRowsetReader::get_segment_iterators(RowsetReaderContext* read_context
         seg_end = segments.size();
     }
 
+    SCOPED_RAW_TIMER(&_stats->rowset_reader_create_iterators_timer_ns);
     for (int i = seg_start; i < seg_end; i++) {
         auto& seg_ptr = segments[i];
         std::unique_ptr<RowwiseIterator> iter;
@@ -261,6 +267,7 @@ Status BetaRowsetReader::_init_iterator() {
     std::vector<RowwiseIteratorUPtr> iterators;
     RETURN_IF_ERROR(get_segment_iterators(_read_context, &iterators));
 
+    SCOPED_RAW_TIMER(&_stats->rowset_reader_init_iterators_timer_ns);
     if (_read_context->merged_rows == nullptr) {
         _read_context->merged_rows = &_merged_rows;
     }
@@ -296,8 +303,8 @@ Status BetaRowsetReader::_init_iterator() {
 }
 
 Status BetaRowsetReader::next_block(vectorized::Block* block) {
-    SCOPED_RAW_TIMER(&_stats->block_fetch_ns);
     RETURN_IF_ERROR(_init_iterator_once());
+    SCOPED_RAW_TIMER(&_stats->block_fetch_ns);
     if (_empty) {
         return Status::Error<END_OF_FILE>("BetaRowsetReader is empty");
     }
@@ -316,8 +323,8 @@ Status BetaRowsetReader::next_block(vectorized::Block* block) {
 }
 
 Status BetaRowsetReader::next_block_view(vectorized::BlockView* block_view) {
-    SCOPED_RAW_TIMER(&_stats->block_fetch_ns);
     RETURN_IF_ERROR(_init_iterator_once());
+    SCOPED_RAW_TIMER(&_stats->block_fetch_ns);
     do {
         auto s = _iterator->next_block_view(block_view);
         if (!s.ok()) {

diff --git a/be/src/olap/rowset/segment_v2/segment.cpp b/be/src/olap/rowset/segment_v2/segment.cpp
@@ -166,7 +166,10 @@ Status Segment::new_iterator(SchemaSPtr schema, const StorageReadOptions& read_o
         }
     }
 
-    RETURN_IF_ERROR(load_index());
+    {
+        SCOPED_RAW_TIMER(&read_options.stats->segment_load_index_timer_ns);
+        RETURN_IF_ERROR(load_index());
+    }
     if (read_options.delete_condition_predicates->num_of_column_predicate() == 0 &&
         read_options.push_down_agg_type_opt != TPushAggOp::NONE &&
         read_options.push_down_agg_type_opt != TPushAggOp::COUNT_ON_INDEX) {

diff --git a/be/src/vec/exec/scan/new_olap_scan_node.cpp b/be/src/vec/exec/scan/new_olap_scan_node.cpp
@@ -104,6 +104,7 @@ Status NewOlapScanNode::_init_profile() {
     _block_load_timer = ADD_TIMER(_segment_profile, "BlockLoadTime");
     _block_load_counter = ADD_COUNTER(_segment_profile, "BlocksLoad", TUnit::UNIT);
     _block_fetch_timer = ADD_TIMER(_scanner_profile, "BlockFetchTime");
+    _tablet_read_timer = ADD_TIMER(_scanner_profile, "TabletReadTime");
     _delete_bitmap_get_agg_timer = ADD_TIMER(_scanner_profile, "DeleteBitmapGetAggTime");
     _raw_rows_counter = ADD_COUNTER(_segment_profile, "RawRowsRead", TUnit::UNIT);
     _block_convert_timer = ADD_TIMER(_scanner_profile, "BlockConvertTime");
@@ -186,6 +187,16 @@ Status NewOlapScanNode::_init_profile() {
     _inverted_index_searcher_cache_miss_counter =
             ADD_COUNTER(_segment_profile, "InvertedIndexSearcherCacheMiss", TUnit::UNIT);
 
+    _rowset_reader_get_segment_iterators_timer =
+            ADD_TIMER(_scanner_profile, "RowsetReaderGetSegmentIteratorsTimer");
+    _rowset_reader_create_iterators_timer =
+            ADD_TIMER(_scanner_profile, "RowsetReaderCreateIteratorsTimer");
+    _rowset_reader_init_iterators_timer =
+            ADD_TIMER(_scanner_profile, "RowsetReaderInitIteratorsTimer");
+    _rowset_reader_load_segments_timer =
+            ADD_TIMER(_scanner_profile, "RowsetReaderLoadSegmentsTimer");
+    _segment_load_index_timer = ADD_TIMER(_scanner_profile, "SegmentLoadIndexTimer");
+
     _output_index_result_column_timer = ADD_TIMER(_segment_profile, "OutputIndexResultColumnTimer");
 
     _filtered_segment_counter = ADD_COUNTER(_segment_profile, "NumSegmentFiltered", TUnit::UNIT);

diff --git a/be/src/vec/exec/scan/new_olap_scan_node.h b/be/src/vec/exec/scan/new_olap_scan_node.h
@@ -142,6 +142,7 @@ class NewOlapScanNode : public VScanNode {
     RuntimeProfile::Counter* _output_col_timer = nullptr;
     std::map<int, PredicateFilterInfo> _filter_info;
 
+    RuntimeProfile::Counter* _tablet_read_timer = nullptr;
     RuntimeProfile::Counter* _stats_filtered_counter = nullptr;
     RuntimeProfile::Counter* _stats_rp_filtered_counter = nullptr;
     RuntimeProfile::Counter* _bf_filtered_counter = nullptr;
@@ -199,6 +200,12 @@ class NewOlapScanNode : public VScanNode {
     RuntimeProfile::Counter* _inverted_index_searcher_cache_hit_counter = nullptr;
     RuntimeProfile::Counter* _inverted_index_searcher_cache_miss_counter = nullptr;
 
+    RuntimeProfile::Counter* _rowset_reader_get_segment_iterators_timer = nullptr;
+    RuntimeProfile::Counter* _rowset_reader_create_iterators_timer = nullptr;
+    RuntimeProfile::Counter* _rowset_reader_init_iterators_timer = nullptr;
+    RuntimeProfile::Counter* _rowset_reader_load_segments_timer = nullptr;
+    RuntimeProfile::Counter* _segment_load_index_timer = nullptr;
+
     RuntimeProfile::Counter* _output_index_result_column_timer = nullptr;
 
     // number of created olap scanners

diff --git a/be/src/vec/exec/scan/new_olap_scanner.cpp b/be/src/vec/exec/scan/new_olap_scanner.cpp
@@ -518,6 +518,7 @@ void NewOlapScanner::_collect_profile_before_close() {
     COUNTER_UPDATE(olap_parent->_decompressor_timer, stats.decompress_ns);
     COUNTER_UPDATE(olap_parent->_read_uncompressed_counter, stats.uncompressed_bytes_read);
 
+    COUNTER_UPDATE(olap_parent->_tablet_read_timer, stats.tablet_read_timer);
     COUNTER_UPDATE(olap_parent->_block_load_timer, stats.block_load_ns);
     COUNTER_UPDATE(olap_parent->_block_load_counter, stats.blocks_load);
     COUNTER_UPDATE(olap_parent->_block_fetch_timer, stats.block_fetch_ns);
@@ -601,6 +602,15 @@ void NewOlapScanner::_collect_profile_before_close() {
     COUNTER_UPDATE(olap_parent->_inverted_index_searcher_cache_miss_counter,
                    stats.inverted_index_searcher_cache_miss);
 
+    COUNTER_UPDATE(olap_parent->_rowset_reader_get_segment_iterators_timer,
+                   stats.rowset_reader_get_segment_iterators_timer_ns);
+    COUNTER_UPDATE(olap_parent->_rowset_reader_create_iterators_timer,
+                   stats.rowset_reader_create_iterators_timer_ns);
+    COUNTER_UPDATE(olap_parent->_rowset_reader_init_iterators_timer,
+                   stats.rowset_reader_init_iterators_timer_ns);
+    COUNTER_UPDATE(olap_parent->_rowset_reader_load_segments_timer,
+                   stats.rowset_reader_load_segments_timer_ns);
+    COUNTER_UPDATE(olap_parent->_segment_load_index_timer, stats.segment_load_index_timer_ns);
     if (config::enable_file_cache) {
         io::FileCacheProfileReporter cache_profile(olap_parent->_segment_profile.get());
         cache_profile.update(&stats.file_cache_stats);

diff --git a/be/src/vec/olap/block_reader.h b/be/src/vec/olap/block_reader.h
@@ -48,6 +48,7 @@ class BlockReader final : public TabletReader {
     Status init(const ReaderParams& read_params) override;
 
     Status next_block_with_aggregation(Block* block, bool* eof) override {
+        SCOPED_RAW_TIMER(&_stats.tablet_read_timer);
         auto res = (this->*_next_block_func)(block, eof);
         if (UNLIKELY(!res.ok() && !res.is<ErrorCode::END_OF_FILE>())) {
             _tablet->report_error(res);