From 99cdba0e79b6ff07da2263478bf4ace35a079eb0 Mon Sep 17 00:00:00 2001 From: haitaoyang Date: Fri, 12 Apr 2024 04:02:46 +0000 Subject: [PATCH] Add some logs and defend codes --- .../access/ob_index_tree_prefetcher.cpp | 27 +++++++++++-------- src/storage/access/ob_index_tree_prefetcher.h | 14 +++++----- src/storage/access/ob_multiple_get_merge.cpp | 2 +- src/storage/access/ob_multiple_merge.cpp | 2 +- .../access/ob_sstable_row_multi_getter.cpp | 2 +- src/storage/access/ob_sstable_row_scanner.cpp | 24 ++++++++--------- src/storage/access/ob_table_scan_iterator.cpp | 13 +++++---- .../index_block/ob_index_block_row_struct.h | 3 ++- 8 files changed, 49 insertions(+), 38 deletions(-) diff --git a/src/storage/access/ob_index_tree_prefetcher.cpp b/src/storage/access/ob_index_tree_prefetcher.cpp index 8ed667b957..eea3c30aca 100644 --- a/src/storage/access/ob_index_tree_prefetcher.cpp +++ b/src/storage/access/ob_index_tree_prefetcher.cpp @@ -47,13 +47,13 @@ void ObIndexTreePrefetcher::reclaim() void ObIndexTreePrefetcher::inner_reset() { - is_rescan_ = false; iter_type_ = 0; cur_level_ = 0; index_tree_height_ = 0; max_rescan_height_ = 0; max_rescan_range_cnt_ = 0; data_version_ = 0; + table_scan_cnt_ = 0; sstable_ = nullptr; sstable_meta_handle_.reset(); iter_param_ = nullptr; @@ -99,8 +99,6 @@ int ObIndexTreePrefetcher::switch_context( LOG_WARN("not inited", K(ret)); } else if (OB_FAIL(init_basic_info(iter_type, sstable, iter_param, access_ctx))) { LOG_WARN("Fail to init basic info", K(ret)); - } else { - is_rescan_ = true; } return ret; } @@ -118,6 +116,8 @@ int ObIndexTreePrefetcher::init_basic_info( } else if (OB_FAIL(iter_param.get_index_read_info(sstable.is_normal_cg_sstable(), index_read_info))) { LOG_WARN("failed to get index read info", KR(ret), K(sstable), K(iter_param)); } else { + table_scan_cnt_++; + const bool first_scan = is_first_scan(); iter_type_ = iter_type; cur_level_ = 0; sstable_ = &sstable; @@ -133,9 +133,9 @@ int ObIndexTreePrefetcher::init_basic_info( ret = OB_INVALID_ARGUMENT; LOG_WARN("Unexpected null long life allocator", K(ret)); } else if (index_scanner_.is_valid()) { - if (OB_ISNULL(iter_param_)) { - ret = OB_INVALID_ARGUMENT; - LOG_WARN("invalid iter param", K(ret), KPC(iter_param_), K(lbt())); + if (OB_UNLIKELY(first_scan)) { + ret = OB_ERR_UNEXPECTED; + LOG_WARN("Unexpected state, index_scanner_ is valid at first scan", K(ret), KPC(this), K(index_scanner_), K(iter_param), K(lbt())); } else { const ObTablet *cur_tablet = OB_ISNULL(iter_param_->tablet_handle_) ? nullptr : iter_param_->tablet_handle_->get_obj(); index_scanner_.switch_context(sstable, cur_tablet, *datum_utils_, *access_ctx_); @@ -390,7 +390,7 @@ int ObIndexTreePrefetcher::prefetch_block_data( const bool is_data) { int ret = OB_SUCCESS; - if (is_rescan_ && last_handle_hit(index_block_info, is_data, micro_handle)) { + if (is_rescan() && last_handle_hit(index_block_info, is_data, micro_handle)) { ++access_ctx_->table_store_stat_.block_cache_hit_cnt_; LOG_DEBUG("last micro block handle hits", K(is_data), K(index_block_info), K(last_micro_block_handle_), K(micro_handle)); @@ -400,7 +400,7 @@ int ObIndexTreePrefetcher::prefetch_block_data( true, /* need submit io */ micro_handle))) { LOG_WARN("Fail to get micro block handle from handle mgr", K(ret)); - } else if (is_rescan_ && is_data && micro_handle.in_block_state()) { + } else if (is_rescan() && is_data && micro_handle.in_block_state()) { last_micro_block_handle_ = micro_handle; } return ret; @@ -517,7 +517,6 @@ int ObIndexTreeMultiPrefetcher::switch_context( } } if (OB_SUCC(ret)) { - is_rescan_ = true; row_states_.set_allocator(long_life_allocator_); level_handles_.set_allocator(long_life_allocator_); if (is_rowkey_sorted_ && OB_FAIL(init_for_sorted_multi_get())) { @@ -912,6 +911,7 @@ int ObIndexTreeMultiPassPrefetcher::i } } if (OB_SUCC(ret)) { + table_scan_cnt_++; is_inited_ = true; } } @@ -927,6 +927,7 @@ int ObIndexTreeMultiPassPrefetcher::s const void *query_range) { int ret = OB_SUCCESS; + const bool first_scan = is_first_scan(); if (IS_NOT_INIT) { ret = OB_NOT_INIT; LOG_WARN("not inited", K(ret)); @@ -938,10 +939,14 @@ int ObIndexTreeMultiPassPrefetcher::s } else if (OB_FAIL(init_basic_info(iter_type, sstable, iter_param, access_ctx, query_range))) { LOG_WARN("Fail to init basic info", K(ret), K(access_ctx)); } else { - is_rescan_ = true; + table_scan_cnt_++; for (int64_t level = 0; OB_SUCC(ret) && level < index_tree_height_; level++) { if (tree_handles_[level].index_scanner_.is_valid()) { - if (OB_ISNULL(iter_param_)) { + if (OB_UNLIKELY(first_scan)) { + ret = OB_ERR_UNEXPECTED; + LOG_WARN("Unexpected state, index_scanner_ is valid at first scan", K(ret), K(level), KPC(this), + K(tree_handles_[level].index_scanner_), KPC(iter_param_), K(lbt())); + } else if (OB_ISNULL(iter_param_)) { ret = OB_INVALID_ARGUMENT; LOG_WARN("invalid iter param", K(ret), KPC(iter_param_), K(lbt())); } else { diff --git a/src/storage/access/ob_index_tree_prefetcher.h b/src/storage/access/ob_index_tree_prefetcher.h index caff2fe7f8..4fb7b038f2 100644 --- a/src/storage/access/ob_index_tree_prefetcher.h +++ b/src/storage/access/ob_index_tree_prefetcher.h @@ -123,13 +123,13 @@ class ObIndexTreePrefetcher public: ObIndexTreePrefetcher() : is_inited_(false), - is_rescan_(false), iter_type_(0), cur_level_(0), index_tree_height_(0), max_rescan_height_(0), max_rescan_range_cnt_(0), data_version_(0), + table_scan_cnt_(0), sstable_(nullptr), sstable_meta_handle_(), index_block_(), @@ -162,8 +162,9 @@ public: int lookup_in_index_tree(ObSSTableReadHandle &read_handle, const bool force_prefetch); OB_INLINE bool is_valid() { return is_inited_; } ObMicroBlockDataHandle &get_last_data_handle() { return last_micro_block_handle_; } - VIRTUAL_TO_STRING_KV(K_(is_rescan), K_(iter_type), K_(cur_level), K_(index_tree_height), - K_(max_rescan_height), K_(max_rescan_range_cnt), K_(data_version), K_(index_scanner)); + VIRTUAL_TO_STRING_KV(K_(is_inited), K_(iter_type), K_(cur_level), K_(index_tree_height), + K_(max_rescan_height), K_(max_rescan_range_cnt), K_(data_version), K_(table_scan_cnt), K_(index_scanner), + KPC_(sstable), KPC_(iter_param), K_(last_micro_block_handle)); protected: void inner_reset(); int init_index_scanner(ObIndexBlockRowScanner &index_scanner); @@ -181,24 +182,25 @@ protected: ObSSTable &sstable, const ObTableIterParam &iter_param, ObTableAccessContext &access_ctx); + OB_INLINE bool is_first_scan() const { return nullptr == sstable_; } + OB_INLINE bool is_rescan() const { return 1 < table_scan_cnt_; } private: ObMicroBlockDataHandle &get_read_handle(const int64_t level) { return micro_handles_[level % DEFAULT_GET_MICRO_DATA_HANDLE_CNT]; } bool last_handle_hit(const ObMicroIndexInfo &block_info, const bool is_data, ObMicroBlockDataHandle µ_handle); - protected: static const int64_t MAX_RESCAN_HOLD_LIMIT = 64; static const int16_t MAX_INDEX_TREE_HEIGHT = 16; bool is_inited_; - bool is_rescan_; int16_t iter_type_; int16_t cur_level_; int16_t index_tree_height_; int16_t max_rescan_height_; int64_t max_rescan_range_cnt_; int64_t data_version_; + int64_t table_scan_cnt_; ObSSTable *sstable_; ObSSTableMetaHandle sstable_meta_handle_; ObMicroBlockData index_block_; @@ -348,7 +350,7 @@ public: { return ext_read_handles_[fetch_rowkey_idx_ % MAX_MULTIGET_MICRO_DATA_HANDLE_CNT]; } OB_INLINE ObMicroBlockDataHandle ¤t_micro_handle() { return *ext_read_handles_[fetch_rowkey_idx_ % MAX_MULTIGET_MICRO_DATA_HANDLE_CNT].micro_handle_; } - INHERIT_TO_STRING_KV("ObIndexTreePrefetcher", ObIndexTreePrefetcher, K_(index_tree_height), + INHERIT_TO_STRING_KV("ObIndexTreePrefetcher", ObIndexTreePrefetcher, K_(index_tree_height), K_(is_rowkey_sorted), K_(fetch_rowkey_idx), K_(prefetch_rowkey_idx), K_(prefetched_rowkey_cnt), K_(max_handle_prefetching_cnt)); bool is_rowkey_sorted_; int64_t fetch_rowkey_idx_; diff --git a/src/storage/access/ob_multiple_get_merge.cpp b/src/storage/access/ob_multiple_get_merge.cpp index 635d51a2ff..2b77bb1d8e 100644 --- a/src/storage/access/ob_multiple_get_merge.cpp +++ b/src/storage/access/ob_multiple_get_merge.cpp @@ -199,7 +199,7 @@ int ObMultipleGetMerge::inner_get_next_row(ObDatumRow &row) ret = OB_SUCCESS; } } else { - STORAGE_LOG(WARN, "Iterator get next row failed", K(i), K(ret)); + STORAGE_LOG(WARN, "Iterator get next row failed", K(i), K(ret), K(tables_)); } } else if (OB_ISNULL(tmp_row)) { ret = OB_ERR_UNEXPECTED; diff --git a/src/storage/access/ob_multiple_merge.cpp b/src/storage/access/ob_multiple_merge.cpp index 5277962fbe..92cc1e6870 100644 --- a/src/storage/access/ob_multiple_merge.cpp +++ b/src/storage/access/ob_multiple_merge.cpp @@ -583,7 +583,7 @@ int ObMultipleMerge::get_next_normal_rows(int64_t &count, int64_t capacity) scan_state_ = ScanState::BATCH; continue; } else if (OB_ITER_END != ret) { - LOG_WARN("Fail to inner get next row, ", K(ret), KP(this)); + LOG_WARN("Fail to inner get next row, ", K(ret), K(tables_), KP(this)); } } else if (need_read_lob_columns(unprojected_row_)) { if (OB_FAIL(handle_lob_before_fuse_row())) { diff --git a/src/storage/access/ob_sstable_row_multi_getter.cpp b/src/storage/access/ob_sstable_row_multi_getter.cpp index b31d889e4b..85f8d8f7be 100644 --- a/src/storage/access/ob_sstable_row_multi_getter.cpp +++ b/src/storage/access/ob_sstable_row_multi_getter.cpp @@ -166,7 +166,7 @@ int ObSSTableRowMultiGetter::fetch_row(ObSSTableReadHandle &read_handle, const b read_handle, store_row, macro_block_reader_))) { - LOG_WARN("Fail to get row", K(ret)); + LOG_WARN("Fail to get row", K(ret), K(prefetcher_)); } return ret; } diff --git a/src/storage/access/ob_sstable_row_scanner.cpp b/src/storage/access/ob_sstable_row_scanner.cpp index 27682ab106..2f134a3c6c 100644 --- a/src/storage/access/ob_sstable_row_scanner.cpp +++ b/src/storage/access/ob_sstable_row_scanner.cpp @@ -793,18 +793,18 @@ int ObSSTableRowScanner::prepare_micro_scanner_for_column_store(Ob } else { prefetcher_.cur_micro_data_fetch_idx_ = read_handle.micro_begin_idx_; cur_range_idx_ = read_handle.range_idx_; - } - blocksstable::ObMicroIndexInfo µ_info = co_prefetcher->current_micro_info(); - ObMicroBlockDataHandle µ_handle = co_prefetcher->current_micro_handle(); - ObMicroBlockData block_data; - if (OB_FAIL(micro_handle.get_micro_block_data(¯o_block_reader_, block_data))) { - LOG_WARN("Fail to get block data", K(ret), K(micro_handle)); - } else if (OB_FAIL(micro_scanner_->open( - micro_handle.macro_block_id_, - block_data, - micro_info.is_left_border(), - micro_info.is_right_border()))) { - LOG_WARN("Failed to open micro_scanner", K(ret), K(micro_info), K(micro_handle), KPC(this)); + blocksstable::ObMicroIndexInfo µ_info = co_prefetcher->current_micro_info(); + ObMicroBlockDataHandle µ_handle = co_prefetcher->current_micro_handle(); + ObMicroBlockData block_data; + if (OB_FAIL(micro_handle.get_micro_block_data(¯o_block_reader_, block_data))) { + LOG_WARN("Fail to get block data", K(ret), K(micro_handle)); + } else if (OB_FAIL(micro_scanner_->open( + micro_handle.macro_block_id_, + block_data, + micro_info.is_left_border(), + micro_info.is_right_border()))) { + LOG_WARN("Failed to open micro_scanner", K(ret), K(micro_info), K(micro_handle), KPC(this)); + } } } else { // micro_scanner_ is already prepared. diff --git a/src/storage/access/ob_table_scan_iterator.cpp b/src/storage/access/ob_table_scan_iterator.cpp index 1c6227bbc0..be090522d6 100644 --- a/src/storage/access/ob_table_scan_iterator.cpp +++ b/src/storage/access/ob_table_scan_iterator.cpp @@ -190,6 +190,9 @@ int ObTableScanIterator::prepare_cached_iter_node() void ObTableScanIterator::try_release_cached_iter_node(const ObQRIterType rescan_iter_type) { if (nullptr != cached_iter_node_ && current_iter_type_ != rescan_iter_type) { + STORAGE_LOG(INFO, "iter type is changed in rescan", KPC(cached_iter_node_), + K(current_iter_type_), K(rescan_iter_type), KP(cached_iter_), + KP(single_merge_), KP(get_merge_), KP(scan_merge_), KP(multi_scan_merge_)); main_table_param_.diable_use_global_iter_pool(); main_table_ctx_.reset_cached_iter_node(); MTL(ObGlobalIteratorPool*)->release(cached_iter_node_); @@ -280,7 +283,7 @@ int ObTableScanIterator::rescan(ObTableScanParam &scan_param) STORAGE_LOG(WARN, "Failed to get query iter type", K(ret)); } else if (FALSE_IT(try_release_cached_iter_node(rescan_iter_type))) { } else if (OB_FAIL(open_iter())) { - STORAGE_LOG(WARN, "fail to open iter", K(ret)); + STORAGE_LOG(WARN, "fail to open iter", K(ret), KPC(cached_iter_node_)); } else { STORAGE_LOG(DEBUG, "Success to rescan ObTableScanIterator", K(scan_param.key_ranges_)); } @@ -317,7 +320,7 @@ int ObTableScanIterator::init(ObTableScanParam &scan_param, const ObTabletHandle } else if (OB_FAIL(prepare_table_context())) { STORAGE_LOG(WARN, "Fail to prepare table ctx, ", K(ret)); } else if (OB_FAIL(open_iter())) { - STORAGE_LOG(WARN, "fail to open iter", K(ret), K(*this)); + STORAGE_LOG(WARN, "fail to open iter", K(ret), KPC(cached_iter_node_), K(*this)); } else { is_inited_ = true; } @@ -356,7 +359,7 @@ int ObTableScanIterator::switch_param(ObTableScanParam &scan_param, const ObTabl } else if (OB_FAIL(switch_param_for_iter())) { STORAGE_LOG(WARN, "Failed to switch param for iter", K(ret), K(*this)); } else if (OB_FAIL(open_iter())) { - STORAGE_LOG(WARN, "fail to open iter", K(ret), K(*this)); + STORAGE_LOG(WARN, "fail to open iter", K(ret), KPC(cached_iter_node_), K(*this)); } else { is_inited_ = true; } @@ -635,7 +638,7 @@ int ObTableScanIterator::get_next_row(blocksstable::ObDatumRow *&row) if (OB_ITER_END != ret) { STORAGE_LOG(WARN, "Fail to get next row, ", K(ret), KPC_(scan_param), K_(main_table_param), KP(single_merge_), KP(get_merge_), KP(scan_merge_), KP(multi_scan_merge_), - KP(skip_scan_merge_)); + KP(skip_scan_merge_), KPC(cached_iter_node_)); } } } @@ -669,7 +672,7 @@ int ObTableScanIterator::get_next_rows(int64_t &count, int64_t capacity) if (OB_ITER_END != ret) { STORAGE_LOG(WARN, "Fail to get next row, ", K(ret), K(*scan_param_), K_(main_table_param), KP(single_merge_), KP(get_merge_), KP(scan_merge_), KP(multi_scan_merge_), - KP(skip_scan_merge_)); + KP(skip_scan_merge_), KPC(cached_iter_node_)); } } } diff --git a/src/storage/blocksstable/index_block/ob_index_block_row_struct.h b/src/storage/blocksstable/index_block/ob_index_block_row_struct.h index 2b7b729fe1..3b07569474 100644 --- a/src/storage/blocksstable/index_block/ob_index_block_row_struct.h +++ b/src/storage/blocksstable/index_block/ob_index_block_row_struct.h @@ -530,7 +530,8 @@ public: } TO_STRING_KV(KP_(query_range), KPC_(row_header), KPC_(minor_meta_info), KPC_(endkey), KP_(agg_row_buf), K_(agg_buf_size), K_(flag), K_(range_idx), K_(parent_macro_id), - K_(nested_offset), K_(cs_row_range), K_(skipping_filter_results)); + K_(nested_offset), K_(rowkey_begin_idx), K_(rowkey_end_idx), K_(cs_row_range), + K_(skipping_filter_results)); public: const ObIndexBlockRowHeader *row_header_;