log: Use more severe log level (warn/err) where appropriate

maflcko commented at 10:05 am on November 27, 2025: member

Logging supports severity levels above info via the legacy LogPrintf. So use the more appropriate LogError or LogWarning, where it applies.

This has a few small benefits:

It often allows to remove the manual and literal “error: “, “Warning:”, … prefixes. Instead the uniform log level formatting is used.
It is easier to grep or glance for more severe logs, which indicate some kind of alert.
LogPrintf didn’t indicate any severity level, but it is an alias for LogInfo. So having the log level explicitly spelled out makes it easier to read the code.
Also, remove the redundant trailing \n newline, while touching.
Also, remove the __func__ formatting in the log string, which is redundant with -logsourcelocations. Instead, use a unique log string for each location.

doc: Fix typo in init log 22229de728

DrahtBot added the label Utils/log/libs on Nov 27, 2025

DrahtBot commented at 10:05 am on November 27, 2025: contributor

The following sections might be updated with supplementary metadata relevant to reviewers and maintainers.

Code Coverage & Benchmarks

For details see: https://corecheck.dev/bitcoin/bitcoin/pulls/33960.

Reviews

See the guideline for information on the review process.

Type	Reviewers
ACK	l0rinc, rkrux
Concept ACK	stickies-v

If your review is incorrectly listed, please copy-paste <!–meta-tag:bot-skip–> into the comment that the bot should ignore.

Conflicts

Reviewers, this pull request conflicts with the following ones:

#33813 (init: Changing the rpcbind argument being ignored to a pop up warning by Ataraxia009)
#33689 (http: replace WorkQueue and single threads handling for ThreadPool by furszy)
#33680 (validation: do not wipe utxo cache for stats/scans/snapshots by l0rinc)
#33646 (log: check fclose() results and report safely in logging.cpp by cedwies)
#33553 (validation: Improve warnings in case of chain corruption by mzumsande)
#33414 (tor: enable PoW defenses for automatically created hidden services by vasild)
#33192 (refactor: unify container presence checks by l0rinc)
#33034 (wallet: Store transactions in a separate sqlite table by achow101)
#33033 (wallet, sqlite: Encapsulate SQLite statements in a RAII class by achow101)
#32685 (wallet: Allow read-only database access for info and dump commands by PeterWrighten)
#32387 (ipc: add windows support by ryanofsky)
#32317 (kernel: Separate UTXO set access from validation functions by sedited)
#32297 (bitcoin-cli: Add -ipcconnect option by ryanofsky)
#32061 (Replace libevent with our own HTTP and socket-handling implementation by pinheadmz)
#30214 (refactor: Improve assumeutxo state representation by ryanofsky)
#29700 (kernel, refactor: return error status on all fatal errors by ryanofsky)
#29641 (scripted-diff: Use LogInfo over LogPrintf [WIP, NOMERGE, DRAFT] by maflcko)

If you consider this pull request important, please also help to review the conflicting pull requests. Ideally, start with the one that should be merged first.

DrahtBot added the label CI failed on Nov 27, 2025

maflcko force-pushed on Nov 27, 2025

in src/validation.cpp:4752 in fa0d6c6040

