diff --git a/dbms/src/Common/TiFlashMetrics.h b/dbms/src/Common/TiFlashMetrics.h index d36f55935de..fcf5d582097 100644 --- a/dbms/src/Common/TiFlashMetrics.h +++ b/dbms/src/Common/TiFlashMetrics.h @@ -756,7 +756,8 @@ namespace DB M(tiflash_read_thread_internal_us, \ "Durations of read thread internal components", \ Histogram, \ - F(type_block_queue_pop_latency, {{"type", "block_queue_pop_latency"}}, ExpBuckets{1, 2, 20})) + F(type_block_queue_pop_latency, {{"type", "block_queue_pop_latency"}}, ExpBuckets{1, 2, 20}), \ + F(type_schedule_one_round, {{"type", "schedule_one_round"}}, ExpBuckets{1, 2, 20})) /// Buckets with boundaries [start * base^0, start * base^1, ..., start * base^(size-1)] diff --git a/dbms/src/Storages/DeltaMerge/ReadThread/SegmentReadTaskScheduler.cpp b/dbms/src/Storages/DeltaMerge/ReadThread/SegmentReadTaskScheduler.cpp index 58aedc77572..4ff80158a0e 100644 --- a/dbms/src/Storages/DeltaMerge/ReadThread/SegmentReadTaskScheduler.cpp +++ b/dbms/src/Storages/DeltaMerge/ReadThread/SegmentReadTaskScheduler.cpp @@ -244,6 +244,7 @@ bool SegmentReadTaskScheduler::isStop() const std::tuple SegmentReadTaskScheduler::scheduleOneRound() { + Stopwatch sw; UInt64 erased_pool_count = 0; UInt64 sched_null_count = 0; UInt64 sched_succ_count = 0; @@ -276,6 +277,7 @@ std::tuple SegmentReadTaskScheduler::scheduleOneRound() ++sched_succ_count; SegmentReaderPoolManager::instance().addTask(std::move(merged_task)); } + GET_METRIC(tiflash_read_thread_internal_us, type_schedule_one_round).Observe(sw.elapsed() / 1000.0); return std::make_tuple(erased_pool_count, sched_null_count, sched_succ_count); } diff --git a/dbms/src/Storages/DeltaMerge/SegmentReadTaskPool.cpp b/dbms/src/Storages/DeltaMerge/SegmentReadTaskPool.cpp index 492c9f65f69..9e8407d3dfa 100644 --- a/dbms/src/Storages/DeltaMerge/SegmentReadTaskPool.cpp +++ b/dbms/src/Storages/DeltaMerge/SegmentReadTaskPool.cpp @@ -263,6 +263,7 @@ void SegmentReadTaskPool::finishSegment(const SegmentPtr & seg) if (pool_finished) { q.finish(); + LOG_INFO(log, "pool_id={} finished", pool_id); } } diff --git a/dbms/src/Storages/DeltaMerge/SegmentReadTaskPool.h b/dbms/src/Storages/DeltaMerge/SegmentReadTaskPool.h index 55695abb5bd..2f17c91febb 100644 --- a/dbms/src/Storages/DeltaMerge/SegmentReadTaskPool.h +++ b/dbms/src/Storages/DeltaMerge/SegmentReadTaskPool.h @@ -159,12 +159,12 @@ class SegmentReadTaskPool : private boost::noncopyable auto total_count = blk_stat.totalCount(); auto total_bytes = blk_stat.totalBytes(); auto blk_avg_bytes = total_count > 0 ? total_bytes / total_count : 0; - auto approximate_max_pending_block_bytes = blk_avg_bytes * max_queue_size; + auto approx_max_pending_block_bytes = blk_avg_bytes * max_queue_size; auto total_rows = blk_stat.totalRows(); LOG_INFO( log, "Done. pool_id={} table_id={} pop={} pop_empty={} pop_empty_ratio={} " - "max_queue_size={} blk_avg_bytes={} approximate_max_pending_block_bytes={:.2f}MB " + "max_queue_size={} blk_avg_bytes={} approx_max_pending_block_bytes={:.2f}MB " "total_count={} total_bytes={:.2f}MB total_rows={} avg_block_rows={} avg_rows_bytes={}B", pool_id, physical_table_id, @@ -173,7 +173,7 @@ class SegmentReadTaskPool : private boost::noncopyable pop_empty_ratio, max_queue_size, blk_avg_bytes, - approximate_max_pending_block_bytes / 1024.0 / 1024.0, + approx_max_pending_block_bytes / 1024.0 / 1024.0, total_count, total_bytes / 1024.0 / 1024.0, total_rows,