This is an automated email from the ASF dual-hosted git repository.
liaoxin pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/doris.git
The following commit(s) were added to refs/heads/master by this push:
new f7d874650fc [opt](load) add some metrics for flush memtable (#55852)
f7d874650fc is described below
commit f7d874650fc3ec201253e4e3bae298c51358010b
Author: Xin Liao <[email protected]>
AuthorDate: Wed Sep 10 17:29:29 2025 +0800
[opt](load) add some metrics for flush memtable (#55852)
---
be/src/io/fs/s3_file_writer.cpp | 16 ++++++--
be/src/olap/memtable_writer.cpp | 9 ++---
be/src/olap/rowset/beta_rowset_writer.cpp | 12 ++++++
be/src/olap/rowset/segment_creator.cpp | 62 ++++++++++++++++++++++++++-----
4 files changed, 81 insertions(+), 18 deletions(-)
diff --git a/be/src/io/fs/s3_file_writer.cpp b/be/src/io/fs/s3_file_writer.cpp
index ff77ab2fe5e..309d4392f6d 100644
--- a/be/src/io/fs/s3_file_writer.cpp
+++ b/be/src/io/fs/s3_file_writer.cpp
@@ -40,6 +40,7 @@
#include "io/fs/s3_obj_storage_client.h"
#include "runtime/exec_env.h"
#include "util/s3_util.h"
+#include "util/stopwatch.hpp"
namespace doris::io {
#include "common/compile_check_begin.h"
@@ -440,8 +441,9 @@ Status
S3FileWriter::_set_upload_to_remote_less_than_buffer_size() {
}
void S3FileWriter::_put_object(UploadFileBuffer& buf) {
- LOG(INFO) << "put_object " << _obj_storage_path_opts.path.native()
- << " size=" << _bytes_appended;
+ MonotonicStopWatch timer;
+ timer.start();
+
if (state() == State::CLOSED) {
DCHECK(state() != State::CLOSED)
<< "state=" << (int)state() << " path=" <<
_obj_storage_path_opts.path.native();
@@ -457,9 +459,12 @@ void S3FileWriter::_put_object(UploadFileBuffer& buf) {
}
TEST_SYNC_POINT_RETURN_WITH_VOID("S3FileWriter::_put_object", this, &buf);
auto resp = client->put_object(_obj_storage_path_opts,
buf.get_string_view_data());
+ timer.stop();
+
if (resp.status.code != ErrorCode::OK) {
- LOG_WARNING("failed to put object, put object failed because {}, file
path {}",
- resp.status.msg, _obj_storage_path_opts.path.native());
+ LOG_WARNING("failed to put object, put object failed because {}, file
path {}, time={}ms",
+ resp.status.msg, _obj_storage_path_opts.path.native(),
+ timer.elapsed_time_milliseconds());
buf.set_status({resp.status.code, std::move(resp.status.msg)});
return;
}
@@ -471,6 +476,9 @@ void S3FileWriter::_put_object(UploadFileBuffer& buf) {
return;
}
+ LOG(INFO) << "put_object " << _obj_storage_path_opts.path.native()
+ << " size=" << _bytes_appended << " time=" <<
timer.elapsed_time_milliseconds()
+ << "ms";
s3_file_created_total << 1;
}
diff --git a/be/src/olap/memtable_writer.cpp b/be/src/olap/memtable_writer.cpp
index a9127b03b55..82349d2e0ee 100644
--- a/be/src/olap/memtable_writer.cpp
+++ b/be/src/olap/memtable_writer.cpp
@@ -266,13 +266,12 @@ Status MemTableWriter::_do_close_wait() {
return Status::InternalError("rows number written by delta writer
dosen't match");
}
- // const FlushStatistic& stat = _flush_token->get_stats();
// print slow log if wait more than 1s
- /*if (_wait_flush_timer->elapsed_time() > 1000UL * 1000 * 1000) {
- LOG(INFO) << "close delta writer for tablet: " << req.tablet_id
+ if (_wait_flush_time_ns > 1000UL * 1000 * 1000) {
+ LOG(INFO) << "close delta writer for tablet: " << _req.tablet_id
<< ", load id: " << print_id(_req.load_id) << ", wait close
for "
- << _wait_flush_timer->elapsed_time() << "(ns), stats: " <<
stat;
- }*/
+ << _wait_flush_time_ns << "(ns), stats: " <<
_flush_token->get_stats();
+ }
return Status::OK();
}
diff --git a/be/src/olap/rowset/beta_rowset_writer.cpp
b/be/src/olap/rowset/beta_rowset_writer.cpp
index a44b0436e93..d80a63e4285 100644
--- a/be/src/olap/rowset/beta_rowset_writer.cpp
+++ b/be/src/olap/rowset/beta_rowset_writer.cpp
@@ -54,6 +54,7 @@
#include "util/debug_points.h"
#include "util/pretty_printer.h"
#include "util/slice.h"
+#include "util/stopwatch.hpp"
#include "util/time.h"
#include "vec/columns/column.h"
#include "vec/common/schema_util.h"
@@ -1089,7 +1090,18 @@ Status BaseBetaRowsetWriter::add_segment(uint32_t
segment_id, const SegmentStati
// ensure that the segment file writing is complete
auto* file_writer = _seg_files.get(segment_id);
if (file_writer && file_writer->state() !=
io::FileWriter::State::CLOSED) {
+ MonotonicStopWatch close_timer;
+ close_timer.start();
RETURN_IF_ERROR(file_writer->close());
+ close_timer.stop();
+
+ auto close_time_ms = close_timer.elapsed_time_milliseconds();
+ if (close_time_ms > 1000) {
+ LOG(INFO) << "file_writer->close() took " << close_time_ms
+ << "ms for segment_id=" << segment_id
+ << ", tablet_id=" << _context.tablet_id
+ << ", rowset_id=" << _context.rowset_id;
+ }
}
RETURN_IF_ERROR(_generate_delete_bitmap(segment_id));
}
diff --git a/be/src/olap/rowset/segment_creator.cpp
b/be/src/olap/rowset/segment_creator.cpp
index 989ccf787f0..489f24728cc 100644
--- a/be/src/olap/rowset/segment_creator.cpp
+++ b/be/src/olap/rowset/segment_creator.cpp
@@ -38,6 +38,7 @@
#include "olap/tablet_schema.h"
#include "olap/utils.h"
#include "util/pretty_printer.h"
+#include "util/stopwatch.hpp"
#include "vec/columns/column.h"
#include "vec/columns/column_nullable.h"
#include "vec/columns/column_string.h"
@@ -208,6 +209,9 @@ Status SegmentFlusher::_create_segment_writer(
Status SegmentFlusher::_flush_segment_writer(
std::unique_ptr<segment_v2::VerticalSegmentWriter>& writer, int64_t*
flush_size) {
+ MonotonicStopWatch total_timer;
+ total_timer.start();
+
uint32_t row_num = writer->num_rows_written();
_num_rows_updated += writer->num_rows_updated();
_num_rows_deleted += writer->num_rows_deleted();
@@ -217,15 +221,23 @@ Status SegmentFlusher::_flush_segment_writer(
if (row_num == 0) {
return Status::OK();
}
+
+ MonotonicStopWatch finalize_timer;
+ finalize_timer.start();
uint64_t segment_file_size;
uint64_t common_index_size;
Status s = writer->finalize(&segment_file_size, &common_index_size);
+ finalize_timer.stop();
+
if (!s.ok()) {
return Status::Error(s.code(), "failed to finalize segment: {}",
s.to_string());
}
+ MonotonicStopWatch inverted_index_timer;
+ inverted_index_timer.start();
int64_t inverted_index_file_size = 0;
RETURN_IF_ERROR(writer->close_inverted_index(&inverted_index_file_size));
+ inverted_index_timer.stop();
VLOG_DEBUG << "tablet_id:" << _context.tablet_id
<< " flushing filename: " << writer->data_dir_path()
@@ -244,15 +256,25 @@ Status SegmentFlusher::_flush_segment_writer(
segstat.data_size = segment_file_size;
segstat.index_size = inverted_index_file_size;
segstat.key_bounds = key_bounds;
- LOG(INFO) << "tablet_id:" << _context.tablet_id
- << ", flushing rowset_dir: " << _context.tablet_path
- << ", rowset_id:" << _context.rowset_id
- << ", data size:" <<
PrettyPrinter::print_bytes(segstat.data_size)
- << ", index size:" <<
PrettyPrinter::print_bytes(segstat.index_size);
writer.reset();
+ MonotonicStopWatch collector_timer;
+ collector_timer.start();
RETURN_IF_ERROR(_context.segment_collector->add(segment_id, segstat));
+ collector_timer.stop();
+
+ total_timer.stop();
+
+ LOG(INFO) << "tablet_id:" << _context.tablet_id
+ << ", flushing rowset_dir: " << _context.tablet_path
+ << ", rowset_id:" << _context.rowset_id
+ << ", data size:" <<
PrettyPrinter::print_bytes(segstat.data_size)
+ << ", index size:" <<
PrettyPrinter::print_bytes(segstat.index_size)
+ << ", timing breakdown: total=" <<
total_timer.elapsed_time_milliseconds() << "ms"
+ << ", finalize=" << finalize_timer.elapsed_time_milliseconds()
<< "ms"
+ << ", inverted_index=" <<
inverted_index_timer.elapsed_time_milliseconds() << "ms"
+ << ", collector=" << collector_timer.elapsed_time_milliseconds()
<< "ms";
if (flush_size) {
*flush_size = segment_file_size;
@@ -262,6 +284,9 @@ Status SegmentFlusher::_flush_segment_writer(
Status
SegmentFlusher::_flush_segment_writer(std::unique_ptr<segment_v2::SegmentWriter>&
writer,
int64_t* flush_size) {
+ MonotonicStopWatch total_timer;
+ total_timer.start();
+
uint32_t row_num = writer->num_rows_written();
_num_rows_updated += writer->num_rows_updated();
_num_rows_deleted += writer->num_rows_deleted();
@@ -271,15 +296,23 @@ Status
SegmentFlusher::_flush_segment_writer(std::unique_ptr<segment_v2::Segment
if (row_num == 0) {
return Status::OK();
}
+
+ MonotonicStopWatch finalize_timer;
+ finalize_timer.start();
uint64_t segment_file_size;
uint64_t common_index_size;
Status s = writer->finalize(&segment_file_size, &common_index_size);
+ finalize_timer.stop();
+
if (!s.ok()) {
return Status::Error(s.code(), "failed to finalize segment: {}",
s.to_string());
}
+ MonotonicStopWatch inverted_index_timer;
+ inverted_index_timer.start();
int64_t inverted_index_file_size = 0;
RETURN_IF_ERROR(writer->close_inverted_index(&inverted_index_file_size));
+ inverted_index_timer.stop();
VLOG_DEBUG << "tablet_id:" << _context.tablet_id
<< " flushing rowset_dir: " << _context.tablet_path
@@ -298,14 +331,25 @@ Status
SegmentFlusher::_flush_segment_writer(std::unique_ptr<segment_v2::Segment
segstat.data_size = segment_file_size;
segstat.index_size = inverted_index_file_size;
segstat.key_bounds = key_bounds;
- LOG(INFO) << "tablet_id:" << _context.tablet_id
- << ", flushing rowset_dir: " << _context.tablet_path
- << ", rowset_id:" << _context.rowset_id << ", data size:" <<
segstat.data_size
- << ", index size:" << segstat.index_size;
writer.reset();
+ MonotonicStopWatch collector_timer;
+ collector_timer.start();
RETURN_IF_ERROR(_context.segment_collector->add(segment_id, segstat));
+ collector_timer.stop();
+
+ total_timer.stop();
+
+ LOG(INFO) << "tablet_id:" << _context.tablet_id
+ << ", flushing rowset_dir: " << _context.tablet_path
+ << ", rowset_id:" << _context.rowset_id
+ << ", data size:" <<
PrettyPrinter::print_bytes(segstat.data_size)
+ << ", index size:" <<
PrettyPrinter::print_bytes(segstat.index_size)
+ << ", timing breakdown: total=" <<
total_timer.elapsed_time_milliseconds() << "ms"
+ << ", finalize=" << finalize_timer.elapsed_time_milliseconds()
<< "ms"
+ << ", inverted_index=" <<
inverted_index_timer.elapsed_time_milliseconds() << "ms"
+ << ", collector=" << collector_timer.elapsed_time_milliseconds()
<< "ms";
if (flush_size) {
*flush_size = segment_file_size;
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
