Merge bitcoin/bitcoin#32948: refactor: cleanup index logging

c18bf0b refactor: cleanup index logging (Sjors Provoost)

Pull request description:

  This PR removes the use of `__func__` from index logging, since we have `-logsourcelocations`.

  It also improves readability by putting `GetName()` in a more logical place.

  Before

  > coinstatsindex: best block of the index not found. Please rebuild the index.

  After:

  > best block of coinstatsindex not found. Please rebuild the index.

  I found myself maintaining this commit as part of Sjors/bitcoin#86, but since that might never land here, it seemed better to split it into its own PR (or get rid of it).

ACKs for top commit:
  l0rinc:
    Lightweight code review ACK c18bf0b
  maflcko:
    review ACK c18bf0b 🚣

Tree-SHA512: 755948371e3ff7a5515b63ce48075631ec7868d69c3c1469176d5be0e8b28e1c071e206ae3f7320f87d8c441f815894acfef61621f05795b5ff6b8a5a3031e3b

Author: fanquake

src/index/base.cpp

@@ -112,7 +112,7 @@ bool BaseIndex::Init()
         // best chain, we will rewind to the fork point during index sync
         const CBlockIndex* locator_index{m_chainstate->m_blockman.LookupBlockIndex(locator.vHave.at(0))};
         if (!locator_index) {
-            return InitError(Untranslated(strprintf("%s: best block of the index not found. Please rebuild the index.", GetName())));
+            return InitError(Untranslated(strprintf("best block of %s not found. Please rebuild the index.", GetName())));
         }
         SetBestBlockIndex(locator_index);
     }
@@ -156,8 +156,8 @@ bool BaseIndex::ProcessBlock(const CBlockIndex* pindex, const CBlock* block_data
     CBlock block;
     if (!block_data) { // disk lookup if block data wasn't provided
         if (!m_chainstate->m_blockman.ReadBlock(block, *pindex)) {
-            FatalErrorf("%s: Failed to read block %s from disk",
-                        __func__, pindex->GetBlockHash().ToString());
+            FatalErrorf("Failed to read block %s from disk",
+                        pindex->GetBlockHash().ToString());
             return false;
         }
         block_info.data = █
@@ -166,16 +166,16 @@ bool BaseIndex::ProcessBlock(const CBlockIndex* pindex, const CBlock* block_data
     CBlockUndo block_undo;
     if (CustomOptions().connect_undo_data) {
         if (pindex->nHeight > 0 && !m_chainstate->m_blockman.ReadBlockUndo(block_undo, *pindex)) {
-            FatalErrorf("%s: Failed to read undo block data %s from disk",
-                        __func__, pindex->GetBlockHash().ToString());
+            FatalErrorf("Failed to read undo block data %s from disk",
+                        pindex->GetBlockHash().ToString());
             return false;
         }
         block_info.undo_data = &block_undo;
     }
 
     if (!CustomAppend(block_info)) {
-        FatalErrorf("%s: Failed to write block %s to index database",
-                    __func__, pindex->GetBlockHash().ToString());
+        FatalErrorf("Failed to write block %s to index database",
+                    pindex->GetBlockHash().ToString());
         return false;
     }
 
@@ -190,7 +190,7 @@ void BaseIndex::Sync()
         std::chrono::steady_clock::time_point last_locator_write_time{0s};
         while (true) {
             if (m_interrupt) {
-                LogPrintf("%s: m_interrupt set; exiting ThreadSync\n", GetName());
+                LogInfo("%s: m_interrupt set; exiting ThreadSync", GetName());
 
                 SetBestBlockIndex(pindex);
                 // No need to handle errors in Commit. If it fails, the error will be already be
@@ -221,7 +221,7 @@ void BaseIndex::Sync()
                 }
             }
             if (pindex_next->pprev != pindex && !Rewind(pindex, pindex_next->pprev)) {
-                FatalErrorf("%s: Failed to rewind index %s to a previous chain tip", __func__, GetName());
+                FatalErrorf("Failed to rewind %s to a previous chain tip", GetName());
                 return;
             }
             pindex = pindex_next;
@@ -231,7 +231,7 @@ void BaseIndex::Sync()
 
             auto current_time{std::chrono::steady_clock::now()};
             if (last_log_time + SYNC_LOG_INTERVAL < current_time) {
-                LogPrintf("Syncing %s with block chain from height %d\n",
+                LogInfo("Syncing %s with block chain from height %d",
                           GetName(), pindex->nHeight);
                 last_log_time = current_time;
             }
@@ -246,9 +246,9 @@ void BaseIndex::Sync()
     }
 
     if (pindex) {
-        LogPrintf("%s is enabled at height %d\n", GetName(), pindex->nHeight);
+        LogInfo("%s is enabled at height %d", GetName(), pindex->nHeight);
     } else {
-        LogPrintf("%s is enabled\n", GetName());
+        LogInfo("%s is enabled", GetName());
     }
 }
 
@@ -266,7 +266,7 @@ bool BaseIndex::Commit()
         }
     }
     if (!ok) {
-        LogError("%s: Failed to commit latest %s state\n", __func__, GetName());
+        LogError("Failed to commit latest %s state", GetName());
         return false;
     }
     return true;
