Skip to content

Commit

Permalink
Merge bitcoin#30750: scripted-diff: LogPrint -> LogDebug
Browse files Browse the repository at this point in the history
fa09cb4 refactor: Remove unused LogPrint (MarcoFalke)
3333415 scripted-diff: LogPrint -> LogDebug (MarcoFalke)

Pull request description:

  `LogPrint` has many issues:

  * It seems to indicate that something is being "printed", however config options such as `-printtoconsole` actually control what and where something is logged.
  * It does not mention the log severity (debug).
  * It is a deprecated alias for `LogDebug`, according to the dev notes.
  * It wastes review cycles, because reviewers sometimes point out that it is deprecated.
  * It makes the code inconsistent, when both are used, possibly even in lines right next to each other (like in `InitHTTPServer`)

  Fix all issues by removing the deprecated alias.

  I checked all conflicting pull requests and at the time of writing there are no conflicts, except in pull requests that are marked as draft, are yet unreviewed, or are blocked on feedback for other reasons. So I think it is fine to do now.

ACKs for top commit:
  stickies-v:
    ACK fa09cb4
  danielabrozzoni:
    utACK fa09cb4
  TheCharlatan:
    ACK fa09cb4

Tree-SHA512: 14270f4cfa3906025a0b994cbb5b2e3c8c2427c0beb19c717a505a2ccbfb1fd1ecf2fd03f6c52d22cde69a8d057e50d2207119fab2c2bc8228db3f10d4288d0f
  • Loading branch information
