From ff95f2361507c136d6472dc5aa16360b72e3fa58 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=E6=9D=8E=E8=B6=85=E5=8B=87?= Date: Mon, 3 Dec 2018 10:08:21 +0800 Subject: [PATCH] Remove OLAP_LOG_DEBUG AND OLAP_LOG_TRACE log format (#378) Use VLOG(3) and VLOG(10) instead --- be/src/agent/pusher.cpp | 24 ++-- be/src/agent/task_worker_pool.cpp | 2 +- be/src/olap/base_compaction.cpp | 9 +- be/src/olap/bit_field_writer.cpp | 4 - be/src/olap/column_data.cpp | 6 +- be/src/olap/column_reader.cpp | 2 +- be/src/olap/column_reader.h | 1 - be/src/olap/cumulative_compaction.cpp | 8 +- be/src/olap/file_helper.cpp | 25 ++-- be/src/olap/file_helper.h | 15 +-- be/src/olap/file_stream.cpp | 6 +- be/src/olap/file_stream.h | 7 - be/src/olap/merger.cpp | 2 +- be/src/olap/olap_cond.cpp | 7 +- be/src/olap/olap_engine.cpp | 93 ++++++------- be/src/olap/olap_header.cpp | 24 ++-- be/src/olap/olap_index.cpp | 4 +- be/src/olap/olap_server.cpp | 2 +- be/src/olap/olap_snapshot.cpp | 23 ++-- be/src/olap/olap_table.cpp | 6 +- be/src/olap/olap_table.h | 8 +- be/src/olap/out_stream.cpp | 16 +-- be/src/olap/out_stream.h | 6 +- be/src/olap/push_handler.cpp | 38 +++--- be/src/olap/push_handler.h | 9 +- be/src/olap/reader.cpp | 36 +++-- be/src/olap/run_length_byte_writer.cpp | 4 - be/src/olap/run_length_integer_reader.cpp | 1 - be/src/olap/run_length_integer_writer.cpp | 2 +- be/src/olap/run_length_integer_writer.h | 2 +- be/src/olap/schema_change.cpp | 156 ++++++++++------------ be/src/olap/segment_group.cpp | 7 +- be/src/olap/segment_reader.cpp | 30 ++--- be/src/olap/segment_writer.cpp | 12 +- be/src/olap/stream_index_writer.cpp | 7 +- be/src/olap/utils.cpp | 36 +++-- be/src/olap/utils.h | 6 - 37 files changed, 286 insertions(+), 360 deletions(-) diff --git a/be/src/agent/pusher.cpp b/be/src/agent/pusher.cpp index e5790c8b26..fc79bfb6d0 100644 --- a/be/src/agent/pusher.cpp +++ b/be/src/agent/pusher.cpp @@ -52,7 +52,7 @@ AgentStatus Pusher::init() { AgentStatus status = DORIS_SUCCESS; if (_is_init) { - OLAP_LOG_DEBUG("has been inited"); + VLOG(3) << "has been inited"; return status; } @@ -195,10 +195,8 @@ AgentStatus Pusher::process(vector* tablet_infos) { time_t now = time(NULL); if (_push_req.timeout > 0) { - OLAP_LOG_DEBUG( - "check time out. time_out:%ld, now:%d", - _push_req.timeout, now); - + VLOG(3) << "check time out. time_out:" << _push_req.timeout + << ", now:" << now; if (_push_req.timeout < now) { OLAP_LOG_WARNING("push time out"); status = DORIS_PUSH_TIME_OUT; @@ -212,13 +210,10 @@ AgentStatus Pusher::process(vector* tablet_infos) { _downloader_param.curl_opt_timeout = timeout; } - OLAP_LOG_DEBUG( - "estimate_time_out: %d, download_timeout: %d, curl_opt_timeout: %d", - estimate_time_out, - _push_req.timeout, - _downloader_param.curl_opt_timeout); - OLAP_LOG_DEBUG("download file, retry time:%d", i); - + VLOG(3) << "estimate_time_out: " << estimate_time_out + << ", download_timeout: " << estimate_time_out + << ", curl_opt_timeout: " << _downloader_param.curl_opt_timeout + << ", download file, retry time:" << i; #ifndef BE_TEST _file_downloader = new FileDownloader(_downloader_param); _download_status = _download_file(); @@ -233,9 +228,8 @@ AgentStatus Pusher::process(vector* tablet_infos) { // Check file size boost::filesystem::path local_file_path(_downloader_param.local_file_path); uint64_t local_file_size = boost::filesystem::file_size(local_file_path); - OLAP_LOG_DEBUG( - "file_size: %d, local_file_size: %d", - file_size, local_file_size); + VLOG(3) << "file_size: " << file_size + << ", local_file_size: " << local_file_size; if (file_size != local_file_size) { OLAP_LOG_WARNING( diff --git a/be/src/agent/task_worker_pool.cpp b/be/src/agent/task_worker_pool.cpp index 8dadbd9f97..9cb9df17e6 100644 --- a/be/src/agent/task_worker_pool.cpp +++ b/be/src/agent/task_worker_pool.cpp @@ -813,7 +813,7 @@ void* TaskWorkerPool::_push_worker_thread_callback(void* arg_this) { } if (status == DORIS_SUCCESS) { - OLAP_LOG_DEBUG("push ok.signature: %ld", agent_task_req.signature); + VLOG(3) << "push ok.signature: " << agent_task_req.signature; error_msgs.push_back("push success"); ++_s_report_version; diff --git a/be/src/olap/base_compaction.cpp b/be/src/olap/base_compaction.cpp index 121b14b630..3128cb6faa 100644 --- a/be/src/olap/base_compaction.cpp +++ b/be/src/olap/base_compaction.cpp @@ -101,7 +101,7 @@ OLAPStatus BaseCompaction::run() { return res; } - OLAP_LOG_TRACE("new_base_version_hash", "%ld", new_base_version_hash); + VLOG(10) << "new_base_version_hash" << new_base_version_hash; // 2. 获取生成新base需要的data sources vector base_data_sources; @@ -377,9 +377,8 @@ OLAPStatus BaseCompaction::_do_base_compaction(VersionHash new_base_version_hash // 4. 如果merge成功，则将新base文件对应的olap index载入 _new_olap_indices.push_back(new_base); - OLAP_LOG_TRACE("merge new base success, start load index. [table='%s' version=%d]", - _table->full_name().c_str(), - _new_base_version.second); + VLOG(10) << "merge new base success, start load index. tablet=" << _table->full_name() + << ", version=" << _new_base_version.second; res = new_base->load(); if (res != OLAP_SUCCESS) { @@ -515,7 +514,7 @@ bool BaseCompaction::_validate_need_merged_versions( return false; } - OLAP_LOG_TRACE("valid need merged version"); + VLOG(10) << "valid need merged version"; return true; } diff --git a/be/src/olap/bit_field_writer.cpp b/be/src/olap/bit_field_writer.cpp index 00e1177449..81c098ebab 100644 --- a/be/src/olap/bit_field_writer.cpp +++ b/be/src/olap/bit_field_writer.cpp @@ -86,8 +86,6 @@ OLAPStatus BitFieldWriter::flush() { } void BitFieldWriter::get_position(PositionEntryWriter* index_entry) const { - // OLAP_LOG_DEBUG("begin recording position [BitFieldWriter], " - // "recorded position count: %d", index_entry->positions_size()); if (NULL != _byte_writer) { _byte_writer->get_position(index_entry); } else { @@ -99,8 +97,6 @@ void BitFieldWriter::get_position(PositionEntryWriter* index_entry) const { } index_entry->add_position(8 - _bits_left); - // OLAP_LOG_DEBUG("end recording position [BitFieldWriter], " - // "recorded position count: %d", index_entry->positions_size()); } } // namespace doris diff --git a/be/src/olap/column_data.cpp b/be/src/olap/column_data.cpp index 354dd97705..5d6f146c1b 100644 --- a/be/src/olap/column_data.cpp +++ b/be/src/olap/column_data.cpp @@ -162,7 +162,7 @@ OLAPStatus ColumnData::_seek_to_block(const RowBlockPosition& block_pos, bool wi end_block = _segment_reader->block_count() - 1; } - OLAP_LOG_DEBUG("###---### seek from %u to %u", block_pos.data_offset, end_block); + VLOG(3) << "seek from " << block_pos.data_offset << " to " << end_block; return _segment_reader->seek_to_block( block_pos.data_offset, end_block, without_filter, &_next_block, &_segment_eof); } @@ -250,8 +250,8 @@ OLAPStatus ColumnData::_find_position_by_full_key( } else { it_result = std::upper_bound(it_start, it_end, key, comparator); } - OLAP_LOG_DEBUG("get result iterator. [offset=%u start_pos='%s']", - *it_result, start_position.to_string().c_str()); + VLOG(3) << "get result iterator. offset=" << *it_result + << ", start_pos=" << start_position.to_string(); } catch (std::exception& e) { LOG(FATAL) << "exception happens when doing seek. exception=" << e.what(); return OLAP_ERR_STL_ERROR; diff --git a/be/src/olap/column_reader.cpp b/be/src/olap/column_reader.cpp index 875a623589..d5dd60708d 100644 --- a/be/src/olap/column_reader.cpp +++ b/be/src/olap/column_reader.cpp @@ -828,7 +828,7 @@ OLAPStatus ColumnReader::init( _present_reader = NULL; _value_present = false; } else { - OLAP_LOG_DEBUG("create null present_stream for column_id: %d", _column_unique_id); + VLOG(3) << "create null present_stream for column_id:" << _column_unique_id; _present_reader = new(std::nothrow) BitFieldReader(present_stream); if (NULL == _present_reader) { diff --git a/be/src/olap/column_reader.h b/be/src/olap/column_reader.h index 1ffe2e62b5..3deb8900f8 100644 --- a/be/src/olap/column_reader.h +++ b/be/src/olap/column_reader.h @@ -42,7 +42,6 @@ class ColumnEncodingMessage; inline ReadOnlyFileStream* extract_stream(uint32_t column_unique_id, StreamInfoMessage::Kind kind, std::map* streams) { - //OLAP_LOG_DEBUG("try to get stream: id=%u, kind=%d", column_unique_id, kind); StreamName stream_name(column_unique_id, kind); std::map::iterator it = streams->find(stream_name); diff --git a/be/src/olap/cumulative_compaction.cpp b/be/src/olap/cumulative_compaction.cpp index 34f954f8a4..ba43b87d32 100755 --- a/be/src/olap/cumulative_compaction.cpp +++ b/be/src/olap/cumulative_compaction.cpp @@ -171,8 +171,8 @@ OLAPStatus CumulativeCompaction::run() { _table->release_cumulative_lock(); - OLAP_LOG_TRACE("elapsed time of doing cumulative compaction. [time=%ldus]", - watch.get_elapse_time_us()); + VLOG(10) << "elapsed time of doing cumulative compaction. " + << "time=" << watch.get_elapse_time_us(); return res; } @@ -308,8 +308,8 @@ OLAPStatus CumulativeCompaction::_get_delta_versions(Versions* delta_versions) { // 因为我们总是保留最新的delta不合并到cumulative文件里，所以此时应该返回错误，不进行cumulative if (delta_versions->size() == 1) { delta_versions->clear(); - OLAP_LOG_TRACE("only one delta version. no new delta versions.[cumulative_point=%d]", - _old_cumulative_layer_point); + VLOG(10) << "only one delta version. no new delta versions. " + << ", cumulative_point=" << _old_cumulative_layer_point; return OLAP_ERR_CUMULATIVE_NO_SUITABLE_VERSIONS; } diff --git a/be/src/olap/file_helper.cpp b/be/src/olap/file_helper.cpp index 8d536043d5..da7dc4d6cc 100644 --- a/be/src/olap/file_helper.cpp +++ b/be/src/olap/file_helper.cpp @@ -69,8 +69,8 @@ OLAPStatus FileHandler::open(const string& file_name, int flag) { return OLAP_ERR_IO_ERROR; } - VLOG(3) << "success to open file. [file_name='" - << file_name << "' flag=" << flag << " fd=" << _fd << "]"; + VLOG(3) << "success to open file. file_name=" << file_name + << ", mode=" << flag << " fd=" << _fd; _is_using_cache = false; _file_name = file_name; return OLAP_SUCCESS; @@ -92,8 +92,8 @@ OLAPStatus FileHandler::open_with_cache(const string& file_name, int flag) { FileDescriptor* file_desc = reinterpret_cast(fd_cache->value(_cache_handle)); _fd = file_desc->fd; - VLOG(3) << "success to open file with cache. [file_name='" << file_name - << "' flag=" << flag << " fd=" << _fd << "]"; + VLOG(3) << "success to open file with cache. file_name=" << file_name + << ", mode=" << flag << " fd=" << _fd; } else { _fd = ::open(file_name.c_str(), flag); if (_fd < 0) { @@ -109,8 +109,9 @@ OLAPStatus FileHandler::open_with_cache(const string& file_name, int flag) { _cache_handle = fd_cache->insert( key, file_desc, 1, &_delete_cache_file_descriptor); - OLAP_LOG_DEBUG("success to open file with cache. [file_name='%s' flag=%d fd=%d]", - file_name.c_str(), flag, _fd); + VLOG(3) << "success to open file with cache. " + << "file_name=" << file_name + << ", mode=" << flag << ", fd=" << _fd; } _is_using_cache = true; _file_name = file_name; @@ -140,8 +141,8 @@ OLAPStatus FileHandler::open_with_mode(const string& file_name, int flag, int mo return OLAP_ERR_IO_ERROR; } - OLAP_LOG_DEBUG("success to open file. [file_name='%s' flag=%d mode=%d fd=%d]", - file_name.c_str(), flag, mode, _fd); + VLOG(3) << "success to open file. file_name=" << file_name + << ", mode=" << mode << ", fd=" << _fd; _file_name = file_name; return OLAP_SUCCESS; } @@ -178,8 +179,8 @@ OLAPStatus FileHandler::close() { } } - OLAP_LOG_DEBUG("finished to close file. [file_name='%s' fd=%d]", - _file_name.c_str(), _fd); + VLOG(3) << "finished to close file. " + << "file_name=" << _file_name << ", fd=" << _fd; _fd = -1; _file_name = ""; _wr_length = 0; @@ -320,8 +321,8 @@ OLAPStatus FileHandlerWithBuf::open(const string& file_name, const char* mode) { return OLAP_ERR_IO_ERROR; } - OLAP_LOG_DEBUG("success to open file. [file_name='%s' flag='%s']", - file_name.c_str(), mode); + VLOG(3) << "success to open file. " + << "file_name=" << file_name << ", mode=" << mode; _file_name = file_name; return OLAP_SUCCESS; } diff --git a/be/src/olap/file_helper.h b/be/src/olap/file_helper.h index 2f4279c09a..2a47306cf7 100644 --- a/be/src/olap/file_helper.h +++ b/be/src/olap/file_helper.h @@ -358,9 +358,7 @@ OLAPStatus FileHeader::unserialize( } if (_fixed_file_header.magic_number != OLAP_FIX_HEADER_MAGIC_NUMBER) { - OLAP_LOG_TRACE("old fix header found, magic num = [%lu]", - _fixed_file_header.magic_number); - + VLOG(10) << "old fix header found, magic num=" << _fixed_file_header.magic_number; FixedFileHeader tmp_header; if (OLAP_SUCCESS != file_handler->pread(&tmp_header, @@ -382,12 +380,11 @@ OLAPStatus FileHeader::unserialize( _fixed_file_header_size = sizeof(tmp_header); } - OLAP_LOG_DEBUG("fix head loaded. [file_length = %lu, checksum = %d, " - "protobuf_length = %lu, proto_checksum = %u, " - "magic_number = %lu, version = %d", - _fixed_file_header.file_length, _fixed_file_header.checksum, - _fixed_file_header.protobuf_length, _fixed_file_header.protobuf_checksum, - _fixed_file_header.magic_number, _fixed_file_header.version); + VLOG(3) << "fix head loaded. file_length=" << _fixed_file_header.file_length + << ", checksum=" << _fixed_file_header.checksum + << ", protobuf_length=" << _fixed_file_header.protobuf_length + << ", magic_number=" << _fixed_file_header.magic_number + << ", version=" << _fixed_file_header.version; if (OLAP_SUCCESS != file_handler->pread(&_extra_fixed_header, sizeof(_extra_fixed_header), _fixed_file_header_size)) { diff --git a/be/src/olap/file_stream.cpp b/be/src/olap/file_stream.cpp index 3af2ad7e56..85ec2a3eb6 100755 --- a/be/src/olap/file_stream.cpp +++ b/be/src/olap/file_stream.cpp @@ -61,8 +61,8 @@ OLAPStatus ReadOnlyFileStream::_assure_data() { if (OLAP_LIKELY(_uncompressed != NULL && _uncompressed->remaining() > 0)) { return OLAP_SUCCESS; } else if (_file_cursor.eof()) { - OLAP_LOG_DEBUG("STREAM EOF.[length=%lu used=%lu]", - _file_cursor.length(), _file_cursor.position()); + VLOG(3) << "STREAM EOF. length=" << _file_cursor.length() + << ", used=" << _file_cursor.position(); return OLAP_ERR_COLUMN_STREAM_EOF; } @@ -130,7 +130,7 @@ OLAPStatus ReadOnlyFileStream::seek(PositionProvider* position) { if (OLAP_LIKELY(OLAP_SUCCESS == res)) { // assure data will be successful in most case } else if (res == OLAP_ERR_COLUMN_STREAM_EOF) { - OLAP_LOG_DEBUG("file stream eof."); + VLOG(3) << "file stream eof."; return res; } else { OLAP_LOG_WARNING("fail to assure data after seek"); diff --git a/be/src/olap/file_stream.h b/be/src/olap/file_stream.h index aeb1c78c1a..8ffffe05ec 100755 --- a/be/src/olap/file_stream.h +++ b/be/src/olap/file_stream.h @@ -174,13 +174,6 @@ private: OLAPStatus res = _file_handler->pread(out_buffer, length, _used + _offset); - - // OLAP_LOG_DEBUG("FILE read from %lu to %lu [%lu - %lu], length %lu", - // _used + _offset, - // _used + _offset + length, - // _offset, - // _offset + _length, - // length); if (OLAP_SUCCESS != res) { OLAP_LOG_WARNING("fail to read from file. [res=%d]", res); return res; diff --git a/be/src/olap/merger.cpp b/be/src/olap/merger.cpp index e190738e7a..3a84b0b844 100644 --- a/be/src/olap/merger.cpp +++ b/be/src/olap/merger.cpp @@ -93,7 +93,7 @@ OLAPStatus Merger::merge(const vector& olap_data_arr, // Read one row into row_cursor OLAPStatus res = reader.next_row_with_aggregation(&row_cursor, &eof); if (OLAP_SUCCESS == res && eof) { - OLAP_LOG_DEBUG("reader read to the end."); + VLOG(3) << "reader read to the end."; break; } else if (OLAP_SUCCESS != res) { OLAP_LOG_WARNING("reader read failed."); diff --git a/be/src/olap/olap_cond.cpp b/be/src/olap/olap_cond.cpp index e107b9eff6..b11e4c1c94 100644 --- a/be/src/olap/olap_cond.cpp +++ b/be/src/olap/olap_cond.cpp @@ -593,10 +593,9 @@ bool Conditions::delete_conditions_eval(const RowCursor& row) const { } } - OLAP_LOG_DEBUG("Row meets the delete conditions. [condition_count=%zu; row=%s]", - _columns.size(), - row.to_string().c_str()); - + VLOG(3) << "Row meets the delete conditions. " + << "condition_count=" << _columns.size() + << ", row=" << row.to_string(); return true; } diff --git a/be/src/olap/olap_engine.cpp b/be/src/olap/olap_engine.cpp index dd0d050cea..b10e5d06ac 100644 --- a/be/src/olap/olap_engine.cpp +++ b/be/src/olap/olap_engine.cpp @@ -260,9 +260,8 @@ OLAPStatus OLAPEngine::load_one_tablet( // load pending data (for realtime push), will add transaction relationship into engine olap_table->load_pending_data(); - OLAP_LOG_DEBUG("succeed to add table. [table=%s, path=%s]", - olap_table->full_name().c_str(), - schema_hash_path.c_str()); + VLOG(3) << "succeed to add table. tablet=" << olap_table->full_name() + << ", path=" << schema_hash_path; return OLAP_SUCCESS; } @@ -755,19 +754,18 @@ OLAPStatus OLAPEngine::clear() { } OLAPTablePtr OLAPEngine::_get_table_with_no_lock(TTabletId tablet_id, SchemaHash schema_hash) { - OLAP_LOG_DEBUG("begin to get olap table. [table=%ld]", tablet_id); - + VLOG(3) << "begin to get olap table. tablet_id=" << tablet_id; tablet_map_t::iterator it = _tablet_map.find(tablet_id); if (it != _tablet_map.end()) { for (OLAPTablePtr table : it->second.table_arr) { if (table->equal(tablet_id, schema_hash)) { - OLAP_LOG_DEBUG("get olap table success. [table=%ld]", tablet_id); + VLOG(3) << "get olap table success. tablet_id=" << tablet_id; return table; } } } - OLAP_LOG_DEBUG("fail to get olap table. [table=%ld]", tablet_id); + VLOG(3) << "fail to get olap table. tablet_id=" << tablet_id; // Return empty olap_table if fail OLAPTablePtr olap_table; return olap_table; @@ -798,7 +796,7 @@ OLAPStatus OLAPEngine::get_tables_by_id( TTabletId tablet_id, list* table_list) { OLAPStatus res = OLAP_SUCCESS; - OLAP_LOG_DEBUG("begin to get tables by id. [table=%ld]", tablet_id); + VLOG(3) << "begin to get tables by id. tablet_id=" << tablet_id; _tablet_map_lock.rdlock(); tablet_map_t::iterator it = _tablet_map.find(tablet_id); @@ -827,7 +825,7 @@ OLAPStatus OLAPEngine::get_tables_by_id( ++it; } - OLAP_LOG_DEBUG("success to get tables by id. [table_num=%u]", table_list->size()); + VLOG(3) << "success to get tables by id. table_num=" << table_list->size(); return res; } @@ -847,8 +845,9 @@ bool OLAPEngine::check_tablet_id_exist(TTabletId tablet_id) { OLAPStatus OLAPEngine::add_table(TTabletId tablet_id, SchemaHash schema_hash, const OLAPTablePtr& table, bool force) { OLAPStatus res = OLAP_SUCCESS; - OLAP_LOG_DEBUG("begin to add olap table to OLAPEngine. [tablet_id=%ld schema_hash=%d], force: %d", - tablet_id, schema_hash, force); + VLOG(3) << "begin to add olap table to OLAPEngine. " + << "tablet_id=" << tablet_id << ", schema_hash=" << schema_hash + << ", force=" << force; _tablet_map_lock.wrlock(); table->set_id(_global_table_id++); @@ -1043,11 +1042,12 @@ OLAPStatus OLAPEngine::publish_version(const TPublishVersionRequest& publish_ver // each tablet for (auto& load_info : load_info_map) { const TabletInfo& tablet_info = load_info.first; - OLAP_LOG_DEBUG("begin to publish version on tablet. " - "[tablet_id=%ld schema_hash=%d version=%d version_hash=%ld transaction_id=%ld]", - tablet_info.tablet_id, tablet_info.schema_hash, - version.first, version_hash, transaction_id); - + VLOG(3) << "begin to publish version on tablet. " + << "tablet_id=" << tablet_info.tablet_id + << ", schema_hash=" << tablet_info.schema_hash + << ", version=" << version.first + << ", version_hash=" << version_hash + << ", transaction_id=" << transaction_id; OLAPTablePtr tablet = get_table(tablet_info.tablet_id, tablet_info.schema_hash); if (tablet.get() == NULL) { @@ -1174,17 +1174,19 @@ OLAPStatus OLAPEngine::clone_incremental_data(OLAPTablePtr tablet, OLAPHeader& c least_complete_version->start_version(), least_complete_version->end_version())); - OLAP_LOG_DEBUG("least complete version_hash in clone src is different, replace it. " - "[tablet=%s least_complete_version=%d-%d local_hash=%ld clone_hash=%ld]", - tablet->full_name().c_str(), - least_complete_version->start_version(), least_complete_version->end_version(), - least_complete_version->version_hash(), clone_src_version->version_hash()); + VLOG(3) << "least complete version_hash in clone src is different, replace it. " + << "tablet=" << tablet->full_name() + << ", least_complete_version=" << least_complete_version->start_version() + << "-" << least_complete_version->end_version() + << ", local_hash=" << least_complete_version->version_hash() + << ", clone_hash=" << clone_src_version->version_hash(); } } - OLAP_LOG_DEBUG("get missing versions again when incremental clone. " - "[table=%s committed_version=%ld missing_versions_size=%d]", - tablet->full_name().c_str(), committed_version, missing_versions.size()); + VLOG(3) << "get missing versions again when incremental clone. " + << "tablet=" << tablet->full_name() + << ", committed_version=" << committed_version + << ", missing_versions_size=" << missing_versions.size(); // check missing versions exist in clone src for (Version version : missing_versions) { @@ -1428,8 +1430,8 @@ OLAPStatus OLAPEngine::drop_tables_on_error_root_path( for (const TabletInfo& tablet_info : tablet_info_vec) { TTabletId tablet_id = tablet_info.tablet_id; TSchemaHash schema_hash = tablet_info.schema_hash; - OLAP_LOG_DEBUG("drop_table begin. [table=%ld schema_hash=%d]", - tablet_id, schema_hash); + VLOG(3) << "drop_table begin. tablet_id=" << tablet_id + << ", schema_hash=" << schema_hash; OLAPTablePtr dropped_table = _get_table_with_no_lock(tablet_id, schema_hash); if (dropped_table.get() == NULL) { OLAP_LOG_WARNING("dropping table not exist. [table=%ld schema_hash=%d]", @@ -1501,9 +1503,8 @@ OLAPTablePtr OLAPEngine::create_table( OLAPStatus OLAPEngine::create_init_version(TTabletId tablet_id, SchemaHash schema_hash, Version version, VersionHash version_hash) { - OLAP_LOG_DEBUG("begin to create init version. [begin=%d end=%d]", - version.first, version.second); - + VLOG(3) << "begin to create init version. " + << "begin=" << version.first << ", end=" << version.second; OLAPTablePtr table; ColumnDataWriter* writer = NULL; SegmentGroup* new_segment_group = NULL; @@ -1583,14 +1584,14 @@ OLAPStatus OLAPEngine::create_init_version(TTabletId tablet_id, SchemaHash schem } } - OLAP_LOG_DEBUG("create init version end. [res=%d]", res); + VLOG(3) << "create init version end. res=" << res; SAFE_DELETE(writer); return res; } bool OLAPEngine::try_schema_change_lock(TTabletId tablet_id) { bool res = false; - OLAP_LOG_DEBUG("try_schema_change_lock begin. [table=%ld]", tablet_id); + VLOG(3) << "try_schema_change_lock begin. table_id=" << tablet_id; _tablet_map_lock.rdlock(); tablet_map_t::iterator it = _tablet_map.find(tablet_id); @@ -1601,12 +1602,12 @@ bool OLAPEngine::try_schema_change_lock(TTabletId tablet_id) { } _tablet_map_lock.unlock(); - OLAP_LOG_DEBUG("try_schema_change_lock end. [table=%ld]", tablet_id); + VLOG(3) << "try_schema_change_lock end. table_id=" << tablet_id; return res; } void OLAPEngine::release_schema_change_lock(TTabletId tablet_id) { - OLAP_LOG_DEBUG("release_schema_change_lock begin. [table=%ld]", tablet_id); + VLOG(3) << "release_schema_change_lock begin. tablet_id=" << tablet_id; _tablet_map_lock.rdlock(); tablet_map_t::iterator it = _tablet_map.find(tablet_id); @@ -1617,7 +1618,7 @@ void OLAPEngine::release_schema_change_lock(TTabletId tablet_id) { } _tablet_map_lock.unlock(); - OLAP_LOG_DEBUG("release_schema_change_lock end. [table=%ld]", tablet_id); + VLOG(3) << "release_schema_change_lock end. tablet_id=" << tablet_id; } void OLAPEngine::_build_tablet_info(OLAPTablePtr olap_table, TTabletInfo* tablet_info) { @@ -1719,7 +1720,7 @@ OLAPStatus OLAPEngine::report_all_tablets_info(std::map* tab } void OLAPEngine::get_tablet_stat(TTabletStatResult& result) { - OLAP_LOG_DEBUG("begin to get all tablet stat."); + VLOG(3) << "begin to get all tablet stat."; // get current time int64_t current_time = UnixMillis(); @@ -1728,7 +1729,7 @@ void OLAPEngine::get_tablet_stat(TTabletStatResult& result) { // update cache if too old if (current_time - _tablet_stat_cache_update_time_ms > config::tablet_stat_cache_update_interval_second * 1000) { - OLAP_LOG_DEBUG("update tablet stat."); + VLOG(3) << "update tablet stat."; _build_tablet_stat(); } @@ -1754,9 +1755,9 @@ void OLAPEngine::_build_tablet_stat() { // we only get base tablet's stat stat.__set_data_size(olap_table->get_data_size()); stat.__set_row_num(olap_table->get_num_rows()); - OLAP_LOG_DEBUG("tablet %d get data size: %d, row num %d", - item.first, olap_table->get_data_size(), - olap_table->get_num_rows()); + VLOG(3) << "tablet_id=" << item.first + << ", data_size=" << olap_table->get_data_size() + << ", row_num:" << olap_table->get_num_rows(); break; } @@ -1791,9 +1792,9 @@ bool OLAPEngine::_can_do_compaction(OLAPTablePtr table) { } void OLAPEngine::start_clean_fd_cache() { - OLAP_LOG_TRACE("start clean file descritpor cache"); + VLOG(10) << "start clean file descritpor cache"; FileHandler::get_fd_cache()->prune(); - OLAP_LOG_TRACE("end clean file descritpor cache"); + VLOG(10) << "end clean file descritpor cache"; } void OLAPEngine::perform_cumulative_compaction() { @@ -2181,8 +2182,7 @@ void OLAPEngine::_cancel_unfinished_schema_change() { ALTER_TABLE_FAILED, new_olap_table->schema_hash(), -1); olap_table->set_schema_change_status( ALTER_TABLE_FAILED, olap_table->schema_hash(), -1); - OLAP_LOG_DEBUG("cancel unfinished schema change. [tablet='%s']", - olap_table->full_name().c_str()); + VLOG(3) << "cancel unfinished schema change. tablet=" << olap_table->full_name(); ++canceled_num; } } @@ -2509,7 +2509,7 @@ OLAPStatus OLAPEngine::compute_checksum( while (true) { OLAPStatus res = reader.next_row_with_aggregation(&row, &eof); if (res == OLAP_SUCCESS && eof) { - OLAP_LOG_DEBUG("reader reads to the end."); + VLOG(3) << "reader reads to the end."; break; } else if (res != OLAP_SUCCESS) { OLAP_LOG_WARNING("fail to read in reader. [res=%d]", res); @@ -2695,8 +2695,9 @@ OLAPStatus OLAPEngine::finish_clone(OLAPTablePtr tablet, const string& clone_dir // link files from clone dir, if file exists, skip it for (const string& clone_file : clone_files) { if (local_files.find(clone_file) != local_files.end()) { - OLAP_LOG_DEBUG("find same file when clone, skip it. [table=%s clone_file=%s]", - tablet->full_name().c_str(), clone_file.c_str()); + VLOG(3) << "find same file when clone, skip it. " + << "tablet=" << tablet->full_name() + << ", clone_file=" << clone_file; continue; } diff --git a/be/src/olap/olap_header.cpp b/be/src/olap/olap_header.cpp index 7a76522c2a..da79c039f4 100644 --- a/be/src/olap/olap_header.cpp +++ b/be/src/olap/olap_header.cpp @@ -710,10 +710,9 @@ OLAPStatus OLAPHeader::select_versions_to_span(const Version& target_version, << (*span_versions)[span_versions->size() - 1].second << ' '; } - OLAP_LOG_TRACE("calculated shortest path. [version='%d-%d' path='%s']", - target_version.first, - target_version.second, - shortest_path_for_debug.str().c_str()); + VLOG(10) << "calculated shortest path. " + << "version=" << target_version.first << "-" << target_version.second + << "path=" << shortest_path_for_debug.str(); return OLAP_SUCCESS; } @@ -860,7 +859,7 @@ static OLAPStatus construct_version_graph( vector* version_graph, unordered_map* vertex_helper_map) { if (versions_in_header.size() == 0) { - OLAP_LOG_DEBUG("there is no version in the header."); + VLOG(3) << "there is no version in the header."; return OLAP_SUCCESS; } @@ -872,9 +871,9 @@ static OLAPStatus construct_version_graph( for (int i = 0; i < versions_in_header.size(); ++i) { vertex_values.push_back(versions_in_header.Get(i).start_version()); vertex_values.push_back(versions_in_header.Get(i).end_version() + 1); - OLAP_LOG_DEBUG("added two vertex_values. [version='%d-%d']", - versions_in_header.Get(i).start_version(), - versions_in_header.Get(i).end_version() + 1); + VLOG(3) << "added two vertex_values. " + << "version=" << versions_in_header.Get(i).start_version() + << "-" << versions_in_header.Get(i).end_version() + 1; } sort(vertex_values.begin(), vertex_values.end()); @@ -1019,10 +1018,9 @@ static OLAPStatus delete_version_from_graph( if (num_isolated_vertex > 1 + static_cast(RATIO_OF_ISOLATED_VERTEX * version_graph->size())) { - OLAP_LOG_DEBUG("the number of isolated vertexes reaches specified ratio," - "reconstruct version graph. [num_isolated_vertex=%d num_vertex=%lu]", - num_isolated_vertex, - version_graph->size()); + VLOG(3) << "the number of isolated vertexes reaches specified ratio," + << "reconstruct version graph. num_isolated_vertex=" << num_isolated_vertex + << ", num_vertex=" << version_graph->size(); // Release memory of version graph. for (vector::iterator it = version_graph->begin(); @@ -1055,7 +1053,7 @@ static OLAPStatus add_vertex_to_graph(int vertex_value, // Vertex with vertex_value already exists. if (vertex_helper_map->find(vertex_value) != vertex_helper_map->end()) { - OLAP_LOG_DEBUG("vertex with vertex value already exists. [value=%d]", vertex_value); + VLOG(3) << "vertex with vertex value already exists. value=" << vertex_value; return OLAP_SUCCESS; } diff --git a/be/src/olap/olap_index.cpp b/be/src/olap/olap_index.cpp index e41ac07fb2..bbc55e638c 100644 --- a/be/src/olap/olap_index.cpp +++ b/be/src/olap/olap_index.cpp @@ -344,8 +344,8 @@ const OLAPIndexOffset MemIndex::find(const RowCursor& k, } offset.offset = *it; - OLAP_LOG_DEBUG("show real offset iterator value. [off=%u]", *it); - OLAP_LOG_DEBUG("show result offset. [seg_off=%u off=%u]", offset.segment, offset.offset); + VLOG(3) << "show real offset iterator value. off=" << *it; + VLOG(3) << "show result offset. seg_off=" << offset.segment << ", off=" << offset.offset; } catch (...) { OLAP_LOG_WARNING("fail to compare value in memindex. [cursor='%s' find_last=%d]", k.to_string().c_str(), diff --git a/be/src/olap/olap_server.cpp b/be/src/olap/olap_server.cpp index 0a7132a5d7..b236caeb3a 100644 --- a/be/src/olap/olap_server.cpp +++ b/be/src/olap/olap_server.cpp @@ -82,7 +82,7 @@ OLAPStatus OLAPEngine::_start_bg_worker() { _fd_cache_clean_callback(nullptr); }); - OLAP_LOG_TRACE("init finished."); + VLOG(10) << "init finished."; return OLAP_SUCCESS; } diff --git a/be/src/olap/olap_snapshot.cpp b/be/src/olap/olap_snapshot.cpp index ff94ae9cf5..9d5e7e9395 100644 --- a/be/src/olap/olap_snapshot.cpp +++ b/be/src/olap/olap_snapshot.cpp @@ -292,7 +292,7 @@ OLAPStatus OLAPEngine::_create_snapshot_files( ref_olap_table, snapshot_id_path); string header_path = _get_header_full_path(ref_olap_table, schema_full_path); if (check_dir_existed(schema_full_path)) { - OLAP_LOG_TRACE("remove the old schema_full_path."); + VLOG(10) << "remove the old schema_full_path."; remove_all_dir(schema_full_path); } create_dirs(schema_full_path); @@ -410,12 +410,12 @@ OLAPStatus OLAPEngine::_create_snapshot_files( SAFE_DELETE(new_olap_header); if (header_locked) { - OLAP_LOG_TRACE("release header lock."); + VLOG(10) << "release header lock."; ref_olap_table->release_header_lock(); } if (ref_olap_table.get() != NULL) { - OLAP_LOG_TRACE("release data sources."); + VLOG(10) << "release data sources."; ref_olap_table->release_data_sources(&olap_data_sources); } @@ -458,7 +458,7 @@ OLAPStatus OLAPEngine::_create_incremental_snapshot_files( string schema_full_path = _get_schema_hash_full_path(ref_olap_table, snapshot_id_path); if (check_dir_existed(schema_full_path)) { - OLAP_LOG_TRACE("remove the old schema_full_path."); + VLOG(10) << "remove the old schema_full_path."; remove_all_dir(schema_full_path); } create_dirs(schema_full_path); @@ -492,9 +492,10 @@ OLAPStatus OLAPEngine::_create_incremental_snapshot_files( const PDelta* incremental_delta = ref_olap_table->get_incremental_delta(Version(missing_version, missing_version)); if (incremental_delta != nullptr) { - OLAP_LOG_DEBUG("success to find missing version when snapshot, " - "begin to link files. [table=%ld schema_hash=%d version=%ld]", - request.tablet_id, request.schema_hash, missing_version); + VLOG(3) << "success to find missing version when snapshot, " + << "begin to link files. tablet_id=" << request.tablet_id + << ", schema_hash=" << request.schema_hash + << ", version=" << missing_version; // link files for (uint32_t i = 0; i < incremental_delta->segment_group(0).num_segments(); i++) { int32_t segment_group_id = incremental_delta->segment_group(0).segment_group_id(); @@ -614,8 +615,8 @@ string OLAPEngine::_construct_data_file_path( OLAPStatus OLAPEngine::_create_hard_link(const string& from_path, const string& to_path) { if (link(from_path.c_str(), to_path.c_str()) == 0) { - OLAP_LOG_TRACE("success to create hard link from path=%s to path=%s]", - from_path.c_str(), to_path.c_str()); + VLOG(10) << "success to create hard link from_path=" << from_path + << ", to_path=" << to_path; return OLAP_SUCCESS; } else { OLAP_LOG_WARNING("failed to create hard link from path=%s to path=%s errno=%d", @@ -702,8 +703,8 @@ OLAPStatus OLAPEngine::storage_medium_migrate( root_path_stream << stores[0]->path() << DATA_PREFIX << "/" << shard; string schema_hash_path = _get_schema_hash_full_path(tablet, root_path_stream.str()); if (check_dir_existed(schema_hash_path)) { - OLAP_LOG_DEBUG("schema hash path already exist, remove it. [schema_hash_path='%s']", - schema_hash_path.c_str()); + VLOG(3) << "schema hash path already exist, remove it. " + << "schema_hash_path=" << schema_hash_path; remove_all_dir(schema_hash_path); } create_dirs(schema_hash_path); diff --git a/be/src/olap/olap_table.cpp b/be/src/olap/olap_table.cpp index 183624743d..0ff9487557 100644 --- a/be/src/olap/olap_table.cpp +++ b/be/src/olap/olap_table.cpp @@ -1697,7 +1697,7 @@ OLAPStatus OLAPTable::split_range( // 如果找不到合适的segment_group，就直接返回startkey，endkey if (base_index == NULL) { - OLAP_LOG_DEBUG("there is no base file now, may be tablet is empty."); + VLOG(3) << "there is no base file now, may be tablet is empty."; // it may be right if the table is empty, so we return success. ranges->emplace_back(start_key.to_tuple()); ranges->emplace_back(end_key.to_tuple()); @@ -1721,7 +1721,7 @@ OLAPStatus OLAPTable::split_range( } step_pos = start_pos; - OLAP_LOG_DEBUG("start post = %d, %d", start_pos.segment, start_pos.index_offset); + VLOG(3) << "start_pos=" << start_pos.segment << ", " << start_pos.index_offset; //find last row_block is end_key is given, or using last_row_block if (base_index->find_short_key(end_key, &helper_cursor, false, &end_pos) != OLAP_SUCCESS) { @@ -1731,7 +1731,7 @@ OLAPStatus OLAPTable::split_range( } } - OLAP_LOG_DEBUG("end post = %d, %d", end_pos.segment, end_pos.index_offset); + VLOG(3) << "end_pos=" << end_pos.segment << ", " << end_pos.index_offset; //get rows between first and last OLAPStatus res = OLAP_SUCCESS; diff --git a/be/src/olap/olap_table.h b/be/src/olap/olap_table.h index 726aadc732..ec2f4f5296 100644 --- a/be/src/olap/olap_table.h +++ b/be/src/olap/olap_table.h @@ -591,11 +591,9 @@ public: _schema_change_status.status = status; _schema_change_status.schema_hash = schema_hash; _schema_change_status.version = version; - OLAP_LOG_DEBUG("set schema change status. [tablet_id=%d], " - "[schema_hash=%d], [status=%d]", - _tablet_id, - _schema_change_status.schema_hash, - _schema_change_status.status); + VLOG(3) << "set schema change status. tablet_id=" << _tablet_id + << ", schema_hash=" << _schema_change_status.schema_hash + << ", status=" << _schema_change_status.status; } void clear_schema_change_status() { diff --git a/be/src/olap/out_stream.cpp b/be/src/olap/out_stream.cpp index 3bbe0796af..7442a56371 100644 --- a/be/src/olap/out_stream.cpp +++ b/be/src/olap/out_stream.cpp @@ -295,21 +295,13 @@ OLAPStatus OutStream::write(const char* buffer, uint64_t length) { } void OutStream::get_position(PositionEntryWriter* index_entry) const { - //OLAP_LOG_DEBUG("begin recording position [OutStream], " - // "recorded position count: %d", index_entry->positions_size()); - //OLAP_LOG_DEBUG("add _spilled_bytes: %lu", _spilled_bytes); index_entry->add_position(_spilled_bytes); if (NULL != _current) { index_entry->add_position(_current->position() - sizeof(StreamHead)); - //OLAP_LOG_DEBUG("add current: %lu", _current->position() - sizeof(StreamHead)); } else { index_entry->add_position(0); - //OLAP_LOG_DEBUG("add current: 0"); } - - //OLAP_LOG_DEBUG("end recording position [OutStream], " - // "recorded position count: %d", index_entry->positions_size()); } uint64_t OutStream::get_stream_length() const { @@ -357,7 +349,7 @@ OLAPStatus OutStream::write_to_file(FileHandler* file_handle, for (std::vector::const_iterator it = _output_buffers.begin(); it != _output_buffers.end(); ++it) { - OLAP_LOG_DEBUG("write stream begin: %lu", file_handle->tell()); + VLOG(3) << "write stream begin:" << file_handle->tell(); res = file_handle->write((*it)->array(), (*it)->limit()); if (OLAP_SUCCESS != res) { @@ -365,7 +357,7 @@ OLAPStatus OutStream::write_to_file(FileHandler* file_handle, return res; } - OLAP_LOG_DEBUG("write stream end: %lu", file_handle->tell()); + VLOG(3) << "write stream end:" << file_handle->tell(); total_stream_len += (*it)->limit(); if (write_mbytes_per_sec > 0) { @@ -373,8 +365,8 @@ OLAPStatus OutStream::write_to_file(FileHandler* file_handle, int64_t sleep_time = total_stream_len / write_mbytes_per_sec - delta_time_us; if (sleep_time > 0) { - OLAP_LOG_DEBUG("sleep to limit merge speed. [time=%lu bytes=%lu]", - sleep_time, total_stream_len); + VLOG(3) << "sleep to limit merge speed. time=" << sleep_time + << ", bytes=" << total_stream_len; usleep(sleep_time); } } diff --git a/be/src/olap/out_stream.h b/be/src/olap/out_stream.h index 0dc2228ff2..154278c9c5 100644 --- a/be/src/olap/out_stream.h +++ b/be/src/olap/out_stream.h @@ -106,12 +106,12 @@ public: } void print_position_debug_info() { - OLAP_LOG_TRACE("compress %lu", _spilled_bytes); + VLOG(10) << "compress: " << _spilled_bytes; if (_current != NULL) { - OLAP_LOG_TRACE("uncompress %lu", _current->position() - sizeof(StreamHead)); + VLOG(10) << "uncompress=" << ( _current->position() - sizeof(StreamHead)); } else { - OLAP_LOG_TRACE("uncompress 0"); + VLOG(10) << "uncompress 0"; } } diff --git a/be/src/olap/push_handler.cpp b/be/src/olap/push_handler.cpp index 3f884aae48..ce89abc42b 100644 --- a/be/src/olap/push_handler.cpp +++ b/be/src/olap/push_handler.cpp @@ -337,8 +337,9 @@ OLAPStatus PushHandler::process_realtime_push( // only when fe sends schema_change true, should consider to push related table if (_request.is_schema_changing) { - OLAP_LOG_DEBUG("push req specify schema changing is true. [table=%s transaction_id=%ld]", - olap_table->full_name().c_str(), request.transaction_id); + VLOG(3) << "push req specify schema changing is true. " + << "tablet=" << olap_table->full_name() + << ", transaction_id=" << request.transaction_id; TTabletId related_tablet_id; TSchemaHash related_schema_hash; @@ -539,8 +540,7 @@ OLAPStatus PushHandler::_convert( uint32_t num_rows = 0; do { - OLAP_LOG_DEBUG("start to convert delta file."); - + VLOG(3) << "start to convert delta file."; std::vector tablet_schema = curr_olap_table->tablet_schema(); //curr_olap_table->set_tablet_schema(); @@ -582,7 +582,7 @@ OLAPStatus PushHandler::_convert( } // 2. New SegmentGroup of curr_olap_table for current push - OLAP_LOG_DEBUG("init SegmentGroup."); + VLOG(3) << "init SegmentGroup."; if (_request.__isset.transaction_id) { // create pending data dir @@ -616,9 +616,8 @@ OLAPStatus PushHandler::_convert( curr_olap_indices->push_back(delta_segment_group); // 3. New Writer to write data into SegmentGroup - OLAP_LOG_DEBUG("init writer. [table='%s' block_row_size=%lu]", - curr_olap_table->full_name().c_str(), - curr_olap_table->num_rows_per_row_block()); + VLOG(3) << "init writer. tablet=" << curr_olap_table->full_name() + << ", block_row_size=" << curr_olap_table->num_rows_per_row_block(); if (NULL == (writer = ColumnDataWriter::create(curr_olap_table, delta_segment_group, true))) { OLAP_LOG_WARNING("fail to create writer. [table='%s']", @@ -636,8 +635,7 @@ OLAPStatus PushHandler::_convert( // 5. Read data from raw file and write into SegmentGroup of curr_olap_table if (_request.__isset.http_file_path) { // Convert from raw to delta - OLAP_LOG_DEBUG("start to convert row file to delta."); - + VLOG(3) << "start to convert row file to delta."; while (!reader->eof()) { if (OLAP_SUCCESS != (res = writer->attached_by(&row))) { OLAP_LOG_WARNING( @@ -671,8 +669,7 @@ OLAPStatus PushHandler::_convert( break; } - OLAP_LOG_DEBUG("load the index."); - + VLOG(3) << "load the index."; if (OLAP_SUCCESS != (res = delta_segment_group->load())) { OLAP_LOG_WARNING("fail to load index. [res=%d table='%s' version=%ld]", res, curr_olap_table->full_name().c_str(), _request.version); @@ -682,7 +679,7 @@ OLAPStatus PushHandler::_convert( _write_rows += delta_segment_group->num_rows(); // 7. Convert data for schema change tables - OLAP_LOG_TRACE("load to related tables of schema_change if possible. "); + VLOG(10) << "load to related tables of schema_change if possible."; if (NULL != new_olap_table.get()) { // create related tablet's pending data dir string dir_path = new_olap_table->construct_pending_data_dir_path(); @@ -712,9 +709,8 @@ OLAPStatus PushHandler::_convert( SAFE_DELETE(reader); SAFE_DELETE(writer); OLAP_LOG_NOTICE_PUSH("processed_rows", "%d", num_rows); - OLAP_LOG_TRACE("convert delta file end. [table='%s' res=%d]", - curr_olap_table->full_name().c_str(), res); - + VLOG(10) << "convert delta file end. res=" << res + << ", tablet=" << curr_olap_table->full_name(); return res; } @@ -809,10 +805,8 @@ OLAPStatus PushHandler::_get_versions_reverted( return OLAP_ERR_PUSH_VERSION_INCORRECT; } - OLAP_LOG_DEBUG("latest deltas was founded. [table='%s' version=%d-%d]", - olap_table->full_name().c_str(), - latest_delta->start_version(), latest_delta->end_version()); - + VLOG(3) << "latest deltas was founded. tablet=" << olap_table->full_name() + << ", version=" << latest_delta->start_version() << "-" << latest_delta->end_version(); // Remove the cumulative delta that end_version == request.version() if (_request.version == latest_delta->start_version()) { Versions all_versions; @@ -821,8 +815,8 @@ OLAPStatus PushHandler::_get_versions_reverted( for (Versions::const_iterator v = all_versions.begin(); v != all_versions.end(); ++v) { if (v->second == _request.version) { unused_versions->push_back(*v); - OLAP_LOG_DEBUG("Add unused version. [table='%s' version=%d-%d]", - olap_table->full_name().c_str(), v->first, v->second); + VLOG(3) << "Add unused version. tablet=" << olap_table->full_name() + << "version=" << v->first << "-" << v->second; } } diff --git a/be/src/olap/push_handler.h b/be/src/olap/push_handler.h index a8f1769a2b..c84def76ea 100644 --- a/be/src/olap/push_handler.h +++ b/be/src/olap/push_handler.h @@ -118,8 +118,7 @@ private: void _obtain_header_rdlock() { for (std::list::iterator it = _olap_table_arr.begin(); it != _olap_table_arr.end(); ++it) { - OLAP_LOG_DEBUG("obtain all header locks rd. [table='%s']", - (*it)->full_name().c_str()); + VLOG(3) << "obtain all header locks rd. tablet=" << (*it)->full_name(); (*it)->obtain_header_rdlock(); } @@ -130,8 +129,7 @@ private: void _obtain_header_wrlock() { for (std::list::iterator it = _olap_table_arr.begin(); it != _olap_table_arr.end(); ++it) { - OLAP_LOG_DEBUG( - "obtain all header locks wr. [table='%s']", (*it)->full_name().c_str()); + VLOG(3) << "obtain all header locks wr. tablet=" << (*it)->full_name(); (*it)->obtain_header_wrlock(); } @@ -143,8 +141,7 @@ private: if (_header_locked) { for (std::list::reverse_iterator it = _olap_table_arr.rbegin(); it != _olap_table_arr.rend(); ++it) { - OLAP_LOG_DEBUG( - "release all header locks. [table='%s']", (*it)->full_name().c_str()); + VLOG(3) << "release all header locks. tablet=" << (*it)->full_name(); (*it)->release_header_lock(); } diff --git a/be/src/olap/reader.cpp b/be/src/olap/reader.cpp index 5df393fb6c..e5b7740519 100644 --- a/be/src/olap/reader.cpp +++ b/be/src/olap/reader.cpp @@ -465,7 +465,7 @@ OLAPStatus Reader::_unique_key_next_row(RowCursor* row_cursor, bool* eof) { } void Reader::close() { - OLAP_LOG_DEBUG("merged rows:%lu", _merged_rows); + VLOG(3) << "merged rows:" << _merged_rows; _conditions.finalize(); _delete_handler.finalize(); _olap_table->release_data_sources(&_own_data_sources); @@ -518,24 +518,24 @@ OLAPStatus Reader::_acquire_data_sources(const ReaderParams& read_params) { is_using_cache, read_params.runtime_state); if (i_data->delta_pruning_filter()) { - OLAP_LOG_DEBUG("filter delta in query in condition: %d, %d", - i_data->version().first, i_data->version().second); + VLOG(3) << "filter delta in query in condition:" + << i_data->version().first << ", " << i_data->version().second; _stats.rows_stats_filtered += i_data->num_rows(); continue; } int ret = i_data->delete_pruning_filter(); if (ret == DEL_SATISFIED) { - OLAP_LOG_DEBUG("filter delta in delete predicate: %d, %d", - i_data->version().first, i_data->version().second); + VLOG(3) << "filter delta in delete predicate:" + << i_data->version().first << ", " << i_data->version().second; _stats.rows_del_filtered += i_data->num_rows(); continue; } else if (ret == DEL_PARTIAL_SATISFIED) { - OLAP_LOG_DEBUG("filter delta partially in delete predicate: %d, %d", - i_data->version().first, i_data->version().second); + VLOG(3) << "filter delta partially in delete predicate:" + << i_data->version().first << ", " << i_data->version().second; i_data->set_delete_status(DEL_PARTIAL_SATISFIED); } else { - OLAP_LOG_DEBUG("not filter delta in delete predicate: %d, %d", - i_data->version().first, i_data->version().second); + VLOG(3) << "not filter delta in delete predicate:" + << i_data->version().first << ", " << i_data->version().second; i_data->set_delete_status(DEL_NOT_SATISFIED); } _data_sources.push_back(i_data); @@ -618,7 +618,7 @@ OLAPStatus Reader::_init_return_columns(const ReaderParams& read_params) { _value_cids.push_back(i); } } - OLAP_LOG_DEBUG("return column is empty, using full column as defaut."); + VLOG(3) << "return column is empty, using full column as defaut."; } else if (read_params.reader_type == READER_CHECKSUM) { _return_columns = read_params.return_columns; for (auto id : read_params.return_columns) { @@ -653,7 +653,7 @@ OLAPStatus Reader::_attach_data_to_merge_set(bool first, bool *eof) { if (_keys_param.start_keys.size() > 0) { if (_next_key_index >= _keys_param.start_keys.size()) { *eof = true; - OLAP_LOG_DEBUG("can NOT attach while start_key has been used."); + VLOG(3) << "can NOT attach while start_key has been used."; return res; } auto cur_key_index = _next_key_index++; @@ -677,10 +677,9 @@ OLAPStatus Reader::_attach_data_to_merge_set(bool first, bool *eof) { if (0 == _keys_param.range.compare("gt")) { if (NULL != end_key && start_key->cmp(*end_key) >= 0) { - OLAP_LOG_TRACE("return EOF when range(%s) start_key(%s) end_key(%s).", - _keys_param.range.c_str(), - start_key->to_string().c_str(), - end_key->to_string().c_str()); + VLOG(10) << "return EOF when range=" << _keys_param.range + << ", start_key=" << start_key->to_string() + << ", end_key=" << end_key->to_string(); *eof = true; return res; } @@ -689,10 +688,9 @@ OLAPStatus Reader::_attach_data_to_merge_set(bool first, bool *eof) { } else if (0 == _keys_param.range.compare("ge")) { if (NULL != end_key && start_key->cmp(*end_key) > 0) { - OLAP_LOG_TRACE("return EOF when range(%s) start_key(%s) end_key(%s).", - _keys_param.range.c_str(), - start_key->to_string().c_str(), - end_key->to_string().c_str()); + VLOG(10) << "return EOF when range=" << _keys_param.range + << ", start_key=" << start_key->to_string() + << ", end_key=" << end_key->to_string(); *eof = true; return res; } diff --git a/be/src/olap/run_length_byte_writer.cpp b/be/src/olap/run_length_byte_writer.cpp index fed2fa41fd..b9f9ef580d 100644 --- a/be/src/olap/run_length_byte_writer.cpp +++ b/be/src/olap/run_length_byte_writer.cpp @@ -138,12 +138,8 @@ OLAPStatus RunLengthByteWriter::flush() { } void RunLengthByteWriter::get_position(PositionEntryWriter* index_entry) const { - // OLAP_LOG_DEBUG("begin recording position [RunLengthByteWriter], " - // "recorded position count: %d", index_entry->positions_size()); _output->get_position(index_entry); index_entry->add_position(_num_literals); - // OLAP_LOG_DEBUG("end recording position [RunLengthByteWriter], " - // "recorded position count: %d", index_entry->positions_size()); } } // namespace doris diff --git a/be/src/olap/run_length_integer_reader.cpp b/be/src/olap/run_length_integer_reader.cpp index 0d1d000dc2..e7e34f6b68 100644 --- a/be/src/olap/run_length_integer_reader.cpp +++ b/be/src/olap/run_length_integer_reader.cpp @@ -43,7 +43,6 @@ OLAPStatus RunLengthIntegerReader::_read_values() { } else { int enc = (first_byte >> 6) & 0x03; - //OLAP_LOG_DEBUG("decoding with %d", enc); if (RunLengthIntegerWriter::SHORT_REPEAT == enc) { res = _read_short_repeat_values(first_byte); } else if (RunLengthIntegerWriter::DIRECT == enc) { diff --git a/be/src/olap/run_length_integer_writer.cpp b/be/src/olap/run_length_integer_writer.cpp index b1e1493e0f..f58ece504d 100644 --- a/be/src/olap/run_length_integer_writer.cpp +++ b/be/src/olap/run_length_integer_writer.cpp @@ -726,7 +726,7 @@ void RunLengthIntegerWriter::get_position(PositionEntryWriter* index_entry, bool if (print) { _output->print_position_debug_info(); - OLAP_LOG_TRACE("literals : %u", _num_literals); + VLOG(10) << "literals=" << _num_literals; } } diff --git a/be/src/olap/run_length_integer_writer.h b/be/src/olap/run_length_integer_writer.h index 78f7f61854..60d61ed071 100644 --- a/be/src/olap/run_length_integer_writer.h +++ b/be/src/olap/run_length_integer_writer.h @@ -114,7 +114,7 @@ public: void print_position_debug_info() { _output->print_position_debug_info(); - OLAP_LOG_TRACE("_num_literals: %lu", _num_literals); + VLOG(10) << "_num_literals=" << _num_literals; } private: diff --git a/be/src/olap/schema_change.cpp b/be/src/olap/schema_change.cpp index b5f8889b78..45c8744c44 100644 --- a/be/src/olap/schema_change.cpp +++ b/be/src/olap/schema_change.cpp @@ -329,11 +329,10 @@ bool RowBlockChanger::change_row_block( if (mutable_block->tablet_schema()[i].type < ref_block.tablet_schema()[ref_column].type) { - OLAP_LOG_DEBUG("type degraded while altering column. " - "[column='%s' origin_type=%d alter_type=%d]", - mutable_block->tablet_schema()[i].name.c_str(), - ref_block._tablet_schema[ref_column].type, - mutable_block->_tablet_schema[i].type); + VLOG(3) << "type degraded while altering column. " + << "column=" << mutable_block->tablet_schema()[i].name + << ", origin_type=" << ref_block._tablet_schema[ref_column].type + << ", alter_type=" << mutable_block->_tablet_schema[i].type; } } } else { @@ -362,7 +361,6 @@ bool RowBlockChanger::change_row_block( // （其实在init时就可以重新init成少的，filter留下的new_row_num） // 在split_table时，可能会出现因为过滤导致没有数据 mutable_block->finalize(new_row_num); - // OLAP_LOG_DEBUG("finilize one block with row_num=%u. ", new_row_num); return true; } @@ -470,7 +468,7 @@ RowBlockAllocator::RowBlockAllocator(const vector& tablet_schema, _row_len += (*it).length; } - OLAP_LOG_DEBUG("RowBlockAllocator(). [row_len=%ld]", _row_len); + VLOG(3) << "RowBlockAllocator(). row_len=" << _row_len; } RowBlockAllocator::~RowBlockAllocator() { @@ -487,8 +485,8 @@ OLAPStatus RowBlockAllocator::allocate(RowBlock** row_block, if (_memory_limitation > 0 && _memory_allocated + row_block_size > _memory_limitation) { - OLAP_LOG_DEBUG("RowBlockAllocator::alocate() memory exceeded. [m_memory_allocated=%ld]", - _memory_allocated); + VLOG(3) << "RowBlockAllocator::alocate() memory exceeded. " + << "m_memory_allocated=" << _memory_allocated; *row_block = NULL; return OLAP_SUCCESS; } @@ -513,12 +511,10 @@ OLAPStatus RowBlockAllocator::allocate(RowBlock** row_block, } _memory_allocated += row_block_size; - OLAP_LOG_DEBUG("RowBlockAllocator::allocate() " - "[this=%p num_rows=%ld m_memory_allocated=%ld p=%p]", - this, - num_rows, - _memory_allocated, - *row_block); + VLOG(3) << "RowBlockAllocator::allocate() this=" << this + << ", num_rows=" << num_rows + << ", m_memory_allocated=" << _memory_allocated + << ", row_block_addr=" << *row_block; return res; } @@ -530,12 +526,10 @@ void RowBlockAllocator::release(RowBlock* row_block) { _memory_allocated -= row_block->capacity() * _row_len; - OLAP_LOG_DEBUG("RowBlockAllocator::release() " - "[this=%p num_rows=%ld m_memory_allocated=%ld p=%p]", - this, - row_block->capacity(), - _memory_allocated, - row_block); + VLOG(3) << "RowBlockAllocator::release() this=" << this + << ", num_rows=" << row_block->capacity() + << ", m_memory_allocated=" << _memory_allocated + << ", row_block_addr=" << row_block; delete row_block; } @@ -664,7 +658,7 @@ SchemaChangeDirectly::SchemaChangeDirectly( _dst_cursor(NULL) {} SchemaChangeDirectly::~SchemaChangeDirectly() { - OLAP_LOG_DEBUG("~SchemaChangeDirectly()"); + VLOG(3) << "~SchemaChangeDirectly()"; SAFE_DELETE(_row_block_allocator); SAFE_DELETE(_src_cursor); SAFE_DELETE(_dst_cursor); @@ -691,8 +685,8 @@ bool LinkedSchemaChange::process(ColumnData* olap_data, SegmentGroup* new_segmen string index_path = new_segment_group->construct_index_file_path(new_segment_group->segment_group_id(), i); string base_table_index_path = olap_data->segment_group()->construct_index_file_path(olap_data->segment_group()->segment_group_id(), i); if (link(base_table_index_path.c_str(), index_path.c_str()) == 0) { - OLAP_LOG_DEBUG("success to create hard link. [from_path=%s to_path=%s]", - base_table_index_path.c_str(), index_path.c_str()); + VLOG(3) << "success to create hard link. from_path=" << base_table_index_path + << ", to_path=" << index_path; } else { LOG(WARNING) << "fail to create hard link. [from_path=" << base_table_index_path.c_str() << " to_path=" << index_path.c_str() @@ -703,8 +697,8 @@ bool LinkedSchemaChange::process(ColumnData* olap_data, SegmentGroup* new_segmen string data_path = new_segment_group->construct_data_file_path(new_segment_group->segment_group_id(), i); string base_table_data_path = olap_data->segment_group()->construct_data_file_path(olap_data->segment_group()->segment_group_id(), i); if (link(base_table_data_path.c_str(), data_path.c_str()) == 0) { - OLAP_LOG_DEBUG("success to create hard link. [from_path=%s to_path=%s]", - base_table_data_path.c_str(), data_path.c_str()); + VLOG(3) << "success to create hard link. from_path=" << base_table_data_path + << ", to_path=" << data_path; } else { LOG(WARNING) << "fail to create hard link. [from_path=" << base_table_data_path.c_str() << " to_path=" << data_path.c_str() @@ -913,7 +907,7 @@ SchemaChangeWithSorting::SchemaChangeWithSorting(OLAPTablePtr olap_table, } SchemaChangeWithSorting::~SchemaChangeWithSorting() { - OLAP_LOG_DEBUG("~SchemaChangeWithSorting()"); + VLOG(3) << "~SchemaChangeWithSorting()"; SAFE_DELETE(_row_block_allocator); } @@ -1133,10 +1127,8 @@ bool SchemaChangeWithSorting::_internal_sorting(const vector& row_blo goto INTERNAL_SORTING_ERR; } - OLAP_LOG_DEBUG("init writer. [table='%s' block_row_size=%lu]", - _olap_table->full_name().c_str(), - _olap_table->num_rows_per_row_block()); - + VLOG(3) << "init writer. tablet=" << _olap_table->full_name() + << ", block_row_size=" << _olap_table->num_rows_per_row_block(); writer = ColumnDataWriter::create(_olap_table, *temp_segment_group, false); if (NULL == writer) { OLAP_LOG_WARNING("failed to create writer."); @@ -1263,7 +1255,7 @@ OLAPStatus SchemaChangeHandler::clear_schema_change_single_info( } if (!check_only) { - OLAP_LOG_DEBUG("broke old schema change chain"); + VLOG(3) << "broke old schema change chain"; olap_table->clear_schema_change_request(); } @@ -1451,8 +1443,8 @@ OLAPStatus SchemaChangeHandler::_do_alter_table( // wait transactions to publish version int num = 0; while (!transaction_ids.empty()) { - OLAP_LOG_DEBUG("wait transactions when schema change. [tablet='%s' transaction_size=%d]", - ref_olap_table->full_name().c_str(), transaction_ids.size()); + VLOG(3) << "wait transactions when schema change. tablet=" << ref_olap_table->full_name() + << ", transaction_size=" << transaction_ids.size(); num++; if (num % 100 == 0) { for (int64_t transaction_id : transaction_ids) { @@ -1471,9 +1463,10 @@ OLAPStatus SchemaChangeHandler::_do_alter_table( } for (int64_t transaction_id : finished_transactions) { transaction_ids.erase(transaction_id); - OLAP_LOG_DEBUG("transaction finished when schema change is waiting. " - "[tablet=%s transaction_id=%ld transaction_size=%d]", - ref_olap_table->full_name().c_str(), transaction_id, transaction_ids.size()); + VLOG(3) << "transaction finished when schema change is waiting. " + << "tablet=" << ref_olap_table->full_name() + << ", transaction_id=" << transaction_id + << ", transaction_size=" << transaction_ids.size(); } } @@ -1484,14 +1477,15 @@ OLAPStatus SchemaChangeHandler::_do_alter_table( // before calculating version_to_be_changed, // remove all data from new tablet, prevent to rewrite data(those double pushed when wait) - OLAP_LOG_DEBUG("begin to remove all data from new tablet to prevent rewrite. [new_tablet=%s]", - new_olap_table->full_name().c_str()); + VLOG(3) << "begin to remove all data from new tablet to prevent rewrite. " + << "new_tablet=" << new_olap_table->full_name(); // only remove the version <= base_tablet's latest version const PDelta* lastest_file_version = ref_olap_table->lastest_version(); if (lastest_file_version != NULL) { - OLAP_LOG_DEBUG("find the latest version of base tablet when remove all data from new. " - "[base_tablet=%s version=%d-%d]", ref_olap_table->full_name().c_str(), - lastest_file_version->start_version(), lastest_file_version->end_version()); + VLOG(3) << "find the latest version of base tablet when remove all data from new. " + << "base_tablet=" << ref_olap_table->full_name() + << ", version=" << lastest_file_version->start_version() + << "-" << lastest_file_version->end_version(); vector new_tablet_versions; new_olap_table->list_versions(&new_tablet_versions); for (vector::const_iterator it = new_tablet_versions.begin(); @@ -1506,9 +1500,10 @@ OLAPStatus SchemaChangeHandler::_do_alter_table( segment_group->delete_all_files(); delete segment_group; } - OLAP_LOG_DEBUG("unregister data source from new tablet when schema change. " - "[new_tablet=%s version=%d-%d res=%d]", - new_olap_table->full_name().c_str(), it->first, it->second, res); + VLOG(3) << "unregister data source from new tablet when schema change. " + << "new_tablet=" << new_olap_table->full_name() + << ", version=" << it->first << "-" << it->second + << ", res=" << res; } } // save header @@ -1615,17 +1610,17 @@ OLAPStatus SchemaChangeHandler::_do_alter_table( CgroupsMgr::apply_system_cgroup(); // process the job : special for query table split key - OLAP_LOG_TRACE("starts to alter table. [new_table='%s' ref_table='%s']", - sc_params.new_olap_table->full_name().c_str(), - sc_params.ref_olap_table->full_name().c_str()); + VLOG(10) << "starts to alter table. " + << "old_tablet=" << sc_params.ref_olap_table->full_name() + << ", new_tablet=" << sc_params.new_olap_table->full_name(); if ((res = _alter_table(&sc_params)) != OLAP_SUCCESS) { OLAP_LOG_WARNING("failed to alter table. [request='%s']", sc_params.debug_message.c_str()); } - OLAP_LOG_TRACE("schema change thread completed the job. [request='%s']", - sc_params.debug_message.c_str()); + VLOG(10) << "schema change thread completed the job. " + << "request=" << sc_params.debug_message; } else { // Delete olap table when submit alter table failed. OLAPEngine::get_instance()->drop_table( @@ -2016,8 +2011,8 @@ OLAPStatus SchemaChangeHandler::_alter_table(SchemaChangeParams* sc_params) { // c. 转换历史数据 for (vector::iterator it = sc_params->ref_olap_data_arr.end() - 1; it >= sc_params->ref_olap_data_arr.begin(); --it) { - OLAP_LOG_TRACE("begin to convert a history delta. [version='%d-%d']", - (*it)->version().first, (*it)->version().second); + VLOG(10) << "begin to convert a history delta. " + << "version=" << (*it)->version().first << "-" << (*it)->version().second; // set status for monitor // 只要有一个new_table为running，ref table就设置为running @@ -2048,8 +2043,8 @@ OLAPStatus SchemaChangeHandler::_alter_table(SchemaChangeParams* sc_params) { (*it)->set_delete_handler(sc_params->delete_handler); int del_ret = (*it)->delete_pruning_filter(); if (DEL_SATISFIED == del_ret) { - OLAP_LOG_DEBUG("filter delta in schema change: %d, %d", - (*it)->version().first, (*it)->version().second); + VLOG(3) << "filter delta in schema change:" + << (*it)->version().first << "-" << (*it)->version().second; res = sc_procedure->create_init_version(new_segment_group->table()->tablet_id(), new_segment_group->table()->schema_hash(), new_segment_group->version(), @@ -2062,12 +2057,12 @@ OLAPStatus SchemaChangeHandler::_alter_table(SchemaChangeParams* sc_params) { OLAP_GOTO(PROCESS_ALTER_EXIT); } } else if (DEL_PARTIAL_SATISFIED == del_ret) { - OLAP_LOG_DEBUG("filter delta partially in schema change: %d, %d", - (*it)->version().first, (*it)->version().second); + VLOG(3) << "filter delta partially in schema change:" + << (*it)->version().first << "-" << (*it)->version().second; (*it)->set_delete_status(DEL_PARTIAL_SATISFIED); } else { - OLAP_LOG_DEBUG("not filter delta in schema change: %d, %d", - (*it)->version().first, (*it)->version().second); + VLOG(3) << "not filter delta in schema change:" + << (*it)->version().first << "-" << (*it)->version().second; (*it)->set_delete_status(DEL_NOT_SATISFIED); } @@ -2107,10 +2102,8 @@ OLAPStatus SchemaChangeHandler::_alter_table(SchemaChangeParams* sc_params) { goto PROCESS_ALTER_EXIT; } - OLAP_LOG_DEBUG("register new version. [table='%s' version='%d-%d']", - sc_params->new_olap_table->full_name().c_str(), - (*it)->version().first, - (*it)->version().second); + VLOG(3) << "register new version. tablet=" << sc_params->new_olap_table->full_name() + << ", version=" << (*it)->version().first << "-" << (*it)->version().second; } else { OLAP_LOG_WARNING("version already exist, version revert occured. " "[table='%s' version='%d-%d']", @@ -2148,9 +2141,8 @@ OLAPStatus SchemaChangeHandler::_alter_table(SchemaChangeParams* sc_params) { sc_params->ref_olap_table->release_header_lock(); sc_params->new_olap_table->release_push_lock(); - OLAP_LOG_TRACE("succeed to convert a history version. [version='%d-%d']", - (*it)->version().first, - (*it)->version().second); + VLOG(10) << "succeed to convert a history version." + << ", version=" << (*it)->version().first << "-" << (*it)->version().second; // 释放ColumnData vector olap_data_to_be_released(it, it + 1); @@ -2186,8 +2178,8 @@ PROCESS_ALTER_EXIT: ALTER_TABLE_FINISHED, sc_params->ref_olap_table->schema_hash(), -1); - OLAP_LOG_DEBUG("set alter table job status. [status=%d]", - sc_params->ref_olap_table->schema_change_status().status); + VLOG(3) << "set alter table job status. " + << "status=" << sc_params->ref_olap_table->schema_change_status().status; } else { sc_params->ref_olap_table->set_schema_change_status( ALTER_TABLE_FAILED, @@ -2198,8 +2190,8 @@ PROCESS_ALTER_EXIT: ALTER_TABLE_FAILED, sc_params->ref_olap_table->schema_hash(), -1); - OLAP_LOG_DEBUG("set alter table job status. [status=%d]", - sc_params->ref_olap_table->schema_change_status().status); + VLOG(3) << "set alter table job status. " + << "status=" << sc_params->ref_olap_table->schema_change_status().status; } sc_params->ref_olap_table->release_data_sources(&(sc_params->ref_olap_data_arr)); @@ -2238,10 +2230,8 @@ OLAPStatus SchemaChangeHandler::_parse_request(OLAPTablePtr ref_olap_table, } column_mapping->ref_column = column_index; - OLAP_LOG_DEBUG("A column refered to existed column will be added after schema changing." - "[column='%s' ref_column='%s']", - column_name.c_str(), - new_column_schema.referenced_column.c_str()); + VLOG(3) << "A column refered to existed column will be added after schema changing." + << "column=" << column_name << ", ref_column=" << new_column_schema.referenced_column; continue; } @@ -2267,10 +2257,9 @@ OLAPStatus SchemaChangeHandler::_parse_request(OLAPTablePtr ref_olap_table, return res; } - OLAP_LOG_TRACE("A column with default value will be added after schema chaning. " - "[column='%s' default_value='%s']", - column_name.c_str(), - new_column_schema.default_value.c_str()); + VLOG(10) << "A column with default value will be added after schema chaning. " + << "column=" << column_name + << ", default_value=" << new_column_schema.default_value; continue; } @@ -2285,10 +2274,9 @@ OLAPStatus SchemaChangeHandler::_parse_request(OLAPTablePtr ref_olap_table, return res; } - OLAP_LOG_DEBUG("A new schema delta is converted while droping column. " - "Droped column will be assigned as '0' for the older schema. " - "[column='%s']", - column_name.c_str()); + VLOG(3) << "A new schema delta is converted while droping column. " + << "Droped column will be assigned as '0' for the older schema. " + << "column=" << column_name; } // Check if re-aggregation is needed. @@ -2378,8 +2366,8 @@ OLAPStatus SchemaChange::create_init_version( Version version, VersionHash version_hash, SegmentGroup* segment_group) { - OLAP_LOG_DEBUG("begin to create init version. [begin=%d end=%d]", - version.first, version.second); + VLOG(3) << "begin to create init version. " + << "begin=" << version.first << ", end=" << version.second; OLAPTablePtr table; ColumnDataWriter* writer = NULL; @@ -2423,7 +2411,7 @@ OLAPStatus SchemaChange::create_init_version( } } while (0); - OLAP_LOG_DEBUG("create init version end. [res=%d]", res); + VLOG(3) << "create init version end. res=" << res; SAFE_DELETE(writer); return res; } diff --git a/be/src/olap/segment_group.cpp b/be/src/olap/segment_group.cpp index e050d289fc..07ec48d71b 100644 --- a/be/src/olap/segment_group.cpp +++ b/be/src/olap/segment_group.cpp @@ -412,7 +412,7 @@ OLAPStatus SegmentGroup::find_short_key(const RowCursor& key, } } - OLAP_LOG_DEBUG("[seg='%d', offset='%d']", offset.segment, offset.offset); + VLOG(3) << "seg=" << offset.segment << ", offset=" << offset.offset; return _index.get_row_block_position(offset, pos); } @@ -626,9 +626,8 @@ OLAPStatus SegmentGroup::finalize_segment(uint32_t data_segment_size, int64_t nu return res; } - OLAP_LOG_DEBUG("finalize_segment. [file_name='%s' file_length=%d]", - _current_file_handler.file_name().c_str(), - file_length); + VLOG(3) << "finalize_segment. file_name=" << _current_file_handler.file_name() + << ", file_length=" << file_length; if ((res = _current_file_handler.close()) != OLAP_SUCCESS) { OLAP_LOG_WARNING("close file error. [err=%m]"); diff --git a/be/src/olap/segment_reader.cpp b/be/src/olap/segment_reader.cpp index f4b73baf36..74febd7fff 100644 --- a/be/src/olap/segment_reader.cpp +++ b/be/src/olap/segment_reader.cpp @@ -377,14 +377,14 @@ OLAPStatus SegmentReader::_pick_columns() { } OLAPStatus SegmentReader::_pick_delete_row_groups(uint32_t first_block, uint32_t last_block) { - OLAP_LOG_DEBUG("pick for %u to %u for delete_condition", first_block, last_block); + VLOG(3) << "pick for " << first_block << " to " << last_block << " for delete_condition"; if (_delete_handler.empty()) { return OLAP_SUCCESS; } if (DEL_NOT_SATISFIED == _delete_status) { - OLAP_LOG_DEBUG("the segment not satisfy the delete_conditions"); + VLOG(3) << "the segment not satisfy the delete_conditions"; return OLAP_SUCCESS; } @@ -430,11 +430,11 @@ OLAPStatus SegmentReader::_pick_delete_row_groups(uint32_t first_block, uint32_t } } else if (true == del_partial_satisfied) { _include_blocks[j] = DEL_PARTIAL_SATISFIED; - OLAP_LOG_DEBUG("filter block partially: %d", j); + VLOG(3) << "filter block partially: " << j; } else { _include_blocks[j] = DEL_SATISFIED; --_remain_block; - OLAP_LOG_DEBUG("filter block: %d", j); + VLOG(3) << "filter block: " << j; if (j < _block_count - 1) { _stats->rows_del_filtered += _num_rows_in_block; } else { @@ -466,7 +466,7 @@ OLAPStatus SegmentReader::_init_include_blocks(uint32_t first_block, uint32_t la } OLAPStatus SegmentReader::_pick_row_groups(uint32_t first_block, uint32_t last_block) { - OLAP_LOG_DEBUG("pick from %u to %u", first_block, last_block); + VLOG(3) << "pick from " << first_block << " to " << last_block; if (first_block > last_block) { OLAP_LOG_WARNING("invalid block offset. [first_block=%u last_block=%u]", @@ -523,9 +523,9 @@ OLAPStatus SegmentReader::_pick_row_groups(uint32_t first_block, uint32_t last_b } if (_remain_block < MIN_FILTER_BLOCK_NUM) { - OLAP_LOG_DEBUG("bloom filter is ignored for too few block remained. " - "[remain_block=%u const_time=%lu]", - _remain_block, timer.get_elapse_time_us()); + VLOG(3) << "bloom filter is ignored for too few block remained. " + << "remain_block=" << _remain_block + << ", const_time=" << timer.get_elapse_time_us(); return OLAP_SUCCESS; } @@ -562,9 +562,8 @@ OLAPStatus SegmentReader::_pick_row_groups(uint32_t first_block, uint32_t last_b } } - OLAP_LOG_DEBUG("pick row groups finished. [remain_block=%u const_time=%lu]", - _remain_block, timer.get_elapse_time_us()); - + VLOG(3) << "pick row groups finished. remain_block=" << _remain_block + << ", const_time=" << timer.get_elapse_time_us(); return OLAP_SUCCESS; } @@ -729,7 +728,7 @@ OLAPStatus SegmentReader::_load_index(bool is_using_cache) { } } - OLAP_LOG_DEBUG("found index entry count %u", _block_count); + VLOG(3) << "found index entry count: " << _block_count; return OLAP_SUCCESS; } @@ -858,8 +857,9 @@ OLAPStatus SegmentReader::_seek_to_block_directly( PositionProvider position(&_column_indices[cid]->entry(block_id)); if (OLAP_SUCCESS != (res = _column_readers[cid]->seek(&position))) { if (OLAP_ERR_COLUMN_STREAM_EOF == res) { - OLAP_LOG_DEBUG("Stream EOF. [tablet_id=%ld column_id=%u block_id=%lu]", - _table->tablet_id(), _column_readers[cid]->column_unique_id(), block_id); + VLOG(3) << "Stream EOF. tablet_id=" << _table->tablet_id() + << ", column_id=" << _column_readers[cid]->column_unique_id() + << ", block_id=" << block_id; return OLAP_ERR_DATA_EOF; } else { OLAP_LOG_WARNING("fail to seek to block. " @@ -875,7 +875,7 @@ OLAPStatus SegmentReader::_seek_to_block_directly( } OLAPStatus SegmentReader::_reset_readers() { - OLAP_LOG_DEBUG("%lu stream in total.", _streams.size()); + VLOG(3) << _streams.size() << " stream in total."; for (std::map::iterator it = _streams.begin(); it != _streams.end(); ++it) { diff --git a/be/src/olap/segment_writer.cpp b/be/src/olap/segment_writer.cpp index 3dae96908f..d801d6379f 100644 --- a/be/src/olap/segment_writer.cpp +++ b/be/src/olap/segment_writer.cpp @@ -191,9 +191,9 @@ OLAPStatus SegmentWriter::_make_file_header(ColumnDataHeaderMessage* file_header data_length += stream->get_stream_length(); } - OLAP_LOG_DEBUG("stream id=%u, type=%d, length=%ld", - it->first.unique_column_id(), it->first.kind(), - stream->get_stream_length()); + VLOG(3) << "stream id=" << it->first.unique_column_id() + << ", type=" << it->first.kind() + << ", length=" << stream->get_stream_length(); } file_header->set_index_length(index_length); @@ -241,10 +241,8 @@ OLAPStatus SegmentWriter::finalize(uint32_t* segment_file_size) { // 输出没有被掐掉的流 if (!stream->is_suppressed()) { checksum = stream->crc32(checksum); - OLAP_LOG_DEBUG("stream id = %u, type = %d", - it->first.unique_column_id(), - it->first.kind()); - + VLOG(3) << "stream id=" << it->first.unique_column_id() + << ", type=" << it->first.kind(); res = stream->write_to_file( &file_handle, _write_mbytes_per_sec); if (OLAP_SUCCESS != res) { diff --git a/be/src/olap/stream_index_writer.cpp b/be/src/olap/stream_index_writer.cpp index 4231a6ca35..6912deeb64 100755 --- a/be/src/olap/stream_index_writer.cpp +++ b/be/src/olap/stream_index_writer.cpp @@ -164,10 +164,9 @@ OLAPStatus StreamIndexWriter::write_to_buffer(char* buffer, size_t buffer_size) } _header.block_count = _index_to_write.size(); - OLAP_LOG_DEBUG("header info: pos %d, stat %d", - _header.position_format, - _header.statistic_format); - OLAP_LOG_DEBUG("entry_size: %d", entry_size); + VLOG(3) << "header info. pos: " << _header.position_format + << ", stat:" << _header.statistic_format + << ", entry_size:" << entry_size; memcpy(buffer, reinterpret_cast(&_header), sizeof(_header)); // set offset, write data char* write_offset = buffer + sizeof(_header); diff --git a/be/src/olap/utils.cpp b/be/src/olap/utils.cpp index 80b6ddfa24..14ca9e3c0b 100644 --- a/be/src/olap/utils.cpp +++ b/be/src/olap/utils.cpp @@ -284,9 +284,9 @@ OLAPStatus olap_compress(const char* src_buf, return OLAP_ERR_COMPRESS_ERROR; } else if (*written_len > dest_len) { - OLAP_LOG_DEBUG("buffer overflow when compressing. [dest_len=%lu written_len=%lu]", - dest_len, - *written_len); + VLOG(3) << "buffer overflow when compressing. " + << "dest_len=" << dest_len + << ", written_len=" << *written_len; return OLAP_ERR_BUFFER_OVERFLOW; } @@ -310,9 +310,9 @@ OLAPStatus olap_compress(const char* src_buf, return OLAP_ERR_COMPRESS_ERROR; } else if (*written_len > dest_len) { - OLAP_LOG_DEBUG("buffer overflow when compressing. [dest_len=%lu written_len=%lu]", - dest_len, - *written_len); + VLOG(3) << "buffer overflow when compressing. " + << ", dest_len=" << dest_len + << ", written_len=" << *written_len; return OLAP_ERR_BUFFER_OVERFLOW; } @@ -323,13 +323,10 @@ OLAPStatus olap_compress(const char* src_buf, int lz4_res = LZ4_compress_default(src_buf, dest_buf, src_len, dest_len); *written_len = lz4_res; if (0 == lz4_res) { - OLAP_LOG_DEBUG("compress failed." - "[src_len=%lu; dest_len=%lu; written_len=%lu; lz4_res=%d]", - src_len, - dest_len, - *written_len, - lz4_res); - + VLOG(3) << "compress failed. src_len=" << src_len + << ", dest_len=" << dest_len + << ", written_len=" << *written_len + << ", lz4_res=" << lz4_res; return OLAP_ERR_BUFFER_OVERFLOW; } break; @@ -1069,8 +1066,7 @@ OLAPStatus move_to_trash(const boost::filesystem::path& schema_hash_root, } // 3. remove file to trash - OLAP_LOG_DEBUG("move file to trash. [%s -> %s]", - old_file_path.c_str(), new_file_path.c_str()); + VLOG(3) << "move file to trash. " << old_file_path << " -> " << new_file_path; if (rename(old_file_path.c_str(), new_file_path.c_str()) < 0) { OLAP_LOG_WARNING("move file to trash failed. [file=%s target='%s' err='%m']", old_file_path.c_str(), new_file_path.c_str()); @@ -1109,7 +1105,7 @@ OLAPStatus Mutex::lock() { OLAPStatus Mutex::trylock() { if (0 != pthread_mutex_trylock(&_lock)) { - OLAP_LOG_DEBUG("failed to got the mutex lock. [err='%m']"); + VLOG(3) << "failed to got the mutex lock. err=" << strerror(errno); return OLAP_ERR_RWLOCK_ERROR; } @@ -1158,7 +1154,7 @@ OLAPStatus RWMutex::rdlock() { OLAPStatus RWMutex::tryrdlock() { if (0 != pthread_rwlock_tryrdlock(&_lock)) { - OLAP_LOG_DEBUG("failed to got the rwlock rdlock. [err='%m']"); + VLOG(3) << "failed to got the rwlock rdlock. err=" << strerror(errno); return OLAP_ERR_RWLOCK_ERROR; } @@ -1167,7 +1163,7 @@ OLAPStatus RWMutex::tryrdlock() { OLAPStatus RWMutex::trywrlock() { if (0 != pthread_rwlock_trywrlock(&_lock)) { - OLAP_LOG_DEBUG("failed to got the rwlock rdlock. [err='%m']"); + VLOG(3) << "failed to got the rwlock rdlock. err=" << strerror(errno); return OLAP_ERR_RWLOCK_ERROR; } @@ -1523,12 +1519,12 @@ OLAPStatus dir_walk(const string& root, } if (S_ISDIR(stat_data.st_mode)) { - OLAP_LOG_DEBUG("find dir. [d_name='%s']", direntp->d_name); + VLOG(3) << "find dir. d_name=" << direntp->d_name; if (NULL != dirs) { dirs->insert(direntp->d_name); } } else { - OLAP_LOG_DEBUG("find file. [d_name='%s']", direntp->d_name); + VLOG(3) << "find file. d_name=" << direntp->d_name; if (NULL != files) { files->insert(direntp->d_name); } diff --git a/be/src/olap/utils.h b/be/src/olap/utils.h index 408a4b6381..b2f0290dba 100644 --- a/be/src/olap/utils.h +++ b/be/src/olap/utils.h @@ -514,13 +514,7 @@ bool valid_datetime(const std::string& value_str); // Log define for non-network usage // 屏蔽DEBUG和TRACE日志以满足性能测试需求 -#define OLAP_LOG_DEBUG(fmt, arg...) OLAP_VLOG_WRITE(3, fmt, ##arg) -#define OLAP_LOG_TRACE(fmt, arg...) OLAP_VLOG_WRITE(20, fmt, ##arg) - #define OLAP_LOG_WARNING(fmt, arg...) OLAP_LOG_WRITE(WARNING, fmt, ##arg) - -#define OLAP_LOG_DEBUG_SOCK(fmt, arg...) OLAP_LOG_WRITE(INFO, fmt, ##arg) -#define OLAP_LOG_TRACE_SOCK(fmt, arg...) OLAP_LOG_WRITE(INFO, fmt, ##arg) #define OLAP_LOG_NOTICE_DIRECT_SOCK(fmt, arg...) OLAP_LOG_WRITE(INFO, fmt, ##arg) #define OLAP_LOG_WARNING_SOCK(fmt, arg...) OLAP_LOG_WRITE(WARNING, fmt, ##arg) #define OLAP_LOG_SETBASIC(type, fmt, arg...)