Align the style for region_id table_id for greping logging

dbms/src/Flash/Coprocessor/DAGStorageInterpreter.cpp

@@ -99,7 +99,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_id={}", r.region_id),
                     Errors::Coprocessor::BadRequest);
             }
             if (region_force_retry.count(id))
@@ -130,15 +130,15 @@ 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_id={}, table id in key range is {}, table id in region is {}",
                                 r.region_id,
                                 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)
                         throw TiFlashException(
-                            fmt::format("Income key ranges is illegal for region: {}", r.region_id),
+                            fmt::format("Income key ranges is illegal for region_id={}", r.region_id),
                             Errors::Coprocessor::BadRequest);
                 }
                 info.required_handle_ranges = r.key_ranges;

dbms/src/Flash/Coprocessor/TablesRegionsInfo.cpp

@@ -68,7 +68,7 @@ static void insertRegionInfoToTablesRegionInfo(const google::protobuf::RepeatedP
         if (region_info.key_ranges.empty())
         {
             throw TiFlashException(
-                fmt::format("Income key ranges is empty for region: {}", region_info.region_id),
+                fmt::format("Income key ranges is empty for region_id={}", region_info.region_id),
                 Errors::Coprocessor::BadRequest);
         }
         /// TiFlash does not support regions with duplicated region id, so for regions with duplicated

dbms/src/Flash/CoprocessorHandler.cpp

@@ -136,7 +136,7 @@ grpc::Status CoprocessorHandler::execute()
     }
     catch (LockException & e)
     {
-        LOG_WARNING(log, "LockException: region {}, message: {}", cop_request->context().region_id(), e.message());
+        LOG_WARNING(log, "LockException: region_id={}, message: {}", cop_request->context().region_id(), e.message());
         cop_response->Clear();
         GET_METRIC(tiflash_coprocessor_request_error, reason_meet_lock).Increment();
         cop_response->set_allocated_locked(e.lock_info.release());
@@ -145,7 +145,7 @@ grpc::Status CoprocessorHandler::execute()
     }
     catch (const RegionException & e)
     {
-        LOG_WARNING(log, "RegionException: region {}, message: {}", cop_request->context().region_id(), e.message());
+        LOG_WARNING(log, "RegionException: region_id={}, message: {}", cop_request->context().region_id(), e.message());
         cop_response->Clear();
         errorpb::Error * region_err;
         switch (e.status)

dbms/src/Storages/DeltaMerge/SSTFilesToBlockInputStream.cpp

@@ -101,7 +101,7 @@ void SSTFilesToBlockInputStream::readPrefix()
     {
         lock_cf_reader = std::make_unique<MultiSSTReader<MonoSSTReader, SSTView>>(proxy_helper, ColumnFamilyType::Lock, make_inner_func, ssts_lock, log);
     }
-    LOG_INFO(log, "Finish Construct MultiSSTReader, write {} lock {} default {} region {}", ssts_write.size(), ssts_lock.size(), ssts_default.size(), this->region->id());
+    LOG_INFO(log, "Finish Construct MultiSSTReader, write={} lock={} default={} region_id={}", ssts_write.size(), ssts_lock.size(), ssts_default.size(), this->region->id());
 
     process_keys.default_cf = 0;
     process_keys.write_cf = 0;

dbms/src/Storages/DeltaMerge/SSTFilesToDTFilesOutputStream.cpp

@@ -22,6 +22,7 @@
 #include <Storages/StorageDeltaMerge.h>
 #include <Storages/Transaction/PartitionStreams.h>
 #include <Storages/Transaction/ProxyFFI.h>
+#include <Storages/Transaction/Region.h>
 #include <Storages/Transaction/SSTReader.h>
 #include <Storages/Transaction/TMTContext.h>
 #include <common/logger_useful.h>
@@ -88,8 +89,8 @@ void SSTFilesToDTFilesOutputStream<ChildStream>::writeSuffix()
 
     LOG_INFO(
         log,
-        "Transformed snapshot in SSTFile to DTFiles, region={} job_type={} cost_ms={} rows={} bytes={} write_cf_keys={} default_cf_keys={} lock_cf_keys={} dt_files=[{}]",
-        child->getRegion()->toString(true),
+        "Transformed snapshot in SSTFile to DTFiles, region_id={} job_type={} cost_ms={} rows={} bytes={} write_cf_keys={} default_cf_keys={} lock_cf_keys={} dt_files=[{}]",
+        child->getRegion()->id(),
         magic_enum::enum_name(job_type),
         watch.elapsedMilliseconds(),
         total_committed_rows,
@@ -132,8 +133,8 @@ bool SSTFilesToDTFilesOutputStream<ChildStream>::newDTFileStream()
 
     LOG_DEBUG(
         log,
-        "Create new DTFile for snapshot data, region={} file_idx={} file={}",
-        child->getRegion()->toString(true),
+        "Create new DTFile for snapshot data, region_id={} file_idx={} file={}",
+        child->getRegion()->id(),
         ingest_files.size() - 1,
         dt_file->path());
 
@@ -159,8 +160,8 @@ bool SSTFilesToDTFilesOutputStream<ChildStream>::finalizeDTFileStream()
 
     LOG_INFO(
         log,
-        "Finished writing DTFile from snapshot data, region={} file_idx={} file_rows={} file_bytes={} data_range={} file_bytes_on_disk={} file={}",
-        child->getRegion()->toString(true),
+        "Finished writing DTFile from snapshot data, region_id={} file_idx={} file_rows={} file_bytes={} data_range={} file_bytes_on_disk={} file={}",
+        child->getRegion()->id(),
         ingest_files.size() - 1,
         committed_rows_this_dt_file,
         committed_bytes_this_dt_file,

dbms/src/Storages/Transaction/ApplySnapshot.cpp

@@ -64,11 +64,12 @@ void KVStore::checkAndApplyPreHandledSnapshot(const RegionPtrWrap & new_region,
         old_applied_index = old_region->appliedIndex();
         if (auto new_index = new_region->appliedIndex(); old_applied_index > new_index)
         {
-            auto s = fmt::format("[region {}] already has newer apply-index {} than {}, should not happen",
-                                 region_id,
-                                 old_applied_index,
-                                 new_index);
-            throw Exception(s, ErrorCodes::LOGICAL_ERROR);
+            throw Exception(
+                ErrorCodes::LOGICAL_ERROR,
+                "try to apply with older index, region_id={} applied_index={} new_index={}",
+                region_id,
+                old_applied_index,
+                new_index);
         }
         else if (old_applied_index == new_index)
         {
@@ -101,16 +102,15 @@ void KVStore::checkAndApplyPreHandledSnapshot(const RegionPtrWrap & new_region,
                 auto state = getProxyHelper()->getRegionLocalState(overlapped_region.first);
                 if (state.state() != raft_serverpb::PeerState::Tombstone)
                 {
-                    throw Exception(fmt::format(
-                                        "range of region {} is overlapped with {}, state: {}",
-                                        region_id,
-                                        overlapped_region.first,
-                                        state.ShortDebugString()),
-                                    ErrorCodes::LOGICAL_ERROR);
+                    throw Exception(ErrorCodes::LOGICAL_ERROR,
+                                    "range of region_id={} is overlapped with region_id={}, state: {}",
+                                    region_id,
+                                    overlapped_region.first,
+                                    state.ShortDebugString());
                 }
                 else
                 {
-                    LOG_INFO(log, "range of region {} is overlapped with `Tombstone` region {}", region_id, overlapped_region.first);
+                    LOG_INFO(log, "range of region_id={} is overlapped with `Tombstone` region_id={}", region_id, overlapped_region.first);
                     handleDestroy(overlapped_region.first, tmt, task_lock);
                 }
             }
@@ -167,7 +167,7 @@ void KVStore::onSnapshot(const RegionPtrWrap & new_region_wrap, RegionPtr old_re
                         storage->getRowKeyColumnSize());
                     if (old_key_range != new_key_range)
                     {
-                        LOG_INFO(log, "clear region {} old range {} before apply snapshot of new range {}", region_id, old_key_range.toDebugString(), new_key_range.toDebugString());
+                        LOG_INFO(log, "clear old range before apply snapshot, region_id={} old_range={} new_range={}", region_id, old_key_range.toDebugString(), new_key_range.toDebugString());
                         dm_storage->deleteRange(old_key_range, context.getSettingsRef());
                         // We must flush the deletion to the disk here, because we only flush new range when persisting this region later.
                         dm_storage->flushCache(context, old_key_range, /*try_until_succeed*/ true);
@@ -225,8 +225,11 @@ void KVStore::onSnapshot(const RegionPtrWrap & new_region_wrap, RegionPtr old_re
 
         if (getRegion(region_id) != old_region || (old_region && old_region_index != old_region->appliedIndex()))
         {
-            auto s = fmt::format("{}: [region {}] instance changed, should not happen", __PRETTY_FUNCTION__, region_id);
-            throw Exception(s, ErrorCodes::LOGICAL_ERROR);
+            throw Exception(
+                ErrorCodes::LOGICAL_ERROR,
+                "{}: region_id={} instance changed, should not happen",
+                __PRETTY_FUNCTION__,
+                region_id);
         }
 
         if (old_region != nullptr)
@@ -420,7 +423,7 @@ void KVStore::applyPreHandledSnapshot(const RegionPtrWrap & new_region, TMTConte
 
     FAIL_POINT_PAUSE(FailPoints::pause_until_apply_raft_snapshot);
 
-    LOG_INFO(log, "Finish apply snapshot, new_region={}", new_region->toString(false));
+    LOG_INFO(log, "Finish apply snapshot, new_region={}", new_region->toString(true));
 }
 
 template void KVStore::applyPreHandledSnapshot<RegionPtrWithSnapshotFiles>(const RegionPtrWithSnapshotFiles &, TMTContext &);
@@ -442,8 +445,11 @@ static const metapb::Peer & findPeer(const metapb::Region & region, UInt64 peer_
     }
 
     throw Exception(
-        fmt::format("{}: [peer {}] not found in [region {}]", __PRETTY_FUNCTION__, peer_id, region.id()),
-        ErrorCodes::LOGICAL_ERROR);
+        ErrorCodes::LOGICAL_ERROR,
+        "{}: peer not found in region, peer_id={} region_id={}",
+        __PRETTY_FUNCTION__,
+        peer_id,
+        region.id());
 }
 
 RegionPtr KVStore::genRegionPtr(metapb::Region && region, UInt64 peer_id, UInt64 index, UInt64 term)
@@ -485,7 +491,7 @@ EngineStoreApplyRes KVStore::handleIngestSST(UInt64 region_id, const SSTViewVec
     const RegionPtr region = getRegion(region_id);
     if (region == nullptr)
     {
-        LOG_WARNING(log, "[region {}] is not found at [term {}, index {}], might be removed already", region_id, term, index);
+        LOG_WARNING(log, "region not found, might be removed already, region_id={} term={} index={}", region_id, term, index);
         return EngineStoreApplyRes::NotFound;
     }
 
@@ -548,7 +554,7 @@ RegionPtr KVStore::handleIngestSSTByDTFile(const RegionPtr & region, const SSTVi
     }
     catch (DB::Exception & e)
     {
-        e.addMessage(fmt::format("(while handleIngestSST region_id={}, index={}, term={})", tmp_region->id(), index, term));
+        e.addMessage(fmt::format("(while handleIngestSST region_id={} index={} term={})", tmp_region->id(), index, term));
         e.rethrow();
     }
 

dbms/src/Storages/Transaction/KVStore.cpp

@@ -141,7 +141,7 @@ bool KVStore::tryFlushRegionCacheInStorage(TMTContext & tmt, const Region & regi
     if (unlikely(storage == nullptr))
     {
         LOG_WARNING(log,
-                    "tryFlushRegionCacheInStorage can not get table for region {} with table id {}, ignored",
+                    "tryFlushRegionCacheInStorage can not get table for region{} with table_id={}, ignored",
                     region.toString(),
                     table_id);
         return true;
@@ -194,7 +194,7 @@ void KVStore::gcRegionPersistedCache(Seconds gc_persist_period)
 
 void KVStore::removeRegion(RegionID region_id, bool remove_data, RegionTable & region_table, const KVStoreTaskLock & task_lock, const RegionTaskLock & region_lock)
 {
-    LOG_INFO(log, "Start to remove [region {}]", region_id);
+    LOG_INFO(log, "Start to remove region_id={}", region_id);
 
     {
         auto manage_lock = genRegionWriteLock(task_lock);
@@ -211,11 +211,11 @@ void KVStore::removeRegion(RegionID region_id, bool remove_data, RegionTable & r
     }
 
     region_persister->drop(region_id, region_lock);
-    LOG_INFO(log, "Persisted [region {}] deleted", region_id);
+    LOG_INFO(log, "Persisted region_id={} deleted", region_id);
 
     region_table.removeRegion(region_id, remove_data, region_lock);
 
-    LOG_INFO(log, "Remove [region {}] done", region_id);
+    LOG_INFO(log, "Remove region_id={} done", region_id);
 }
 
 KVStoreTaskLock KVStore::genTaskLock() const
@@ -303,7 +303,7 @@ void KVStore::handleDestroy(UInt64 region_id, TMTContext & tmt, const KVStoreTas
     const auto region = getRegion(region_id);
     if (region == nullptr)
     {
-        LOG_INFO(log, "[region {}] is not found, might be removed already", region_id);
+        LOG_INFO(log, "region_id={} not found, might be removed already", region_id);
         return;
     }
     LOG_INFO(log, "Handle destroy {}", region->toString());
@@ -350,16 +350,16 @@ bool KVStore::tryFlushRegionData(UInt64 region_id, bool force_persist, bool try_
         /// The triggered CompactLog will be handled by `handleUselessAdminRaftCmd`,
         /// and result in a `EngineStoreApplyRes::NotFound`.
         /// Proxy will print this message and continue: `region not found in engine-store, maybe have exec `RemoveNode` first`.
-        LOG_WARNING(log, "region {} [index: {}, term {}], not exist when flushing, maybe have exec `RemoveNode` first", region_id, index, term);
+        LOG_WARNING(log, "[region_id={} term={} index={}] not exist when flushing, maybe have exec `RemoveNode` first", region_id, term, index);
         return true;
     }
     if (force_persist)
     {
         auto & curr_region = *curr_region_ptr;
-        LOG_DEBUG(log, "{} flush region due to tryFlushRegionData by force, index {} term {}", curr_region.toString(false), index, term);
+        LOG_DEBUG(log, "flush region due to tryFlushRegionData by force, region_id={} term={} index={}", curr_region.id(), term, index);
         if (!forceFlushRegionDataImpl(curr_region, try_until_succeed, tmt, region_task_lock, index, term))
         {
-            throw Exception("Force flush region " + std::to_string(region_id) + " failed", ErrorCodes::LOGICAL_ERROR);
+            throw Exception(ErrorCodes::LOGICAL_ERROR, "Force flush region failed, region_id={}", region_id);
         }
         return true;
     }
@@ -397,7 +397,7 @@ bool KVStore::canFlushRegionDataImpl(const RegionPtr & curr_region_ptr, UInt8 fl
     }
     if (can_flush && flush_if_possible)
     {
-        LOG_DEBUG(log, "{} flush region due to tryFlushRegionData, index {} term {}", curr_region.toString(false), index, term);
+        LOG_DEBUG(log, "flush region due to tryFlushRegionData, region_id={} term={} index={}", curr_region.id(), term, index);
         return forceFlushRegionDataImpl(curr_region, try_until_succeed, tmt, region_task_lock, index, term);
     }
     return can_flush;
@@ -504,7 +504,7 @@ EngineStoreApplyRes KVStore::handleAdminRaftCmd(raft_cmdpb::AdminRequest && requ
         if (curr_region_ptr == nullptr)
         {
             LOG_WARNING(log,
-                        "[region {}] is not found at [term {}, index {}, cmd {}], might be removed already",
+                        "region not found, might be removed already, region_id={} term={} index={} cmd={}",
                         curr_region_id,
                         term,
                         index,
@@ -709,7 +709,7 @@ void WaitCheckRegionReady(
                 if (region_error.has_region_not_found() || region_error.has_epoch_not_match())
                     need_retry = false;
                 LOG_DEBUG(log,
-                          "neglect error region {} not found {} epoch not match {}",
+                          "neglect error region_id={} not found {} epoch not match {}",
                           region_id,
                           region_error.has_region_not_found(),
                           region_error.has_epoch_not_match());

dbms/src/Storages/Transaction/LearnerRead.cpp

@@ -164,7 +164,7 @@ LearnerReadSnapshot doLearnerRead(
         auto region = kvstore->getRegion(info.region_id);
         if (region == nullptr)
         {
-            LOG_WARNING(log, "[region {}] is not found in KVStore, try again", info.region_id);
+            LOG_WARNING(log, "region not found in KVStore, region_id={}", info.region_id);
             throw RegionException({info.region_id}, RegionException::RegionReadStatus::NOT_FOUND);
         }
         regions_snapshot.emplace(info.region_id, std::move(region));
@@ -316,7 +316,7 @@ LearnerReadSnapshot doLearnerRead(
                 return;
             }
             // TODO: Maybe collect all the Regions that happen wait index timeout instead of just throwing one Region id
-            throw TiFlashException(Errors::Coprocessor::RegionError, "Region {} is unavailable at {}", region_id, index);
+            throw TiFlashException(Errors::Coprocessor::RegionError, "Region unavailable, region_id={} index={}", region_id, index);
         };
         const auto wait_index_timeout_ms = tmt.waitIndexTimeout();
         for (size_t region_idx = region_begin_idx, read_index_res_idx = 0; region_idx < num_regions; ++region_idx, ++read_index_res_idx)
@@ -380,7 +380,7 @@ LearnerReadSnapshot doLearnerRead(
                             {
                                 LOG_WARNING(
                                     log,
-                                    "Check memory cache, region {}, version {}, handle range {}, status {}",
+                                    "Check memory cache, region_id={} version={} handle_range={} status={}",
                                     region_to_query.region_id,
                                     region_to_query.version,
                                     RecordKVFormat::DecodedTiKVKeyRangeToDebugString(region_to_query.range_in_table),
@@ -396,9 +396,9 @@ LearnerReadSnapshot doLearnerRead(
         stats.wait_index_elapsed_ms = watch.elapsedMilliseconds();
         LOG_DEBUG(
             log,
-            "Finish wait index | resolve locks | check memory cache for {} regions, cost {}ms, {} unavailable regions",
-            batch_read_index_req.size(),
+            "Finish wait index | resolve locks | check memory cache, wait_cost={}ms n_regions={} n_unavailable={}",
             stats.wait_index_elapsed_ms,
+            batch_read_index_req.size(),
             unavailable_regions.size());
     };
 
@@ -465,7 +465,7 @@ void validateQueryInfo(
             fail_status = status;
             LOG_WARNING(
                 log,
-                "Check after read from Storage, region {}, version {}, handle range {}, status {}",
+                "Check after snapshot acquired from storage, region_id={} version={} handle_range={} status={}",
                 region_query_info.region_id,
                 region_query_info.version,
                 RecordKVFormat::DecodedTiKVKeyRangeToDebugString(region_query_info.range_in_table),