From d15d97d748e0328a4f3cf6d642723a2642c0e896 Mon Sep 17 00:00:00 2001
From: xufei <xufeixw@mail.ustc.edu.cn>
Date: Wed, 14 Jun 2023 13:37:07 +0800
Subject: [PATCH] add more log when learner read meet error (#7655)

close pingcap/tiflash#7647
---
 .../Coprocessor/DAGStorageInterpreter.cpp     | 23 ++++++++++++++-----
 .../src/Storages/Transaction/TiKVKeyValue.cpp |  6 +++++
 dbms/src/Storages/Transaction/TiKVKeyValue.h  |  2 ++
 3 files changed, 25 insertions(+), 6 deletions(-)

diff --git a/dbms/src/Flash/Coprocessor/DAGStorageInterpreter.cpp b/dbms/src/Flash/Coprocessor/DAGStorageInterpreter.cpp
index f5b5cc9c73e..107507ddcd1 100644
--- a/dbms/src/Flash/Coprocessor/DAGStorageInterpreter.cpp
+++ b/dbms/src/Flash/Coprocessor/DAGStorageInterpreter.cpp
@@ -96,7 +96,8 @@ MakeRegionQueryInfos(
     const std::unordered_set<RegionID> & region_force_retry,
     TMTContext & tmt,
     MvccQueryInfo & mvcc_info,
-    bool batch_cop [[maybe_unused]])
+    bool batch_cop [[maybe_unused]],
+    const LoggerPtr & log)
 {
     mvcc_info.regions_query_info.clear();
     RegionRetryList region_need_retry;
@@ -108,7 +109,7 @@ MakeRegionQueryInfos(
             if (r.key_ranges.empty())
             {
                 throw TiFlashException(
-                    fmt::format("Income key ranges is empty for region: {}", r.region_id),
+                    fmt::format("Income key ranges is empty for region: {}, version {}, conf_version {}", r.region_id, r.region_version, r.region_conf_version),
                     Errors::Coprocessor::BadRequest);
             }
             if (region_force_retry.count(id))
@@ -143,16 +144,24 @@ MakeRegionQueryInfos(
                     {
                         throw TiFlashException(
                             fmt::format(
-                                "Income key ranges is illegal for region: {}, table id in key range is {}, table id in region is {}",
+                                "Income key ranges is illegal for region: {}, version {}, conf_version {}, table id in key range is {}, table id in region is {}",
                                 r.region_id,
+                                r.region_version,
+                                r.region_conf_version,
                                 table_id_in_range,
                                 physical_table_id),
                             Errors::Coprocessor::BadRequest);
                     }
                     if (p.first->compare(*info.range_in_table.first) < 0 || p.second->compare(*info.range_in_table.second) > 0)
+                    {
+                        LOG_WARNING(log, fmt::format("Income key ranges is illegal for region: {}, version {}, conf_version {}, request range: [{}, {}), region range: [{}, {})", r.region_id, r.region_version, r.region_conf_version, p.first->toDebugString(), p.second->toDebugString(), info.range_in_table.first->toDebugString(), info.range_in_table.second->toDebugString()));
                         throw TiFlashException(
-                            fmt::format("Income key ranges is illegal for region: {}", r.region_id),
+                            fmt::format("Income key ranges is illegal for region: {}, version {}, conf_version {}",
+                                        r.region_id,
+                                        r.region_version,
+                                        r.region_conf_version),
                             Errors::Coprocessor::BadRequest);
+                    }
                 }
                 info.required_handle_ranges = r.key_ranges;
                 info.bypass_lock_ts = r.bypass_lock_ts;
@@ -687,7 +696,8 @@ LearnerReadSnapshot DAGStorageInterpreter::doCopLearnerRead()
         {},
         tmt,
         *mvcc_query_info,
-        false);
+        false,
+        log);
 
     if (info_retry)
         throw RegionException({info_retry->begin()->get().region_id}, status);
@@ -717,7 +727,8 @@ LearnerReadSnapshot DAGStorageInterpreter::doBatchCopLearnerRead()
                 force_retry,
                 tmt,
                 *mvcc_query_info,
-                true);
+                true,
+                log);
             UNUSED(status);
 
             if (retry)
diff --git a/dbms/src/Storages/Transaction/TiKVKeyValue.cpp b/dbms/src/Storages/Transaction/TiKVKeyValue.cpp
index 288246e75c0..52fba369f34 100644
--- a/dbms/src/Storages/Transaction/TiKVKeyValue.cpp
+++ b/dbms/src/Storages/Transaction/TiKVKeyValue.cpp
@@ -27,6 +27,12 @@ std::string_view DecodedTiKVKey::getUserKey() const
     return TiKVKeyspaceID::removeKeyspaceID(std::string_view(data(), size()));
 }
 
+std::string DecodedTiKVKey::toDebugString() const
+{
+    const auto & user_key = getUserKey();
+    return Redact::keyToDebugString(user_key.data(), user_key.size());
+}
+
 std::string DecodedTiKVKey::makeKeyspacePrefix(KeyspaceID keyspace_id)
 {
     return TiKVKeyspaceID::makeKeyspacePrefix(keyspace_id);
diff --git a/dbms/src/Storages/Transaction/TiKVKeyValue.h b/dbms/src/Storages/Transaction/TiKVKeyValue.h
index 86a07621912..21b9e18bc66 100644
--- a/dbms/src/Storages/Transaction/TiKVKeyValue.h
+++ b/dbms/src/Storages/Transaction/TiKVKeyValue.h
@@ -103,6 +103,8 @@ struct DecodedTiKVKey : std::string
 
     KeyspaceID getKeyspaceID() const;
     std::string_view getUserKey() const;
+    // Format as a hex string for debugging. The value will be converted to '?' if redact-log is on
+    std::string toDebugString() const;
     static std::string makeKeyspacePrefix(KeyspaceID keyspace_id);
 };