4749+        LogError("Verification error: coin database inconsistencies found (last %i blocks, %i good transactions before that)", chainstate.m_chain.Height() - pindexFailure->nHeight + 1, nGoodTransactions);
4750         return VerifyDBResult::CORRUPTED_BLOCK_DB;
4751     }
4752     if (skipped_l3_checks) {
4753-        LogPrintf("Skipped verification of level >=3 (insufficient database cache size). Consider increasing -dbcache.\n");
4754+        LogError("Skipped verification of level >=3 (insufficient database cache size). Consider increasing -dbcache.");

l0rinc commented at 11:24 am on November 27, 2025:

hmmm, are you sure this is an error?

in src/util/exception.cpp:39 in fa0d6c6040

35@@ -36,6 +36,6 @@ static std::string FormatException(const std::exception* pex, std::string_view t
36 void PrintExceptionContinue(const std::exception* pex, std::string_view thread_name)
37 {
38     std::string message = FormatException(pex, thread_name);
39-    LogPrintf("\n\n************************\n%s\n", message);
40+    LogWarning("\n\n************************\n%s\n", message);

l0rinc commented at 11:25 am on November 27, 2025:

Is there any particular reason for keeping the trailing newline here?

0    LogWarning("\n\n************************\n%s", message);

in src/dbwrapper.cpp:51 in fa0d6c6040

46@@ -47,8 +47,8 @@ static void HandleError(const leveldb::Status& status)
47     if (status.ok())
48         return;
49     const std::string errmsg = "Fatal LevelDB error: " + status.ToString();
50-    LogPrintf("%s\n", errmsg);
51-    LogPrintf("You can use -debug=leveldb to get more complete diagnostic messages\n");
52+    LogWarning("%s", errmsg);
53+    LogWarning("You can use -debug=leveldb to get more complete diagnostic messages");

l0rinc commented at 11:26 am on November 27, 2025:

If it’sFatal, shouldn’t it be a LogError?

in src/wallet/sqlite.cpp:294 in fa0d6c6040

290@@ -291,7 +291,7 @@ void SQLiteDatabase::Open()
291 
292     if (m_use_unsafe_sync) {
293         // Use normal synchronous mode for the journal
294-        LogPrintf("WARNING SQLite is configured to not wait for data to be flushed to disk. Data loss and corruption may occur.\n");
295+        LogWarning("WARNING SQLite is configured to not wait for data to be flushed to disk. Data loss and corruption may occur.");

l0rinc commented at 11:28 am on November 27, 2025:

do we need to keep the WARNING prefix here?

0        LogWarning("SQLite is configured to not wait for data to be flushed to disk. Data loss and corruption may occur.");

in src/init.cpp:1345 in fa0d6c6040

1341@@ -1342,7 +1342,7 @@ static ChainstateLoadResult InitAndLoadChainstate(
1342             index->Interrupt();
1343             index->Stop();
1344             if (!(index->Init() && index->StartBackgroundSync())) {
1345-                LogPrintf("[snapshot] WARNING failed to restart index %s on snapshot chain\n", index->GetName());
1346+                LogWarning("[snapshot] WARNING failed to restart index %s on snapshot chain", index->GetName());

l0rinc commented at 11:29 am on November 27, 2025:

same:

0                LogWarning("[snapshot] Failed to restart index %s on snapshot chain", index->GetName());

in src/httpserver.cpp:335 in fa0d6c6040

331@@ -332,7 +332,7 @@ static void http_request_cb(struct evhttp_request* req, void* arg)
332         if (g_work_queue->Enqueue(item.get())) {
333             item.release(); /* if true, queue took ownership */
334         } else {
335-            LogPrintf("WARNING: request rejected because http work queue depth exceeded, it can be increased with the -rpcworkqueue= setting\n");
336+            LogWarning("request rejected because http work queue depth exceeded, it can be increased with the -rpcworkqueue= setting");

l0rinc commented at 11:29 am on November 27, 2025:

0            LogWarning("Request rejected because http work queue depth exceeded, it can be increased with the -rpcworkqueue= setting");

in src/httpserver.cpp:605 in fa0d6c6040

601@@ -602,7 +602,7 @@ HTTPRequest::~HTTPRequest()
602 {
603     if (!replySent) {
604         // Keep track of whether reply was sent to avoid request leaks
605-        LogPrintf("%s: Unhandled request\n", __func__);
606+        LogWarning("Unhandled http request");

l0rinc commented at 11:29 am on November 27, 2025:

nit:

0        LogWarning("Unhandled HTTP request");

in src/wallet/sqlite.cpp:586 in fa0d6c6040

582@@ -583,8 +583,8 @@ SQLiteCursor::~SQLiteCursor()
583     sqlite3_reset(m_cursor_stmt);
584     int res = sqlite3_finalize(m_cursor_stmt);
585     if (res != SQLITE_OK) {
586-        LogPrintf("%s: cursor closed but could not finalize cursor statement: %s\n",
587-                  __func__, sqlite3_errstr(res));
588+        LogWarning("cursor closed but could not finalize cursor statement: %s",

l0rinc commented at 11:30 am on November 27, 2025:

0        LogWarning("Cursor closed but could not finalize cursor statement: %s",

in src/httpserver.cpp:465 in fa0d6c6040

461@@ -462,7 +462,7 @@ bool InitHTTPServer(const util::SignalInterrupt& interrupt)
462     raii_evhttp http_ctr = obtain_evhttp(base_ctr.get());
463     struct evhttp* http = http_ctr.get();
464     if (!http) {
465-        LogPrintf("couldn't create evhttp. Exiting.\n");
466+        LogError("couldn't create evhttp. Exiting.");

l0rinc commented at 11:31 am on November 27, 2025:

0        LogError("Couldn't create evhttp. Exiting.");

in src/validation.cpp:5638 in fa0d6c6040

5634@@ -5635,7 +5635,7 @@ Chainstate& ChainstateManager::InitializeChainstate(CTxMemPool* mempool)
5635     const bool destroyed = DestroyDB(path_str);
5636 
5637     if (!destroyed) {
5638-        LogPrintf("error: leveldb DestroyDB call failed on %s\n", path_str);
5639+        LogWarning("error: leveldb DestroyDB call failed on %s", path_str);

l0rinc commented at 11:33 am on November 27, 2025:

So is this a warning or an error?

in src/validation.cpp:6419 in fa0d6c6040 outdated

6415@@ -6416,8 +6416,8 @@ bool ChainstateManager::ValidatedSnapshotCleanup()
6416     // is in-memory, in which case we can't do on-disk cleanup. You'd better be
6417     // in a unittest!
6418     if (!ibd_chainstate_path_maybe || !snapshot_chainstate_path_maybe) {
6419-        LogPrintf("[snapshot] snapshot chainstate cleanup cannot happen with "
6420-                  "in-memory chainstates. You are testing, right?\n");
6421+        LogError("[snapshot] snapshot chainstate cleanup cannot happen with "

l0rinc commented at 11:38 am on November 27, 2025:

“You are testing, right?” - what a weird error - should it be a warning since it seems to be a test-only config

maflcko commented at 12:35 pm on November 27, 2025:

hmm, probably should be an Assume(false), but I only want to change the logs here, not the other behavior. It is dead code either way.

edit: Actually went with making all internal BUGs also use LogError

in src/validation.cpp:1199 in fa0d6c6040 outdated

1195@@ -1196,7 +1196,7 @@ bool MemPoolAccept::ConsensusScriptChecks(const ATMPArgs& args, Workspace& ws)
1196     script_verify_flags currentBlockScriptVerifyFlags{GetBlockScriptFlags(*m_active_chainstate.m_chain.Tip(), m_active_chainstate.m_chainman)};
1197     if (!CheckInputsFromMempoolAndCache(tx, state, m_view, m_pool, currentBlockScriptVerifyFlags,
1198                                         ws.m_precomputed_txdata, m_active_chainstate.CoinsTip(), GetValidationCache())) {
1199-        LogPrintf("BUG! PLEASE REPORT THIS! CheckInputScripts failed against latest-block but not STANDARD flags %s, %s\n", hash.ToString(), state.ToString());
1200+        LogWarning("BUG! PLEASE REPORT THIS! CheckInputScripts failed against latest-block but not STANDARD flags %s, %s", hash.ToString(), state.ToString());

l0rinc commented at 11:39 am on November 27, 2025:

The message indicates this to be a bit more serious than a warning

maflcko commented at 12:36 pm on November 27, 2025:

hmm, probably should be an Assume(false), but I only want to change the logs here, not the other behavior. it is dead code either way.

edit: Actually went with making all internal BUGs also use LogError

in src/validation.cpp:3381 in fa0d6c6040

3377@@ -3378,8 +3378,8 @@ bool Chainstate::ActivateBestChain(BlockValidationState& state, std::shared_ptr<
3378     // Belt-and-suspenders check that we aren't attempting to advance the background
3379     // chainstate past the snapshot base block.
3380     if (WITH_LOCK(::cs_main, return m_disabled)) {
3381-        LogPrintf("m_disabled is set - this chainstate should not be in operation. "
3382-            "Please report this as a bug. %s\n", CLIENT_BUGREPORT);
3383+        LogWarning("m_disabled is set - this chainstate should not be in operation. "

l0rinc commented at 11:40 am on November 27, 2025:

same, the message indicates urgency, should it be an error instead?

in src/wallet/scriptpubkeyman.cpp:758 in fa0d6c6040 outdated

754@@ -755,7 +755,7 @@ std::optional<MigrationData> LegacyDataSPKM::MigrateToDescriptor()
755 
756     // Make sure that we have accounted for all scriptPubKeys
757     if (!Assume(spks.empty())) {
758-        LogPrintf("%s\n", STR_INTERNAL_BUG("Error: Some output scripts were not migrated.\n"));
759+        LogWarning("%s", STR_INTERNAL_BUG("Error: Some output scripts were not migrated."));

l0rinc commented at 11:40 am on November 27, 2025:

same, should it be an error instead?

maflcko commented at 12:36 pm on November 27, 2025:

I don’t think the node shuts down here (fatal error). Also, this is dead code, so I don’t think it matters much.

edit: Actually went with making all internal BUGs also use LogError

in src/wallet/scriptpubkeyman.cpp:892 in fa0d6c6040 outdated

888@@ -889,7 +889,7 @@ bool DescriptorScriptPubKeyMan::CheckDecryptionKey(const CKeyingMaterial& master
889             break;
890     }
891     if (keyPass && keyFail) {
892-        LogPrintf("The wallet is probably corrupted: Some keys decrypt but not all.\n");
893+        LogWarning("The wallet is probably corrupted: Some keys decrypt but not all.");

l0rinc commented at 11:41 am on November 27, 2025:

we’re throwing after this, shouldn’t it be an error?

maflcko commented at 12:36 pm on November 27, 2025:

Sure, but the node does not shut down (fatal error)

in src/flatfile.cpp:50 in fa0d6c6040 outdated

47     }
48     if (pos.nPos && fseek(file, pos.nPos, SEEK_SET)) {
49-        LogPrintf("Unable to seek to position %u of %s\n", pos.nPos, fs::PathToString(path));
50+        LogWarning("Unable to seek to position %u of %s", pos.nPos, fs::PathToString(path));
51         if (fclose(file) != 0) {
52             LogError("Unable to close file %s", fs::PathToString(path));

l0rinc commented at 11:42 am on November 27, 2025:

not being able to open is a warning but not being able to close is an error? I could imagine it vice-versa…

maflcko commented at 12:38 pm on November 27, 2025:

thx, fixed (they are all errors and shut down the node)

l0rinc changes_requested

l0rinc commented at 11:44 am on November 27, 2025: contributor

Thanks for addressing these! I have skimmed over the changes, I think some of the warning/error distinctions should be reconsidered.

DrahtBot removed the label CI failed on Nov 27, 2025

maflcko force-pushed on Nov 27, 2025

maflcko commented at 12:39 pm on November 27, 2025: member

thx, fixed all, except for those that are dead code anyway (left a reply there in the review thread)

rkrux commented at 12:52 pm on November 27, 2025: contributor

Maybe can also mention this benefit in the PR description that LogPrintf was unconditional logging that was deprecated while LogError and LogWarning use basic rate limiting to mitigate disk filling attacks.

https://github.com/bitcoin/bitcoin/blob/38c8474d0d774b1ed5d6139a9fec9933a6cfc099/src/logging.h#L364-L373

maflcko commented at 1:08 pm on November 27, 2025: member

Maybe can also mention this benefit in the PR description that LogPrintf was unconditional logging that was deprecated while LogError and LogWarning use basic rate limiting to mitigate disk filling attacks.

I don’t think this is correct. You can see from the code you quoted that the legacy one is just an alias for the one “modern” one. Also, all three have /*should_ratelimit=*/true.

rkrux commented at 1:18 pm on November 27, 2025: contributor

Ah, you are correct. I got carried away by the code comment below and assumed the code is like below (LogPrintLevel instead of LogInfo):

0// Deprecated unconditional logging. 
1#define LogPrintf(...) LogPrintLevel_(__VA_ARGS__)

log: Use LogError for fatal errors fa0018d011

log: Use LogWarning for non-critical logs

As per doc/developer-notes#logging, LogWarning should be used for severe
problems that do not warrant shutting down the node

fa45a1503e

maflcko force-pushed on Nov 27, 2025

l0rinc commented at 2:16 pm on November 27, 2025: contributor

Code review ACK fa45a1503eee603059166071857215ea9bd7242a

l0rinc approved

rkrux approved

rkrux commented at 8:44 am on November 28, 2025: contributor

crACK fa45a1503eee603059166071857215ea9bd7242a

The removal of the trailing \n seems fine as well because it is added later internally if not added by the caller.

fanquake requested review from stickies-v on Nov 28, 2025

in src/util/fs_helpers.cpp:1 in fa45a1503e

stickies-v commented at 11:21 am on November 28, 2025:

Seems to me like these should be LogWarning, a flush failing doesn’t inherently mean the node or subsystem must be shut down?

maflcko commented at 12:16 pm on November 28, 2025:

I think there will always be a possibility to argue one way or the other, when not all code paths lead to an immediate crash/shutdown. However, conceptually, even if there was a code path that would not result in a crash/shutdown on a failing FileCommit, it seems like it should propagate the error up as a fatal one.

Note that flushError results in an AbortNode, just like fatalError.

I understand that a flush failure in addrdb.cpp or mempool_persist.cpp does not lead to a fatal error later on, but this seems like a weak reason to not treat this as a serious alert. If those files fail to flush, Bitcoin Core will most likely run into a blockchain storage flush failure later on anyway. So might as well be honest and log it as error here.

In any case, I don’t think it matters much:

After all, this is just the debug log and either log level should be an improvement here, than the info level.
I don’t think anyone will, but if someone picks up #30364, the exact level picked here will be irrelevant.
Ideally, low level util functions should not be logging at all, but rather pass up a Result (possibly with an error string or error value). Once that is done, the exact level picked here will again be irrelevant.

stickies-v commented at 11:41 am on November 28, 2025: contributor

Concept ACK

I think LogError should be rare in utility/helper functions, and reserved for the places where the actual shutdown is initiated or inevitable (e.g. right before a assert, std::abort, Shutdown(), …).

We shouldn’t have to inspect a function’s callers in order to determine whether LogError is appropriate within that function. In fa0018d01102ad1d358eee20d8bae1e438ceebf8, what do you think about replacing LogError with LogWarning whenever we’re not actually shutting down? This may lead to some shutdowns not having an ERROR message (they currently don’t either), but I would rather address that by adding a LogError statement where it is necessary (can be done in later PRs)?

log: Use more severe log level (warn/err) where appropriate #33960

Code Coverage & Benchmarks

Reviews

Conflicts