wallet, logging: Replace WalletLogPrintf() with LogInfo()

ryanofsky commented at 5:57 pm on June 26, 2024: contributor

Make new logging macros LogDebug(), LogTrace(), LogInfo(), LogWarning(), and LogError() compatible with wallet code and drop custom WalletLogPrintf() function. The new logging macros introduced in #28318 weren’t previously useful in wallet code because wallet code prefixes most log messages with the wallet names to be be able to distinguish log output from multiple wallets. Fix this by introducing a new WalletLogSource class inheriting from BCLog::Source which can include the wallet name in log messages.

This is based on #29256. The non-base commits are:

DrahtBot commented at 5:57 pm on June 26, 2024: 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/30343.

Reviews

See the guideline for information on the review process. A summary of reviews will appear here.

Conflicts

Reviewers, this pull request conflicts with the following ones:

#32149 (wallet, migration: Fix empty wallet crash by pablomartin4btc)
#32023 (wallet: removed duplicate call to GetDescriptorScriptPubKeyMan by saikiran57)
#31423 (wallet: migration, don’t create spendable wallet from a watch-only legacy wallet by furszy)
#31398 (wallet: refactor: various master key encryption cleanups by theStack)
#31296 (wallet: Translate [default wallet] string in progress messages by ryanofsky)
#30221 (wallet: Ensure best block matches wallet scan state by achow101)
#29641 (scripted-diff: Use LogInfo over LogPrintf [WIP, NOMERGE, DRAFT] by maflcko)
#29415 (Broadcast own transactions only via short-lived Tor or I2P connections by vasild)
#29136 (wallet: addhdkey RPC to add just keys to wallets via new void(KEY) descriptor by achow101)
#28333 (wallet: Construct ScriptPubKeyMans with all data rather than loaded progressively by achow101)

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.

in src/wallet/wallet.h:448 in 5b30f17c22 outdated

444@@ -444,6 +445,8 @@ class CWallet final : public WalletStorage, public interfaces::Chain::Notificati
445      */
446     mutable RecursiveMutex cs_wallet;
447 
448+    WalletLogSource m_log;

hodlinator commented at 7:16 pm on June 26, 2024:

Why not rename GetLogSource() -> Log() here and in WalletStorage and keep m_log private? I tried and it compiles as of 5b30f17c22ade44d301aed5051a398fa38251ef7.

ryanofsky commented at 3:46 am on June 27, 2024:

re: #30343 (review)

Why not rename GetLogSource() -> Log() here and in WalletStorage and keep m_log private? I tried and it compiles as of 5b30f17.

Nice suggestion, implemented. This is much cleaner looking.

in src/wallet/walletdb.cpp:553 in 5b30f17c22 outdated