fanquake committed Sep 2, 2024
2 parents ef6f49e + fa09cb4 commit d4cc0c6
Show file tree
Hide file tree
Showing 45 changed files with 361 additions and 369 deletions.
2 changes: 1 addition & 1 deletion contrib/devtools/bitcoin-tidy/example_logprintf.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -22,7 +22,7 @@ static inline void LogPrintf_(const std::string& logging_function, const std::st
#define LogPrintLevel_(category, level, ...) LogPrintf_(__func__, __FILE__, __LINE__, category, level, __VA_ARGS__)
#define LogPrintf(...) LogPrintLevel_(LogFlags::NONE, Level::None, __VA_ARGS__)

#define LogPrint(category, ...) \
#define LogDebug(category, ...) \
do { \
LogPrintf(__VA_ARGS__); \
} while (0)
Expand Down
2 changes: 0 additions & 2 deletions doc/developer-notes.md
Original file line number Diff line number Diff line change
Expand Up @@ -741,8 +741,6 @@ logging messages. They should be used as follows:
useful for debugging and can reasonably be enabled on a production
system (that has sufficient free storage space). They will be logged
if the program is started with `-debug=category` or `-debug=1`.
Note that `LogPrint(BCLog::CATEGORY, fmt, params...)` is a deprecated
alias for `LogDebug`.

- `LogInfo(fmt, params...)` should only be used rarely, e.g. for startup
messages or for infrequent and important events such as a new block tip
Expand Down
4 changes: 2 additions & 2 deletions doc/fuzzing.md
Original file line number Diff line number Diff line change
Expand Up @@ -257,7 +257,7 @@ index 7601a6ea84..702d0f56ce 100644
// Check start string, network magic
- if (memcmp(hdr.pchMessageStart, m_chain_params.MessageStart(), CMessageHeader::MESSAGE_START_SIZE) != 0) {
+ if (false && memcmp(hdr.pchMessageStart, m_chain_params.MessageStart(), CMessageHeader::MESSAGE_START_SIZE) != 0) { // skip network magic checking
LogPrint(BCLog::NET, "Header error: Wrong MessageStart %s received, peer=%d\n", HexStr(hdr.pchMessageStart), m_node_id);
LogDebug(BCLog::NET, "Header error: Wrong MessageStart %s received, peer=%d\n", HexStr(hdr.pchMessageStart), m_node_id);
return -1;
}
@@ -788,7 +788,7 @@ CNetMessage V1TransportDeserializer::GetMessage(const std::chrono::microseconds
Expand All @@ -266,7 +266,7 @@ index 7601a6ea84..702d0f56ce 100644
// Check checksum and header message type string
- if (memcmp(hash.begin(), hdr.pchChecksum, CMessageHeader::CHECKSUM_SIZE) != 0) {
+ if (false && memcmp(hash.begin(), hdr.pchChecksum, CMessageHeader::CHECKSUM_SIZE) != 0) { // skip checksum checking
LogPrint(BCLog::NET, "Header error: Wrong checksum (%s, %u bytes), expected %s was %s, peer=%d\n",
LogDebug(BCLog::NET, "Header error: Wrong checksum (%s, %u bytes), expected %s was %s, peer=%d\n",
SanitizeString(msg.m_type), msg.m_message_size,
HexStr(Span{hash}.first(CMessageHeader::CHECKSUM_SIZE)),
EOF
Expand Down
24 changes: 12 additions & 12 deletions src/addrman.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -342,7 +342,7 @@ void AddrManImpl::Unserialize(Stream& s_)
serialized_asmap_checksum == supplied_asmap_checksum};

if (!restore_bucketing) {
LogPrint(BCLog::ADDRMAN, "Bucketing method was updated, re-bucketing addrman entries from disk\n");
LogDebug(BCLog::ADDRMAN, "Bucketing method was updated, re-bucketing addrman entries from disk\n");
}

for (auto bucket_entry : bucket_entries) {
Expand Down Expand Up @@ -387,7 +387,7 @@ void AddrManImpl::Unserialize(Stream& s_)
}
}
if (nLost + nLostUnk > 0) {
LogPrint(BCLog::ADDRMAN, "addrman lost %i new and %i tried addresses due to collisions or invalid addresses\n", nLostUnk, nLost);
LogDebug(BCLog::ADDRMAN, "addrman lost %i new and %i tried addresses due to collisions or invalid addresses\n", nLostUnk, nLost);
}

const int check_code{CheckAddrman()};
Expand Down Expand Up @@ -481,7 +481,7 @@ void AddrManImpl::ClearNew(int nUBucket, int nUBucketPos)
assert(infoDelete.nRefCount > 0);
infoDelete.nRefCount--;
vvNew[nUBucket][nUBucketPos] = -1;
LogPrint(BCLog::ADDRMAN, "Removed %s from new[%i][%i]\n", infoDelete.ToStringAddrPort(), nUBucket, nUBucketPos);
LogDebug(BCLog::ADDRMAN, "Removed %s from new[%i][%i]\n", infoDelete.ToStringAddrPort(), nUBucket, nUBucketPos);
if (infoDelete.nRefCount == 0) {
Delete(nIdDelete);
}
Expand Down Expand Up @@ -536,7 +536,7 @@ void AddrManImpl::MakeTried(AddrInfo& info, int nId)
vvNew[nUBucket][nUBucketPos] = nIdEvict;
nNew++;
m_network_counts[infoOld.GetNetwork()].n_new++;
LogPrint(BCLog::ADDRMAN, "Moved %s from tried[%i][%i] to new[%i][%i] to make space\n",
LogDebug(BCLog::ADDRMAN, "Moved %s from tried[%i][%i] to new[%i][%i] to make space\n",
infoOld.ToStringAddrPort(), nKBucket, nKBucketPos, nUBucket, nUBucketPos);
}
assert(vvTried[nKBucket][nKBucketPos] == -1);
Expand Down Expand Up @@ -612,7 +612,7 @@ bool AddrManImpl::AddSingle(const CAddress& addr, const CNetAddr& source, std::c
pinfo->nRefCount++;
vvNew[nUBucket][nUBucketPos] = nId;
const auto mapped_as{m_netgroupman.GetMappedAS(addr)};
LogPrint(BCLog::ADDRMAN, "Added %s%s to new[%i][%i]\n",
LogDebug(BCLog::ADDRMAN, "Added %s%s to new[%i][%i]\n",
addr.ToStringAddrPort(), (mapped_as ? strprintf(" mapped to AS%i", mapped_as) : ""), nUBucket, nUBucketPos);
} else {
if (pinfo->nRefCount == 0) {
Expand Down Expand Up @@ -663,7 +663,7 @@ bool AddrManImpl::Good_(const CService& addr, bool test_before_evict, NodeSecond
}
// Output the entry we'd be colliding with, for debugging purposes
auto colliding_entry = mapInfo.find(vvTried[tried_bucket][tried_bucket_pos]);
LogPrint(BCLog::ADDRMAN, "Collision with %s while attempting to move %s to tried table. Collisions=%d\n",
LogDebug(BCLog::ADDRMAN, "Collision with %s while attempting to move %s to tried table. Collisions=%d\n",
colliding_entry != mapInfo.end() ? colliding_entry->second.ToStringAddrPort() : "",
addr.ToStringAddrPort(),
m_tried_collisions.size());
Expand All @@ -672,7 +672,7 @@ bool AddrManImpl::Good_(const CService& addr, bool test_before_evict, NodeSecond
// move nId to the tried tables
MakeTried(info, nId);
const auto mapped_as{m_netgroupman.GetMappedAS(addr)};
LogPrint(BCLog::ADDRMAN, "Moved %s%s to tried[%i][%i]\n",
LogDebug(BCLog::ADDRMAN, "Moved %s%s to tried[%i][%i]\n",
addr.ToStringAddrPort(), (mapped_as ? strprintf(" mapped to AS%i", mapped_as) : ""), tried_bucket, tried_bucket_pos);
return true;
}
Expand All @@ -685,7 +685,7 @@ bool AddrManImpl::Add_(const std::vector<CAddress>& vAddr, const CNetAddr& sourc
added += AddSingle(*it, source, time_penalty) ? 1 : 0;
}
if (added > 0) {
LogPrint(BCLog::ADDRMAN, "Added %i addresses (of %i) from %s: %i tried, %i new\n", added, vAddr.size(), source.ToStringAddr(), nTried, nNew);
LogDebug(BCLog::ADDRMAN, "Added %i addresses (of %i) from %s: %i tried, %i new\n", added, vAddr.size(), source.ToStringAddr(), nTried, nNew);
}
return added > 0;
}
Expand Down Expand Up @@ -777,7 +777,7 @@ std::pair<CAddress, NodeSeconds> AddrManImpl::Select_(bool new_only, std::option

// With probability GetChance() * chance_factor, return the entry.
if (insecure_rand.randbits<30>() < chance_factor * info.GetChance() * (1 << 30)) {
LogPrint(BCLog::ADDRMAN, "Selected %s from %s\n", info.ToStringAddrPort(), search_tried ? "tried" : "new");
LogDebug(BCLog::ADDRMAN, "Selected %s from %s\n", info.ToStringAddrPort(), search_tried ? "tried" : "new");
return {info, info.m_last_try};
}

Expand Down Expand Up @@ -837,7 +837,7 @@ std::vector<CAddress> AddrManImpl::GetAddr_(size_t max_addresses, size_t max_pct

addresses.push_back(ai);
}
LogPrint(BCLog::ADDRMAN, "GetAddr returned %d random addresses\n", addresses.size());
LogDebug(BCLog::ADDRMAN, "GetAddr returned %d random addresses\n", addresses.size());
return addresses;
}

Expand Down Expand Up @@ -935,7 +935,7 @@ void AddrManImpl::ResolveCollisions_()

// Give address at least 60 seconds to successfully connect
if (current_time - info_old.m_last_try > 60s) {
LogPrint(BCLog::ADDRMAN, "Replacing %s with %s in tried table\n", info_old.ToStringAddrPort(), info_new.ToStringAddrPort());
LogDebug(BCLog::ADDRMAN, "Replacing %s with %s in tried table\n", info_old.ToStringAddrPort(), info_new.ToStringAddrPort());

// Replaces an existing address already in the tried table with the new address
Good_(info_new, false, current_time);
Expand All @@ -945,7 +945,7 @@ void AddrManImpl::ResolveCollisions_()
// If the collision hasn't resolved in some reasonable amount of time,
// just evict the old entry -- we must not be able to
// connect to it for some reason.
LogPrint(BCLog::ADDRMAN, "Unable to test; replacing %s with %s in tried table anyway\n", info_old.ToStringAddrPort(), info_new.ToStringAddrPort());
LogDebug(BCLog::ADDRMAN, "Unable to test; replacing %s with %s in tried table anyway\n", info_old.ToStringAddrPort(), info_new.ToStringAddrPort());
Good_(info_new, false, current_time);
erase_collision = true;
}
Expand Down
6 changes: 3 additions & 3 deletions src/banman.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -36,7 +36,7 @@ void BanMan::LoadBanlist()
if (m_ban_db.Read(m_banned)) {
SweepBanned(); // sweep out unused entries

LogPrint(BCLog::NET, "Loaded %d banned node addresses/subnets %dms\n", m_banned.size(),
LogDebug(BCLog::NET, "Loaded %d banned node addresses/subnets %dms\n", m_banned.size(),
Ticks<std::chrono::milliseconds>(SteadyClock::now() - start));
} else {
LogPrintf("Recreating the banlist database\n");
Expand Down Expand Up @@ -65,7 +65,7 @@ void BanMan::DumpBanlist()
m_is_dirty = true;
}

LogPrint(BCLog::NET, "Flushed %d banned node addresses/subnets to disk %dms\n", banmap.size(),
LogDebug(BCLog::NET, "Flushed %d banned node addresses/subnets to disk %dms\n", banmap.size(),
Ticks<std::chrono::milliseconds>(SteadyClock::now() - start));
}

Expand Down Expand Up @@ -193,7 +193,7 @@ void BanMan::SweepBanned()
m_banned.erase(it++);
m_is_dirty = true;
notify_ui = true;
LogPrint(BCLog::NET, "Removed banned node address/subnet: %s\n", sub_net.ToString());
LogDebug(BCLog::NET, "Removed banned node address/subnet: %s\n", sub_net.ToString());
} else {
++it;
}
Expand Down
16 changes: 8 additions & 8 deletions src/bench/logging.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -11,7 +11,7 @@

// All but 2 of the benchmarks should have roughly similar performance:
//
// LogPrintWithoutCategory should be ~3 orders of magnitude faster, as nothing is logged.
// LogWithoutDebug should be ~3 orders of magnitude faster, as nothing is logged.
//
// LogWithoutWriteToFile should be ~2 orders of magnitude faster, as it avoids disk writes.

Expand Down Expand Up @@ -40,14 +40,14 @@ static void LogPrintLevelWithoutThreadNames(benchmark::Bench& bench)
LogPrintLevel(BCLog::NET, BCLog::Level::Error, "%s\n", "test"); });
}

static void LogPrintWithCategory(benchmark::Bench& bench)
static void LogWithDebug(benchmark::Bench& bench)
{
Logging(bench, {"-logthreadnames=0", "-debug=net"}, [] { LogPrint(BCLog::NET, "%s\n", "test"); });
Logging(bench, {"-logthreadnames=0", "-debug=net"}, [] { LogDebug(BCLog::NET, "%s\n", "test"); });
}

static void LogPrintWithoutCategory(benchmark::Bench& bench)
static void LogWithoutDebug(benchmark::Bench& bench)
{
Logging(bench, {"-logthreadnames=0", "-debug=0"}, [] { LogPrint(BCLog::NET, "%s\n", "test"); });
Logging(bench, {"-logthreadnames=0", "-debug=0"}, [] { LogDebug(BCLog::NET, "%s\n", "test"); });
}

static void LogPrintfCategoryWithThreadNames(benchmark::Bench& bench)
Expand Down Expand Up @@ -79,14 +79,14 @@ static void LogWithoutWriteToFile(benchmark::Bench& bench)
// Disable writing the log to a file, as used for unit tests and fuzzing in `MakeNoLogFileContext`.
Logging(bench, {"-nodebuglogfile", "-debug=1"}, [] {
LogPrintf("%s\n", "test");
LogPrint(BCLog::NET, "%s\n", "test");
LogDebug(BCLog::NET, "%s\n", "test");
});
}

BENCHMARK(LogPrintLevelWithThreadNames, benchmark::PriorityLevel::HIGH);
BENCHMARK(LogPrintLevelWithoutThreadNames, benchmark::PriorityLevel::HIGH);
BENCHMARK(LogPrintWithCategory, benchmark::PriorityLevel::HIGH);
BENCHMARK(LogPrintWithoutCategory, benchmark::PriorityLevel::HIGH);
BENCHMARK(LogWithDebug, benchmark::PriorityLevel::HIGH);
BENCHMARK(LogWithoutDebug, benchmark::PriorityLevel::HIGH);
BENCHMARK(LogPrintfCategoryWithThreadNames, benchmark::PriorityLevel::HIGH);
BENCHMARK(LogPrintfCategoryWithoutThreadNames, benchmark::PriorityLevel::HIGH);
BENCHMARK(LogPrintfWithThreadNames, benchmark::PriorityLevel::HIGH);
Expand Down
6 changes: 3 additions & 3 deletions src/blockencodings.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -167,7 +167,7 @@ ReadStatus PartiallyDownloadedBlock::InitData(const CBlockHeaderAndShortTxIDs& c
break;
}

LogPrint(BCLog::CMPCTBLOCK, "Initialized PartiallyDownloadedBlock for block %s using a cmpctblock of size %lu\n", cmpctblock.header.GetHash().ToString(), GetSerializeSize(cmpctblock));
LogDebug(BCLog::CMPCTBLOCK, "Initialized PartiallyDownloadedBlock for block %s using a cmpctblock of size %lu\n", cmpctblock.header.GetHash().ToString(), GetSerializeSize(cmpctblock));

return READ_STATUS_OK;
}
Expand Down Expand Up @@ -217,10 +217,10 @@ ReadStatus PartiallyDownloadedBlock::FillBlock(CBlock& block, const std::vector<
return READ_STATUS_CHECKBLOCK_FAILED;
}

LogPrint(BCLog::CMPCTBLOCK, "Successfully reconstructed block %s with %lu txn prefilled, %lu txn from mempool (incl at least %lu from extra pool) and %lu txn requested\n", hash.ToString(), prefilled_count, mempool_count, extra_count, vtx_missing.size());
LogDebug(BCLog::CMPCTBLOCK, "Successfully reconstructed block %s with %lu txn prefilled, %lu txn from mempool (incl at least %lu from extra pool) and %lu txn requested\n", hash.ToString(), prefilled_count, mempool_count, extra_count, vtx_missing.size());
if (vtx_missing.size() < 5) {
for (const auto& tx : vtx_missing) {
LogPrint(BCLog::CMPCTBLOCK, "Reconstructed block %s required tx %s\n", hash.ToString(), tx->GetHash().ToString());
LogDebug(BCLog::CMPCTBLOCK, "Reconstructed block %s required tx %s\n", hash.ToString(), tx->GetHash().ToString());
}
}

Expand Down
6 changes: 3 additions & 3 deletions src/dbwrapper.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -130,7 +130,7 @@ static void SetMaxOpenFiles(leveldb::Options *options) {
options->max_open_files = 64;
}
#endif
LogPrint(BCLog::LEVELDB, "LevelDB using max_open_files=%d (default=%d)\n",
LogDebug(BCLog::LEVELDB, "LevelDB using max_open_files=%d (default=%d)\n",
options->max_open_files, default_open_files);
}

Expand Down Expand Up @@ -299,7 +299,7 @@ bool CDBWrapper::WriteBatch(CDBBatch& batch, bool fSync)
HandleError(status);
if (log_memory) {
double mem_after = DynamicMemoryUsage() / 1024.0 / 1024;
LogPrint(BCLog::LEVELDB, "WriteBatch memory usage: db=%s, before=%.1fMiB, after=%.1fMiB\n",
LogDebug(BCLog::LEVELDB, "WriteBatch memory usage: db=%s, before=%.1fMiB, after=%.1fMiB\n",
m_name, mem_before, mem_after);
}
return true;
Expand All @@ -310,7 +310,7 @@ size_t CDBWrapper::DynamicMemoryUsage() const
std::string memory;
std::optional<size_t> parsed;
if (!DBContext().pdb->GetProperty("leveldb.approximate-memory-usage", &memory) || !(parsed = ToIntegral<size_t>(memory))) {
LogPrint(BCLog::LEVELDB, "Failed to get approximate-memory-usage property\n");
LogDebug(BCLog::LEVELDB, "Failed to get approximate-memory-usage property\n");
return 0;
}
return parsed.value();
Expand Down
2 changes: 1 addition & 1 deletion src/flatfile.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -66,7 +66,7 @@ size_t FlatFileSeq::Allocate(const FlatFilePos& pos, size_t add_size, bool& out_
if (CheckDiskSpace(m_dir, inc_size)) {
FILE *file = Open(pos);
if (file) {
LogPrint(BCLog::VALIDATION, "Pre-allocating up to position 0x%x in %s%05u.dat\n", new_size, m_prefix, pos.nFile);
LogDebug(BCLog::VALIDATION, "Pre-allocating up to position 0x%x in %s%05u.dat\n", new_size, m_prefix, pos.nFile);
AllocateFileRange(file, pos.nPos, inc_size);
fclose(file);
return inc_size;
Expand Down
Loading

0 comments on commit d4cc0c6

Please sign in to comment.