@@ -284,8 +284,8 @@ bool BaseIndex::Rewind(const CBlockIndex* current_tip, const CBlockIndex* new_ti
         interfaces::BlockInfo block_info = kernel::MakeBlockInfo(iter_tip);
         if (CustomOptions().disconnect_data) {
             if (!m_chainstate->m_blockman.ReadBlock(block, *iter_tip)) {
-                LogError("%s: Failed to read block %s from disk",
-                             __func__, iter_tip->GetBlockHash().ToString());
+                LogError("Failed to read block %s from disk",
+                         iter_tip->GetBlockHash().ToString());
                 return false;
             }
             block_info.data = &block;
@@ -336,8 +336,8 @@ void BaseIndex::BlockConnected(ChainstateRole role, const std::shared_ptr<const
     const CBlockIndex* best_block_index = m_best_block_index.load();
     if (!best_block_index) {
         if (pindex->nHeight != 0) {
-            FatalErrorf("%s: First block connected is not the genesis block (height=%d)",
-                       __func__, pindex->nHeight);
+            FatalErrorf("First block connected is not the genesis block (height=%d)",
+                       pindex->nHeight);
             return;
         }
     } else {
@@ -347,15 +347,15 @@ void BaseIndex::BlockConnected(ChainstateRole role, const std::shared_ptr<const
         // in the ValidationInterface queue backlog even after the sync thread has caught up to the
         // new chain tip. In this unlikely event, log a warning and let the queue clear.
         if (best_block_index->GetAncestor(pindex->nHeight - 1) != pindex->pprev) {
-            LogPrintf("%s: WARNING: Block %s does not connect to an ancestor of "
-                      "known best chain (tip=%s); not updating index\n",
-                      __func__, pindex->GetBlockHash().ToString(),
+            LogWarning("Block %s does not connect to an ancestor of "
+                      "known best chain (tip=%s); not updating index",
+                      pindex->GetBlockHash().ToString(),
                       best_block_index->GetBlockHash().ToString());
             return;
         }
         if (best_block_index != pindex->pprev && !Rewind(best_block_index, pindex->pprev)) {
-            FatalErrorf("%s: Failed to rewind index %s to a previous chain tip",
-                       __func__, GetName());
+            FatalErrorf("Failed to rewind %s to a previous chain tip",
+                       GetName());
             return;
         }
     }
@@ -390,8 +390,8 @@ void BaseIndex::ChainStateFlushed(ChainstateRole role, const CBlockLocator& loca
     }
 
     if (!locator_tip_index) {
-        FatalErrorf("%s: First block (hash=%s) in locator was not found",
-                   __func__, locator_tip_hash.ToString());
+        FatalErrorf("First block (hash=%s) in locator was not found",
+                   locator_tip_hash.ToString());
         return;
     }
 
@@ -402,9 +402,9 @@ void BaseIndex::ChainStateFlushed(ChainstateRole role, const CBlockLocator& loca
     // event, log a warning and let the queue clear.
     const CBlockIndex* best_block_index = m_best_block_index.load();
     if (best_block_index->GetAncestor(locator_tip_index->nHeight) != locator_tip_index) {
-        LogPrintf("%s: WARNING: Locator contains block (hash=%s) not on known best "
-                  "chain (tip=%s); not writing index locator\n",
-                  __func__, locator_tip_hash.ToString(),
+        LogWarning("Locator contains block (hash=%s) not on known best "
+                  "chain (tip=%s); not writing index locator",
+                  locator_tip_hash.ToString(),
                   best_block_index->GetBlockHash().ToString());
         return;
     }
@@ -434,7 +434,7 @@ bool BaseIndex::BlockUntilSyncedToCurrentChain() const
         }
     }
 
-    LogPrintf("%s: %s is catching up on block notifications\n", __func__, GetName());
+    LogInfo("%s is catching up on block notifications", GetName());
     m_chain->context()->validation_signals->SyncWithValidationInterfaceQueue();
     return true;
 }

src/index/blockfilterindex.cpp

@@ -126,8 +126,8 @@ bool BlockFilterIndex::CustomInit(const std::optional<interfaces::BlockRef>& blo
         // indicate database corruption or a disk failure, and starting the index would cause
         // further corruption.
         if (m_db->Exists(DB_FILTER_POS)) {
-            LogError("%s: Cannot read current %s state; index may be corrupted\n",
-                         __func__, GetName());
+            LogError("Cannot read current %s state; index may be corrupted",
+                      GetName());
             return false;
         }
 
@@ -139,7 +139,7 @@ bool BlockFilterIndex::CustomInit(const std::optional<interfaces::BlockRef>& blo
     if (block) {
         auto op_last_header = ReadFilterHeader(block->height, block->hash);
         if (!op_last_header) {
-            LogError("Cannot read last block filter header; index may be corrupted\n");
+            LogError("Cannot read last block filter header; index may be corrupted");
             return false;
         }
         m_last_header = *op_last_header;
@@ -155,11 +155,11 @@ bool BlockFilterIndex::CustomCommit(CDBBatch& batch)
     // Flush current filter file to disk.
     AutoFile file{m_filter_fileseq->Open(pos)};
     if (file.IsNull()) {
-        LogError("%s: Failed to open filter file %d\n", __func__, pos.nFile);
+        LogError("Failed to open filter file %d", pos.nFile);
         return false;
     }
     if (!file.Commit()) {
-        LogError("%s: Failed to commit filter file %d\n", __func__, pos.nFile);
+        LogError("Failed to commit filter file %d", pos.nFile);
         (void)file.fclose();
         return false;
     }
@@ -185,13 +185,13 @@ bool BlockFilterIndex::ReadFilterFromDisk(const FlatFilePos& pos, const uint256&
     try {
         filein >> block_hash >> encoded_filter;
         if (Hash(encoded_filter) != hash) {
-            LogError("Checksum mismatch in filter decode.\n");
+            LogError("Checksum mismatch in filter decode.");
             return false;
         }
         filter = BlockFilter(GetFilterType(), block_hash, std::move(encoded_filter), /*skip_decode_check=*/true);
     }
     catch (const std::exception& e) {
-        LogError("%s: Failed to deserialize block filter from disk: %s\n", __func__, e.what());
+        LogError("Failed to deserialize block filter from disk: %s", e.what());
         return false;
     }
 
@@ -210,15 +210,15 @@ size_t BlockFilterIndex::WriteFilterToDisk(FlatFilePos& pos, const BlockFilter&
     if (pos.nPos + data_size > MAX_FLTR_FILE_SIZE) {
         AutoFile last_file{m_filter_fileseq->Open(pos)};
         if (last_file.IsNull()) {
-            LogPrintf("%s: Failed to open filter file %d\n", __func__, pos.nFile);
+            LogError("Failed to open filter file %d", pos.nFile);
             return 0;
         }
         if (!last_file.Truncate(pos.nPos)) {
-            LogPrintf("%s: Failed to truncate filter file %d\n", __func__, pos.nFile);
+            LogError("Failed to truncate filter file %d", pos.nFile);
             return 0;
         }
         if (!last_file.Commit()) {
-            LogPrintf("%s: Failed to commit filter file %d\n", __func__, pos.nFile);
+            LogError("Failed to commit filter file %d", pos.nFile);
             (void)last_file.fclose();
             return 0;
         }
@@ -235,13 +235,13 @@ size_t BlockFilterIndex::WriteFilterToDisk(FlatFilePos& pos, const BlockFilter&
     bool out_of_space;
     m_filter_fileseq->Allocate(pos, data_size, out_of_space);
     if (out_of_space) {
-        LogPrintf("%s: out of disk space\n", __func__);
+        LogError("out of disk space");
         return 0;
     }
 
     AutoFile fileout{m_filter_fileseq->Open(pos)};
     if (fileout.IsNull()) {
-        LogPrintf("%s: Failed to open filter file %d\n", __func__, pos.nFile);
+        LogError("Failed to open filter file %d", pos.nFile);
         return 0;
     }
 
@@ -263,8 +263,8 @@ std::optional<uint256> BlockFilterIndex::ReadFilterHeader(int height, const uint
     }
 
     if (read_out.first != expected_block_hash) {
-        LogError("%s: previous block header belongs to unexpected block %s; expected %s\n",
-                         __func__, read_out.first.ToString(), expected_block_hash.ToString());
+        LogError("previous block header belongs to unexpected block %s; expected %s",
+                 read_out.first.ToString(), expected_block_hash.ToString());
         return std::nullopt;
     }
 
@@ -306,15 +306,15 @@ bool BlockFilterIndex::Write(const BlockFilter& filter, uint32_t block_height, c
     db_it.Seek(key);
 
     if (!db_it.GetKey(key) || key.height != height) {
-        LogError("%s: unexpected key in %s: expected (%c, %d)\n",
-                 __func__, index_name, DB_BLOCK_HEIGHT, height);
+        LogError("unexpected key in %s: expected (%c, %d)",
+                  index_name, DB_BLOCK_HEIGHT, height);
         return false;
     }
 
     std::pair<uint256, DBVal> value;
     if (!db_it.GetValue(value)) {
-        LogError("%s: unable to read value in %s at key (%c, %d)\n",
-                 __func__, index_name, DB_BLOCK_HEIGHT, height);
+        LogError("unable to read value in %s at key (%c, %d)",
+                 index_name, DB_BLOCK_HEIGHT, height);
         return false;
     }
 
@@ -367,12 +367,12 @@ static bool LookupRange(CDBWrapper& db, const std::string& index_name, int start
                         const CBlockIndex* stop_index, std::vector<DBVal>& results)
 {
     if (start_height < 0) {
-        LogError("%s: start height (%d) is negative\n", __func__, start_height);
+        LogError("start height (%d) is negative", start_height);
         return false;
     }
     if (start_height > stop_index->nHeight) {
-        LogError("%s: start height (%d) is greater than stop height (%d)\n",
-                     __func__, start_height, stop_index->nHeight);
+        LogError("start height (%d) is greater than stop height (%d)",
+                 start_height, stop_index->nHeight);
         return false;
     }
 
@@ -389,8 +389,8 @@ static bool LookupRange(CDBWrapper& db, const std::string& index_name, int start
 
         size_t i = static_cast<size_t>(height - start_height);
         if (!db_it->GetValue(values[i])) {
-            LogError("%s: unable to read value in %s at key (%c, %d)\n",
-                         __func__, index_name, DB_BLOCK_HEIGHT, height);
+            LogError("unable to read value in %s at key (%c, %d)",
+                     index_name, DB_BLOCK_HEIGHT, height);
             return false;
         }
 
@@ -413,8 +413,8 @@ static bool LookupRange(CDBWrapper& db, const std::string& index_name, int start
         }
 
         if (!db.Read(DBHashKey(block_hash), results[i])) {
-            LogError("%s: unable to read value in %s at key (%c, %s)\n",
-                         __func__, index_name, DB_BLOCK_HASH, block_hash.ToString());
+            LogError("unable to read value in %s at key (%c, %s)",
+                     index_name, DB_BLOCK_HASH, block_hash.ToString());
             return false;
         }
     }