log: Use ConstevalFormatString #30889

nit: The Params name was already used in scriptpubkeyman.h and wallet.h before the PR but Args is used in util/string.h, index/base.h/cpp, netbase.cpp and used to be used here. Why switch and touch 2 additional lines?

The old way feels more consistent with the C "varargs". But maybe there's a convincing argument for "Params".

Did the change locally and it compiles without causing any non-obvious issue.

Ok, done

nit: Line grows from 209 to 253 chars, please consider inserting line break(s).

inline void LogPrintFormatInternal(std::string_view logging_function, std::string_view source_file, const int source_line,
    const BCLog::LogFlags flag, const BCLog::Level level, util::ConstevalFormatString<sizeof...(Params)> fmt, const Params&... params)

See https://github.com/bitcoin/bitcoin/blob/6fc4692797121b54de0c54e5b09ee47f322c038a/src/.clang-format#L23, so I'll leave this as-is for now.

nit: maybe we could dogfood this and use:

            log_msg = tfm::format("Error \"%s\" while formatting log message: %s", fmterr.what(), fmt.fmt);

No. It seems fragile to fall back to tinyformat when a tinyformat error occurred. Even if unlikley, that just seems like it could lead to another tfm exception, rendering this whole code useless in the first place.

I understand (and somewhat share) the reasoning, but doesn't this mean that we don't trust tfm::format even in a fixed case? E.g. isn't it possible after this call for log_msg to contain dangling format specifiers, which would be passed on to LogInfo anyway?

doesn't this mean that we don't trust tfm::format even in a fixed case?

See #30889 (comment), but this should never happen. So I don't think micro-optimizing this is worth it.

Ok, what about the case when fmterr.what() contains formatting, like %s?

Ok, what about the case when fmterr.what() contains formatting, like %s?

It may or may not contain it. It doesn't matter either way. Also, I am not changing that (or any behavior). So a separate issue or pull request seems better.

Should this always be info? Some WalletLogPrintf usages seem like warnings, or errors.

A refactor is not allowed to change behavior. If you want to change behavior, a separate issue or pull request seems more appropriate.

Added "This refactor does not change behavior of the compiled executables." to the pull description and applied the label.

That's my concern as well, it seems to me we're changing behavior (or at least meaning) here by swapping a neutral LogPrintf to Info level logging, when in fact it's sometimes a warning or error.

LogInfo is neutral, because there is no level. See GetLogPrefix:

    // If there is no category, Info is implied
    if (!has_category && level == Level::Info) return {};

In any case, it is literally a macro alias:

// Deprecated unconditional logging.
#define LogPrintf(...) LogInfo(__VA_ARGS__)

Got it, thanks. Would it make sense to add an optional log-level parameter here to be able to set some of those logs to errors/warns in a future PR?

Would it make sense ... in a future PR?

I don't know and I don't think it matters much one way or the other.

Got it, thanks.

Ok, resolving this for now.

clever workaround

By not letting LogInfo do the formatting, there's no tinyformat::format_error error handling anymore. This makes the code less robust to the malformed format strings we do not catch at compile time. For example, with this diff:

diff --git a/src/wallet/wallet.cpp b/src/wallet/wallet.cpp
index 83e96adf07..e6a2576f0a 100644
--- a/src/wallet/wallet.cpp
+++ b/src/wallet/wallet.cpp
@@ -3822,7 +3822,7 @@ void CWallet::LoadActiveScriptPubKeyMan(uint256 id, OutputType type, bool intern
     // Legacy wallets have only one ScriptPubKeyManager and it's active for all output and change types.
     Assert(IsWalletFlagSet(WALLET_FLAG_DESCRIPTORS));
 
-    WalletLogPrintf("Setting spkMan to active: id = %s, type = %s, internal = %s\n", id.ToString(), FormatOutputType(type), internal ? "true" : "false");
+    WalletLogPrintf("Setting spkMan to active: id = %s, type = %s, internal = %*s\n", id.ToString(), FormatOutputType(type), internal ? "true" : "false");
     auto& spk_mans = internal ? m_internal_spk_managers : m_external_spk_managers;
     auto& spk_mans_other = internal ? m_external_spk_managers : m_internal_spk_managers;
     auto spk_man = m_spk_managers.at(id).get();

on master, this would still allow a wallet to be loaded (with just the logging failing):

% bitcoin-cli loadwallet test
{
  "name": "test"
}

...

2024-09-19T10:32:57Z init message: Loading wallet…
2024-09-19T10:32:57Z [test] Wallet file version = 10500, last client version = 289900
2024-09-19T10:32:57Z [test] Descriptors: 8, Descriptor Keys: 1 plaintext, 0 encrypted, 1 total.
2024-09-19T10:32:57Z Error "tinyformat: Cannot convert from argument type to integer for use as variable width or precision" while formatting log message: %s Setting spkMan to active: id = %s, type = %s, internal = %*s
2024-09-19T10:32:57Z Error "tinyformat: Cannot convert from argument type to integer for use as variable width or precision" while formatting log message: %s Setting spkMan to active: id = %s, type = %s, internal = %*s
2024-09-19T10:32:57Z Error "tinyformat: Cannot convert from argument type to integer for use as variable width or precision" while formatting log message: %s Setting spkMan to active: id = %s, type = %s, internal = %*s
2024-09-19T10:32:57Z Error "tinyformat: Cannot convert from argument type to integer for use as variable width or precision" while formatting log message: %s Setting spkMan to active: id = %s, type = %s, internal = %*s
2024-09-19T10:32:57Z Error "tinyformat: Cannot convert from argument type to integer for use as variable width or precision" while formatting log message: %s Setting spkMan to active: id = %s, type = %s, internal = %*s
2024-09-19T10:32:57Z Error "tinyformat: Cannot convert from argument type to integer for use as variable width or precision" while formatting log message: %s Setting spkMan to active: id = %s, type = %s, internal = %*s
2024-09-19T10:32:57Z Error "tinyformat: Cannot convert from argument type to integer for use as variable width or precision" while formatting log message: %s Setting spkMan to active: id = %s, type = %s, internal = %*s
2024-09-19T10:32:57Z Error "tinyformat: Cannot convert from argument type to integer for use as variable width or precision" while formatting log message: %s Setting spkMan to active: id = %s, type = %s, internal = %*s
2024-09-19T10:32:57Z [test] Wallet completed loading in             281ms

whereas on facbcd4cef8890ae18976fb53b67ea56b3c04454, you get:

% bitcoin-cli loadwallet test
error code: -4
error message:
Wallet loading failed. Error loading <...>/signet/wallets/test/wallet.dat: Wallet corrupted

...

2024-09-19T11:00:08Z init message: Loading wallet…
2024-09-19T11:00:08Z [test] Wallet file version = 10500, last client version = 289900
2024-09-19T11:00:09Z [test] Descriptors: 8, Descriptor Keys: 1 plaintext, 0 encrypted, 1 total.
2024-09-19T11:00:09Z [test] Releasing wallet test..

Similar concern in scriptpubkeyman.h.

Good point and good catch. This should be trivial to fix by using a macro approach to concatenate the two format strings. (In C++ "a" "b" is equivalent to "ab"). A macro approach was my initial implementation when I wrote this in July, but the benefit wasn't clear, so I switched to this. Basically,

• Breaking this requires an intentionally malformed format string, such as %n or %*s, which may or may not be caught during review.
• The wallet logging is unconditional, so this requires the code to be completely untested. Otherwise tests would hopefully catch the intentional malformed format string before review.
• There are many other places where tinyformat is used without a catch, so it is unclear why it should be checked here, but not in the other places.

But again, it should be trivial to add this back, if reviewers think this would be useful to add back.

Addressed in #30928.

You're right that the unconditional logging should make these errors quite likely to be caught in review, and that there is no consistency in when we catch formatting exceptions or not. In #30928 I tried to address the latter by enforcing run-time exceptions are handled whenever we use util::ConstevalFormatString, which should correlate with needing to prioritize run-time robustness.

is there a conceptual difference between Args (used here) and Params (used in WalletLogPrintf)?

No

So can we unify the two and use only one to avoid confusion?

I don't want to touch lines in this pull request that don't have to be touched. Also, I don't want to increase the scope here.