550             }
551 
552             DatabaseCursor::Status status = cursor->Next(key, value);
553             if (status != DatabaseCursor::Status::DONE) {
554-                pwallet->WalletLogPrintf("Error: Unexpected legacy entry found in descriptor wallet %s. The wallet might have been tampered with or created with malicious intent.\n", pwallet->GetName());
555+                LogInfo(log, "Error: Unexpected legacy entry found in descriptor wallet %s. The wallet might have been tampered with or created with malicious intent.\n", pwallet->GetName());

hodlinator commented at 7:19 pm on June 26, 2024:

Shouldn’t this be a LogError/LogWarning with removed Error: -prefix?

ryanofsky commented at 3:47 am on June 27, 2024:

re: #30343 (review)

Shouldn’t this be a LogError/LogWarning with removed Error: -prefix?

Agree that makes sense. I implemented it in a followup commit so the main commit is still a refactoring that does not change behavior.

For now I did not remove “Error:” and “Warning:” prefixes because it would be a more significant, possibly unwelcome change, since the prefixes could help messages stand out, and might be relied upon by tests. I’m also not sure if the decision to include warning and error prefixes has been discussed before somewhere else. But I’m happy to change this if there is more feedback in support of it.

in src/wallet/walletdb.cpp:987 in 5b30f17c22 outdated

984         std::string purpose_str;
985         value >> purpose_str;
986         std::optional<AddressPurpose> purpose{PurposeFromString(purpose_str)};
987         if (!purpose) {
988-            pwallet->WalletLogPrintf("Warning: nonstandard purpose string '%s' for address '%s'\n", purpose_str, strAddress);
989+            LogInfo(log, "Warning: nonstandard purpose string '%s' for address '%s'\n", purpose_str, strAddress);

hodlinator commented at 7:20 pm on June 26, 2024:

LogWarning?

ryanofsky commented at 3:47 am on June 27, 2024:

re: #30343 (review)

LogWarning?

Thanks, done in a new commit (see earlier comment)

in src/wallet/scriptpubkeyman.h:34 in 5b30f17c22 outdated

30@@ -31,6 +31,7 @@
31 enum class OutputType;
32 
33 namespace wallet {
34+class WalletLogSource;
35 struct MigrationData;
36 class ScriptPubKeyMan;

hodlinator commented at 7:25 pm on June 26, 2024:

nit: Should strive for alphabetical ordering?

ryanofsky commented at 3:46 am on June 27, 2024:

re: #30343 (review)

nit: Should strive for alphabetical ordering?

Yes, now piped these through sort

in src/wallet/wallet.cpp:3871 in 5b30f17c22 outdated

3867@@ -3866,13 +3868,13 @@ ScriptPubKeyMan* CWallet::AddWalletDescriptor(WalletDescriptor& desc, const Flat
3868     AssertLockHeld(cs_wallet);
3869 
3870     if (!IsWalletFlagSet(WALLET_FLAG_DESCRIPTORS)) {
3871-        WalletLogPrintf("Cannot add WalletDescriptor to a non-descriptor wallet\n");
3872+        LogInfo(m_log, "Cannot add WalletDescriptor to a non-descriptor wallet\n");

hodlinator commented at 7:48 pm on June 26, 2024:

Should maybe have been a warning all along?

ryanofsky commented at 3:46 am on June 27, 2024:

re: #30343 (review)

Should maybe have been a warning all along?

Good catch. It actually looks to me like all of the log prints in this function should be errors. I changed them to use LogError in a new commit. It’s a separate commit because the level change is a minor change in behavior, and is less obvious than other level changes.

maflcko commented at 5:41 am on June 27, 2024:

Are you sure that LogError is the right level? It should only be used for fatal errors where the node needs to shut down, according to the docs. This seems like a warning here, as suggested above.

Some wallet code can probably use Result and pass errors up, possibly here as well. And the caller can decide whether to log as a warning or return over RPC (or something else).

ryanofsky commented at 6:51 am on June 27, 2024:

Are you sure that LogError is the right level? It should only be used for fatal errors where the node needs to shut down, according to the docs. This seems like a warning here, as suggested above.

Oh, that is interesting. The descriptions of those log levels in https://github.com/bitcoin/bitcoin/blob/b27afb7fb774809c9c075d56e44657e0b607a00c/doc/developer-notes.md#logging are much more severe than I would have expected. Based on those descriptions I would expect LogError to be called LogFatal and LogWarning to be called LogCritical. I would have expected LogError to be used for normal errors, and LogWarning to be used for normal warnings.

Maybe the naming would be worth following up on, but I don’t think it would be good to do in this PR. It actually seems like LogInfo is the right log level to use here, not LogWarning. Or do you disagree? Should I just drop the last two commits in this PR?

in src/wallet/wallet.cpp:2491 in 5b30f17c22 outdated

2489         }
2490 
2491         // Delete purpose entry
2492         if (!batch.ErasePurpose(dest)) {
2493-            WalletLogPrintf("Error: cannot erase address book entry purpose\n");
2494+            LogInfo(m_log, "Error: cannot erase address book entry purpose\n");

hodlinator commented at 7:50 pm on June 26, 2024:

LogInfo(m_log, "Error: -> LogError( here and in other places?

ryanofsky commented at 3:46 am on June 27, 2024:

re: #30343 (review)

LogInfo(m_log, "Error: -> LogError( here and in other places?

Thanks, done in a new commit (see earlier comment)

hodlinator commented at 10:17 pm on June 26, 2024: contributor

Went through this and the parent PR together. It was helpful to see how that other PR’s changes were used in this one.

ryanofsky referenced this in commit 8de95b3b5d on Jun 27, 2024

ryanofsky referenced this in commit 5a629a60c4 on Jun 27, 2024

ryanofsky force-pushed on Jun 27, 2024

ryanofsky commented at 4:13 am on June 27, 2024: contributor

Thanks for the review! The suggestions are a big improvement and make the logging code more succinct and clean.

Rebased 5b30f17c22ade44d301aed5051a398fa38251ef7 -> 5a629a60c4739b94383596f9d040502b7b2c8b69 (pr/gwlog.1 -> pr/gwlog.2, compare) on top of the updated parent PR implementing review suggestions.

ryanofsky referenced this in commit 1ac3f01fe5 on Jun 27, 2024

ryanofsky referenced this in commit db8c6fc2ca on Jun 27, 2024

ryanofsky force-pushed on Jun 27, 2024

DrahtBot added the label CI failed on Jun 27, 2024

DrahtBot commented at 4:35 am on June 27, 2024: contributor

🚧 At least one of the CI tasks failed. Make sure to run all tests locally, according to the documentation.

Possibly this is due to a silent merge conflict (the changes in this pull request being incompatible with the current code in the target branch). If so, make sure to rebase on the latest commit of the target branch.

Leave a comment here, if you need help tracking down a confusing failure.

Debug: https://github.com/bitcoin/bitcoin/runs/26740126920

ryanofsky commented at 4:36 am on June 27, 2024: contributor

Updated 5a629a60c4739b94383596f9d040502b7b2c8b69 -> db8c6fc2ca5e1ad99aeda741e3b453f1f7bf7955 (pr/gwlog.2 -> pr/gwlog.3, compare) fixing initialization order bug in last push

DrahtBot removed the label CI failed on Jun 27, 2024

ryanofsky referenced this in commit 6b5b2354c6 on Jun 28, 2024

ryanofsky referenced this in commit d486e49b54 on Jun 28, 2024

ryanofsky referenced this in commit b0c2f8203d on Jun 28, 2024

ryanofsky referenced this in commit 29eaec25af on Jun 28, 2024

ryanofsky force-pushed on Jun 28, 2024

ryanofsky commented at 2:27 pm on June 28, 2024: contributor

Updated and rebased db8c6fc2ca5e1ad99aeda741e3b453f1f7bf7955 -> 29eaec25af32e543df3cff091938c3cb8f7cce17 (pr/gwlog.3 -> pr/gwlog.4, compare) with suggestion to use constexpr Rebased 29eaec25af32e543df3cff091938c3cb8f7cce17 -> 0260cd5ccc3120102c001b3ab6c5f29dcf184b58 (pr/gwlog.4 -> pr/gwlog.5, compare) due to conflict with #30406 Rebased 0260cd5ccc3120102c001b3ab6c5f29dcf184b58 -> 0d49ada2b42e5b48b21bb7cb854851f09641abbb (pr/gwlog.5 -> pr/gwlog.6, compare) on top of updated base pr/bclog.20 Rebased 0d49ada2b42e5b48b21bb7cb854851f09641abbb -> f6b93a976b0127b55705dc33caf986a3344e12a4 (pr/gwlog.6 -> pr/gwlog.7, compare) due to conflict with #30485 Rebased f6b93a976b0127b55705dc33caf986a3344e12a4 -> 4c8fe044d3241664151b3727e31ac2eaa741b717 (pr/gwlog.7 -> pr/gwlog.8, compare) due to conflicts with #26619, #30659, and other PRs Rebased 4c8fe044d3241664151b3727e31ac2eaa741b717 -> e8c6095c75dead138e79a18146ce865e7fe6529a (pr/gwlog.8 -> pr/gwlog.9, compare) due to conflicts with #31061

glozow added the label Wallet on Jul 2, 2024

DrahtBot added the label Needs rebase on Jul 11, 2024

ryanofsky referenced this in commit 5cec69a56e on Jul 17, 2024

ryanofsky referenced this in commit 57346e0dea on Jul 17, 2024

ryanofsky referenced this in commit b9a3715858 on Jul 17, 2024

ryanofsky referenced this in commit 0260cd5ccc on Jul 17, 2024

ryanofsky force-pushed on Jul 17, 2024

DrahtBot removed the label Needs rebase on Jul 17, 2024

DrahtBot commented at 10:41 am on July 22, 2024: contributor

🚧 At least one of the CI tasks failed. Debug: https://github.com/bitcoin/bitcoin/runs/27589923083

Make sure to run all tests locally, according to the documentation.

The failure may happen due to a number of reasons, for example:

Possibly due to a silent merge conflict (the changes in this pull request being incompatible with the current code in the target branch). If so, make sure to rebase on the latest commit of the target branch.
A sanitizer issue, which can only be found by compiling with the sanitizer and running the affected test.
An intermittent issue.

Leave a comment here, if you need help tracking down a confusing failure.

DrahtBot added the label CI failed on Jul 22, 2024

DrahtBot removed the label CI failed on Jul 22, 2024

DrahtBot added the label Needs rebase on Jul 26, 2024

ryanofsky referenced this in commit c75687736a on Aug 7, 2024

ryanofsky referenced this in commit 0d51d583aa on Aug 7, 2024

ryanofsky force-pushed on Aug 7, 2024

ryanofsky referenced this in commit f16a846d79 on Aug 7, 2024

ryanofsky referenced this in commit 0d49ada2b4 on Aug 7, 2024

ryanofsky referenced this in commit 989f2ea404 on Aug 7, 2024

ryanofsky referenced this in commit f6b93a976b on Aug 7, 2024

ryanofsky referenced this in commit 5f6750a543 on Aug 7, 2024

ryanofsky referenced this in commit 517a4f1c0f on Aug 7, 2024

ryanofsky force-pushed on Aug 7, 2024

DrahtBot removed the label Needs rebase on Aug 7, 2024

DrahtBot added the label Needs rebase on Aug 15, 2024

ryanofsky referenced this in commit 8e9e7b90cd on Dec 9, 2024

ryanofsky referenced this in commit 4c8fe044d3 on Dec 9, 2024

ryanofsky referenced this in commit 980a494f6c on Dec 9, 2024

ryanofsky referenced this in commit 09fcfffd48 on Dec 9, 2024

ryanofsky force-pushed on Dec 9, 2024

DrahtBot removed the label Needs rebase on Dec 9, 2024

DrahtBot added the label Needs rebase on Jan 15, 2025

ryanofsky referenced this in commit b7e37883da on Mar 12, 2025

ryanofsky force-pushed on Mar 12, 2025

ryanofsky referenced this in commit e8c6095c75 on Mar 12, 2025

ryanofsky referenced this in commit 278ff86ca2 on Mar 12, 2025

ryanofsky referenced this in commit 6784d2baae on Mar 12, 2025

DrahtBot removed the label Needs rebase on Mar 12, 2025

log, test: Add test for currently accepted logging arguments

Test will be extended in next commit to cover support for context objects.

f62272d811

log, refactor: Allow log macros to accept context arguments

Allow LogDebug(), LogTrace(), LogInfo(), LogWarning(), and LogError() macros to
accept context arguments to provide more information in log messages and more
control over logging to callers.

This functionality is used in followup PRs:

- https://github.com/bitcoin/bitcoin/pull/30342 - To let libbitcoinkernel send
  output to specfic `BCLog::Logger` instances instead of a global instance, so
  output can be disambiguated and applications can have more control over
  logging.

- https://github.com/bitcoin/bitcoin/pull/30343 - To replace custom
  `WalletLogPrintf` calls with standard logging calls that automatically include
  wallet names and don't log everything at info level.

This commit does not change behavior of current log prints or require them to
be updated. It includes tests and documentation covering the new functionality.

Co-Authored-By: Hodlinator <172445034+hodlinator@users.noreply.github.com>

eaac991552

log, refactor: Add preprocessor workaround for MSVC

Needed to fix errors like:

const Context &GetContext(const Context &)': expects 1 arguments - 3 provided

due to a compiler bug:

https://stackoverflow.com/questions/5134523/msvc-doesnt-expand-va-args-correctly/5134656#5134656

Example CI failure:

https://github.com/bitcoin/bitcoin/actions/runs/8072891468/job/22055528830?pr=29256

6e41dfa317

log, refactor: Disallow category args to logging macros

Disallow passing BCLog category constants to LogInfo(), LogWarning(), and
LogError() macros, and disallow omitting BCLog categories when calling
LogDebug() and LogTrace() macros.

These restrictions have existed since the logging macros were added in #28318
and not technically neccessary, but are believed to be useful to prevent log
spam and prevent users from filtering out important messages based on category.

Co-Authored-By: Hodlinator <172445034+hodlinator@users.noreply.github.com>

093d58e055

Merge remote-tracking branch 'origin/pull/29256/head' e249f9d924

wallet, logging: Replace WalletLogPrintf() with LogInfo()

Make new logging macros LogDebug(), LogTrace(), LogInfo(), LogWarning(), and
LogError() compatible with wallet code and drop custom WalletLogPrintf()
function. The new logging macros introduced in #28318 weren't previously useful
in wallet code because wallet code prefixes most log messages with the wallet
names to be be able to distinguish log output from multiple wallets. Fix this
by introducing a new WalletLogContext class inheriting from BCLog::Context
which can include the wallet name in log messages

fea5da15ee

wallet, logging: Switch LogInfo to LogWarning/LogError

Switch to LogWarning / LogError in obvious places where wallet code is clearly outputting warnings and errors.

Suggested by hodlinator in
https://github.com/bitcoin/bitcoin/pull/30343#discussion_r1655406670
https://github.com/bitcoin/bitcoin/pull/30343#discussion_r1655407301
https://github.com/bitcoin/bitcoin/pull/30343#discussion_r1655436010

e6f21513ed

wallet, logging: Switch LogInfo to LogError in AddWalletDescriptor

Seems like all of these cases are treated as errors, so it makes sense to use
the corresponding log level.

Change suggested by hodlinator in https://github.com/bitcoin/bitcoin/pull/30343#discussion_r1655434943

2e4d0c3b51

ryanofsky referenced this in commit 6d0745d22b on Apr 3, 2025

ryanofsky referenced this in commit 1218acc259 on Apr 3, 2025

ryanofsky referenced this in commit af6f854df0 on Apr 3, 2025

ryanofsky force-pushed on Apr 3, 2025

ryanofsky referenced this in commit c3161fcac9 on Apr 3, 2025

ryanofsky referenced this in commit 4a10cb6ed9 on Apr 3, 2025

ryanofsky referenced this in commit 2be41ef85f on Apr 3, 2025

ryanofsky referenced this in commit c96e91eced on Apr 4, 2025

ryanofsky referenced this in commit a7266cfc9d on Apr 4, 2025

ryanofsky force-pushed on Apr 4, 2025

DrahtBot added the label CI failed on Apr 4, 2025

DrahtBot commented at 3:37 am on April 4, 2025: contributor

🚧 At least one of the CI tasks failed. Debug: https://github.com/bitcoin/bitcoin/runs/39937553048

Try to run the tests locally, according to the documentation. However, a CI failure may still happen due to a number of reasons, for example:

Possibly due to a silent merge conflict (the changes in this pull request being incompatible with the current code in the target branch). If so, make sure to rebase on the latest commit of the target branch.
A sanitizer issue, which can only be found by compiling with the sanitizer and running the affected test.
An intermittent issue.

Leave a comment here, if you need help tracking down a confusing failure.

DrahtBot removed the label CI failed on Apr 4, 2025

DrahtBot commented at 1:25 am on April 10, 2025: contributor

🐙 This pull request conflicts with the target branch and needs rebase.

DrahtBot added the label Needs rebase on Apr 10, 2025

wallet, logging: Replace WalletLogPrintf() with LogInfo() #30343

Code Coverage & Benchmarks

Reviews

Conflicts