Raft: Revert the cpp logging changes from #10515 (#10541)

close #10540

Signed-off-by: JaySon-Huang <[email protected]>

Author: JaySon-Huang

dbms/src/Common/TiFlashMetrics.h

@@ -580,9 +580,6 @@ static_assert(RAFT_REGION_BIG_WRITE_THRES * 4 < RAFT_REGION_BIG_WRITE_MAX, "Inva
       F(type_key_not_in_region, {{"type", "key_not_in_region"}}),                                                                   \
       F(type_tikv_server_issue, {{"type", "tikv_server_issue"}}),                                                                   \
       F(type_tikv_lock, {{"type", "tikv_lock"}}),                                                                                   \
-      F(type_server_is_busy, {{"type", "server_is_busy"}}),                                                                         \
-      F(type_stale_command, {{"type", "stale_command"}}),                                                                           \
-      F(type_store_not_match, {{"type", "store_not_match"}}),                                                                       \
       F(type_other, {{"type", "other"}}))                                                                                           \
     /* required by DBaaS */                                                                                                         \
     M(tiflash_server_info,                                                                                                          \

dbms/src/Debug/ReadIndexStressTest.cpp

@@ -38,7 +38,6 @@ static const std::map<std::string, ReadIndexStressTest::TestType> TestName2Type
 
 ReadIndexStressTest::ReadIndexStressTest(const TMTContext & tmt_)
     : tmt(tmt_)
-    , logger(Logger::get("ReadIndexStressTest"))
 {
     MockStressTestCfg::enable = true;
     LOG_WARNING(logger, "enable MockStressTest");

dbms/src/Debug/ReadIndexStressTest.h

@@ -57,7 +57,7 @@ class ReadIndexStressTest
 
 private:
     const TMTContext & tmt;
-    LoggerPtr logger;
+    Poco::Logger * logger{&Poco::Logger::get("ReadIndexStressTest")};
 };
 
 

dbms/src/Storages/KVStore/FFI/ProxyFFI.cpp

@@ -51,6 +51,8 @@ const std::string ColumnFamilyName::Lock = "lock";
 const std::string ColumnFamilyName::Default = "default";
 const std::string ColumnFamilyName::Write = "write";
 
+extern const uint64_t DEFAULT_BATCH_READ_INDEX_TIMEOUT_MS;
+
 ColumnFamilyType NameToCF(const std::string & cf)
 {
     if (cf.empty() || cf == ColumnFamilyName::Default)

dbms/src/Storages/KVStore/Read/LearnerReadWorker.cpp

@@ -48,40 +48,57 @@ struct UnavailableRegions
         , is_wn_disagg_read(is_wn_disagg_read_)
     {}
 
-    size_t size() const { return unavailable_ids.size(); }
+    size_t size() const { return ids.size(); }
 
-    bool empty() const { return unavailable_ids.empty(); }
+    bool empty() const { return ids.empty(); }
 
-    bool contains(RegionID region_id) const { return unavailable_ids.contains(region_id); }
+    bool contains(RegionID region_id) const { return ids.contains(region_id); }
 
-    void addStatus(RegionID region_id, RegionException::RegionReadStatus status_, std::string && extra_msg_)
+    void addStatus(RegionID id, RegionException::RegionReadStatus status_, std::string && extra_msg_)
     {
-        unavailable_ids[region_id] = UnavailableDesc{status_, std::move(extra_msg_)};
+        status = status_;
+        ids.emplace(id);
+        extra_msg = std::move(extra_msg_);
     }
 
     void addRegionLock(RegionID region_id_, LockInfoPtr && region_lock_)
     {
         region_locks.emplace_back(region_id_, std::move(region_lock_));
-        unavailable_ids[region_id_] = UnavailableDesc{RegionException::RegionReadStatus::MEET_LOCK, ""};
+        ids.emplace(region_id_);
     }
 
     void tryThrowRegionException();
 
     void addRegionWaitIndexTimeout(RegionID region_id, UInt64 index_to_wait, UInt64 current_applied_index);
 
-    String toDebugString(size_t num_show) const;
+    String toDebugString() const
+    {
+        FmtBuffer buffer;
+        buffer.append("{ids=[");
+        buffer.joinStr(
+            ids.begin(),
+            ids.end(),
+            [](const auto & v, FmtBuffer & f) { f.fmtAppend("{}", v); },
+            "|");
+        buffer.append("] locks=");
+        buffer.append("[");
+        buffer.joinStr(
+            region_locks.begin(),
+            region_locks.end(),
+            [](const auto & v, FmtBuffer & f) { f.fmtAppend("{}({})", v.first, v.second->DebugString()); },
+            "|");
+        buffer.append("]}");
+        return buffer.toString();
+    }
 
 private:
     const bool batch_cop;
     const bool is_wn_disagg_read;
 
-    struct UnavailableDesc
-    {
-        RegionException::RegionReadStatus s;
-        std::string extra_msg;
-    };
-    std::unordered_map<RegionID, UnavailableDesc> unavailable_ids;
+    RegionException::UnavailableRegions ids;
     std::vector<std::pair<RegionID, LockInfoPtr>> region_locks;
+    RegionException::RegionReadStatus status{RegionException::RegionReadStatus::NOT_FOUND};
+    std::string extra_msg;
 };
 
 using RegionsReadIndexResult = std::unordered_map<RegionID, kvrpcpb::ReadIndexResponse>;

dbms/src/Storages/KVStore/Read/LearnerReadWorker.h

@@ -137,13 +137,9 @@ void WaitCheckRegionReadyImpl(
     static constexpr double BATCH_READ_INDEX_TIME_RATE = 0.2;
     auto log = Logger::get(__FUNCTION__);
 
-    UInt64 read_index_timeout = tmt.batchReadIndexTimeout();
-
     LOG_INFO(
         log,
-        "start to check regions ready, read_index_timeout={} min_wait_tick={:.3f}s max_wait_tick={:.3f}s "
-        "wait_region_ready_timeout={:.3f}s",
-        read_index_timeout,
+        "start to check regions ready, min_wait_tick={:.3f}s max_wait_tick={:.3f}s wait_region_ready_timeout={:.3f}s",
         wait_tick_time,
         max_wait_tick_time,
         get_wait_region_ready_timeout_sec);
@@ -176,7 +172,7 @@ void WaitCheckRegionReadyImpl(
         }
 
         // Record the latest commit index in TiKV
-        auto read_index_res = kvstore.batchReadIndex(batch_read_index_req, read_index_timeout);
+        auto read_index_res = kvstore.batchReadIndex(batch_read_index_req, tmt.batchReadIndexTimeout());
         for (auto && [resp, region_id] : read_index_res)
         {
             bool need_retry = resp.read_index() == 0;

dbms/src/Storages/KVStore/Read/ReadIndex.cpp

@@ -21,6 +21,8 @@
 #include <common/logger_useful.h>
 #include <kvproto/kvrpcpb.pb.h>
 
+#include <algorithm>
+#include <condition_variable>
 #include <memory>
 #include <thread>
 
@@ -30,7 +32,6 @@ namespace tests
 {
 class ReadIndexTest;
 } // namespace tests
-class KVStore;
 
 struct AsyncWaker
 {
@@ -94,7 +95,9 @@ class ReadIndexWorkerManager : boost::noncopyable
     void runOneRound(SteadyClock::duration min_dur, size_t id);
     void stop();
     ~ReadIndexWorkerManager();
-    BatchReadIndexRes batchReadIndex(const std::vector<kvrpcpb::ReadIndexRequest> & reqs, uint64_t timeout_ms);
+    BatchReadIndexRes batchReadIndex(
+        const std::vector<kvrpcpb::ReadIndexRequest> & reqs,
+        uint64_t timeout_ms = 10 * 1000);
 
     static std::unique_ptr<ReadIndexWorkerManager> newReadIndexWorkerManager(
         const TiFlashRaftProxyHelper & proxy_helper,

dbms/src/Storages/KVStore/Read/ReadIndexWorker.h

@@ -14,7 +14,6 @@
 
 #include <Common/setThreadName.h>
 #include <Storages/KVStore/Read/ReadIndexWorkerImpl.h>
-#include <common/logger_useful.h>
 
 namespace DB
 {
@@ -245,16 +244,8 @@ BatchReadIndexRes ReadIndexWorkerManager::batchReadIndex(
             }
             else
             {
-                // The read index request might be dropped by a leader/candidate/follower.
-                // The learner will retry the read index request internally in raftstore.
-                // See https://github.com/tikv/tikv/pull/19071. The default retry interval is 4s at the time of writing.
-                // Reaching this point means the request still timed out after retries.
-                GET_METRIC(tiflash_raft_learner_read_failures_count, type_read_index_timeout).Increment();
-                // Generate a "region not found" error response for the region that still has no response after timeout
                 kvrpcpb::ReadIndexResponse tmp;
-                auto * e = tmp.mutable_region_error();
-                e->mutable_region_not_found()->set_region_id(it.first);
-                e->set_message("tiflash read index timeout(" + std::to_string(timeout_ms) + "ms)");
+                tmp.mutable_region_error()->mutable_region_not_found();
                 resps.emplace_back(std::move(tmp), it.first);
             }
             tasks.pop();

dbms/src/Storages/KVStore/Read/ReadIndexWorkerManager.cpp

@@ -39,9 +39,6 @@ class RegionException : public Exception
         KEY_NOT_IN_REGION,
         TIKV_SERVER_ISSUE,
         READ_INDEX_TIMEOUT,
-        STALE_COMMAND,
-        STORE_NOT_MATCH,
-        MEET_LOCK, // meet LockInfoPtr when reading
         OTHER,
     };