From 3d625b4fd2092ceda7a9c8735dac35647e6ec9c0 Mon Sep 17 00:00:00 2001
From: JaySon-Huang <tshent@qq.com>
Date: Tue, 7 May 2024 16:42:47 +0800
Subject: [PATCH] cherry-pick #8963 for some logging refine

---
 .../Storages/DeltaMerge/DeltaMergeStore.cpp   | 31 +++++++++----------
 .../Storages/DeltaMerge/SegmentReadTaskPool.h |  4 +--
 dbms/src/Storages/StorageDeltaMerge.cpp       |  2 --
 3 files changed, 16 insertions(+), 21 deletions(-)

diff --git a/dbms/src/Storages/DeltaMerge/DeltaMergeStore.cpp b/dbms/src/Storages/DeltaMerge/DeltaMergeStore.cpp
index 306750dbd70..2409e0df6a6 100644
--- a/dbms/src/Storages/DeltaMerge/DeltaMergeStore.cpp
+++ b/dbms/src/Storages/DeltaMerge/DeltaMergeStore.cpp
@@ -1174,15 +1174,6 @@ BlockInputStreams DeltaMergeStore::read(
         /*try_split_task =*/!enable_read_thread);
     auto log_tracing_id = getLogTracingId(*dm_context);
     auto tracing_logger = log->getChild(log_tracing_id);
-    LOG_INFO(
-        tracing_logger,
-        "Read create segment snapshot done, keep_order={} dt_enable_read_thread={} enable_read_thread={} "
-        "is_fast_scan={} is_push_down_filter_empty={}",
-        keep_order,
-        db_context.getSettingsRef().dt_enable_read_thread,
-        enable_read_thread,
-        is_fast_scan,
-        filter == nullptr || filter->before_where == nullptr);
 
     auto after_segment_read = [&](const DMContextPtr & dm_context_, const SegmentPtr & segment_) {
         // TODO: Update the tracing_id before checkSegmentUpdate?
@@ -1242,7 +1233,13 @@ BlockInputStreams DeltaMergeStore::read(
     }
     LOG_INFO(
         tracing_logger,
-        "Read create stream done, pool_id={} num_streams={}",
+        "Read create stream done, keep_order={} dt_enable_read_thread={} enable_read_thread={} "
+        "is_fast_scan={} is_push_down_filter_empty={} pool_id={} num_streams={}",
+        keep_order,
+        db_context.getSettingsRef().dt_enable_read_thread,
+        enable_read_thread,
+        is_fast_scan,
+        filter == nullptr || filter->before_where == nullptr,
         read_task_pool->pool_id,
         final_num_stream);
 
@@ -1285,12 +1282,6 @@ void DeltaMergeStore::read(
         /*try_split_task =*/!enable_read_thread);
     auto log_tracing_id = getLogTracingId(*dm_context);
     auto tracing_logger = log->getChild(log_tracing_id);
-    LOG_INFO(
-        tracing_logger,
-        "Read create segment snapshot done, keep_order={} dt_enable_read_thread={} enable_read_thread={}",
-        keep_order,
-        db_context.getSettingsRef().dt_enable_read_thread,
-        enable_read_thread);
 
     auto after_segment_read = [&](const DMContextPtr & dm_context_, const SegmentPtr & segment_) {
         // TODO: Update the tracing_id before checkSegmentUpdate?
@@ -1360,7 +1351,13 @@ void DeltaMergeStore::read(
 
     LOG_INFO(
         tracing_logger,
-        "Read create PipelineExec done, pool_id={} num_streams={}",
+        "Read create PipelineExec done, keep_order={} dt_enable_read_thread={} enable_read_thread={} "
+        "is_fast_scan={} is_push_down_filter_empty={} pool_id={} num_streams={}",
+        keep_order,
+        db_context.getSettingsRef().dt_enable_read_thread,
+        enable_read_thread,
+        is_fast_scan,
+        filter == nullptr || filter->before_where == nullptr,
         read_task_pool->pool_id,
         final_num_stream);
 }
diff --git a/dbms/src/Storages/DeltaMerge/SegmentReadTaskPool.h b/dbms/src/Storages/DeltaMerge/SegmentReadTaskPool.h
index 41c016375ff..b5268a750f4 100644
--- a/dbms/src/Storages/DeltaMerge/SegmentReadTaskPool.h
+++ b/dbms/src/Storages/DeltaMerge/SegmentReadTaskPool.h
@@ -158,7 +158,7 @@ class SegmentReadTaskPool : private boost::noncopyable
         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 total_rows = blk_stat.totalRows();
-        LOG_DEBUG(
+        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 "
@@ -297,4 +297,4 @@ struct fmt::formatter<DB::DM::SegmentReadTaskPtr>
             t->segment->segmentEpoch(),
             t->read_snapshot->delta->getDeltaIndexEpoch());
     }
-};
\ No newline at end of file
+};
diff --git a/dbms/src/Storages/StorageDeltaMerge.cpp b/dbms/src/Storages/StorageDeltaMerge.cpp
index c0f743c5599..8056f4cca36 100644
--- a/dbms/src/Storages/StorageDeltaMerge.cpp
+++ b/dbms/src/Storages/StorageDeltaMerge.cpp
@@ -675,8 +675,6 @@ DM::RowKeyRanges StorageDeltaMerge::parseMvccQueryInfo(
     const String & req_id,
     const LoggerPtr & tracing_logger)
 {
-    LOG_DEBUG(tracing_logger, "Read with tso: {}", mvcc_query_info.read_tso);
-
     auto keyspace_id = getTableInfo().getKeyspaceID();
     checkReadTso(mvcc_query_info.read_tso, context, req_id, keyspace_id);