diff options
-rwxr-xr-x | ci/test/00_setup_env_native_qt5.sh | 4 | ||||
-rwxr-xr-x | contrib/macdeploy/detached-sig-create.sh | 2 | ||||
-rw-r--r-- | depends/Makefile | 1 | ||||
-rw-r--r-- | depends/README.md | 3 | ||||
-rw-r--r-- | depends/config.site.in | 4 | ||||
-rw-r--r-- | doc/developer-notes.md | 45 | ||||
-rw-r--r-- | src/bitcoin-cli.cpp | 12 | ||||
-rw-r--r-- | src/httpserver.cpp | 5 | ||||
-rw-r--r-- | src/i2p.cpp | 4 | ||||
-rw-r--r-- | src/init.cpp | 2 | ||||
-rw-r--r-- | src/init/common.cpp | 2 | ||||
-rw-r--r-- | src/logging.cpp | 56 | ||||
-rw-r--r-- | src/logging.h | 31 | ||||
-rw-r--r-- | src/net.cpp | 15 | ||||
-rw-r--r-- | src/net.h | 7 | ||||
-rw-r--r-- | src/net_processing.cpp | 2 | ||||
-rw-r--r-- | src/test/fuzz/connman.cpp | 4 | ||||
-rw-r--r-- | src/test/logging_tests.cpp | 42 | ||||
-rw-r--r-- | src/torcontrol.cpp | 2 | ||||
-rwxr-xr-x | test/functional/feature_assumeutxo.py | 20 | ||||
-rwxr-xr-x | test/functional/wallet_migration.py | 35 | ||||
-rwxr-xr-x | test/lint/lint-format-strings.py | 5 |
22 files changed, 224 insertions, 79 deletions
diff --git a/ci/test/00_setup_env_native_qt5.sh b/ci/test/00_setup_env_native_qt5.sh index f351298f1e..2492cfb58c 100755 --- a/ci/test/00_setup_env_native_qt5.sh +++ b/ci/test/00_setup_env_native_qt5.sh @@ -9,8 +9,8 @@ export LC_ALL=C.UTF-8 export CONTAINER_NAME=ci_native_qt5 export CI_IMAGE_NAME_TAG="docker.io/debian:bullseye" # Use minimum supported python3.9 and gcc-10, see doc/dependencies.md -export PACKAGES="gcc-10 g++-10 python3-zmq qtbase5-dev qttools5-dev-tools libdbus-1-dev libharfbuzz-dev" -export DEP_OPTS="NO_QT=1 NO_UPNP=1 NO_NATPMP=1 DEBUG=1 ALLOW_HOST_PACKAGES=1 CC=gcc-10 CXX=g++-10" +export PACKAGES="gcc-10 g++-10 python3-zmq" +export DEP_OPTS="NO_UPNP=1 NO_NATPMP=1 DEBUG=1 CC=gcc-10 CXX=g++-10" export TEST_RUNNER_EXTRA="--previous-releases --coverage --extended --exclude feature_dbcrash" # Run extended tests so that coverage does not fail, but exclude the very slow dbcrash export RUN_UNIT_TESTS_SEQUENTIAL="true" export RUN_UNIT_TESTS="false" diff --git a/contrib/macdeploy/detached-sig-create.sh b/contrib/macdeploy/detached-sig-create.sh index 626381cf43..097a7c35ee 100755 --- a/contrib/macdeploy/detached-sig-create.sh +++ b/contrib/macdeploy/detached-sig-create.sh @@ -24,7 +24,7 @@ fi rm -rf ${TEMPDIR} mkdir -p ${TEMPDIR} -${SIGNAPPLE} sign -f --detach "${TEMPDIR}/${OUTROOT}" "$@" "${BUNDLE}" +${SIGNAPPLE} sign -f --detach "${TEMPDIR}/${OUTROOT}" "$@" "${BUNDLE}" --hardened-runtime tar -C "${TEMPDIR}" -czf "${OUT}" . rm -rf "${TEMPDIR}" diff --git a/depends/Makefile b/depends/Makefile index 319c3498df..558ddd60a0 100644 --- a/depends/Makefile +++ b/depends/Makefile @@ -242,7 +242,6 @@ $(host_prefix)/share/config.site : config.site.in $(host_prefix)/.stamp_$(final_ -e 's|@CXXFLAGS@|$(strip $(host_CXXFLAGS) $(host_$(release_type)_CXXFLAGS))|' \ -e 's|@CPPFLAGS@|$(strip $(host_CPPFLAGS) $(host_$(release_type)_CPPFLAGS))|' \ -e 's|@LDFLAGS@|$(strip $(host_LDFLAGS) $(host_$(release_type)_LDFLAGS))|' \ - -e 's|@allow_host_packages@|$(ALLOW_HOST_PACKAGES)|' \ -e 's|@no_qt@|$(NO_QT)|' \ -e 's|@no_qr@|$(NO_QR)|' \ -e 's|@no_zmq@|$(NO_ZMQ)|' \ diff --git a/depends/README.md b/depends/README.md index 8af5e36bfd..a33037b6a6 100644 --- a/depends/README.md +++ b/depends/README.md @@ -110,9 +110,6 @@ The following can be set when running make: `make FOO=bar` - `NO_UPNP`: Don't download/build/cache packages needed for enabling UPnP - `NO_NATPMP`: Don't download/build/cache packages needed for enabling NAT-PMP - `NO_USDT`: Don't download/build/cache packages needed for enabling USDT tracepoints -- `ALLOW_HOST_PACKAGES`: Packages that are missed in dependencies (due to `NO_*` option or - build script logic) are searched for among the host system packages using - `pkg-config`. It allows building with packages of other (newer) versions - `MULTIPROCESS`: Build libmultiprocess (experimental, requires CMake) - `DEBUG`: Disable some optimizations and enable more runtime checking - `HOST_ID_SALT`: Optional salt to use when generating host package ids diff --git a/depends/config.site.in b/depends/config.site.in index a6a5596bb8..9bc599e7cd 100644 --- a/depends/config.site.in +++ b/depends/config.site.in @@ -89,9 +89,7 @@ fi PKG_CONFIG="$(which pkg-config) --static" PKG_CONFIG_PATH="${depends_prefix}/share/pkgconfig:${depends_prefix}/lib/pkgconfig" -if test -z "@allow_host_packages@"; then - PKG_CONFIG_LIBDIR="${depends_prefix}/lib/pkgconfig" -fi +PKG_CONFIG_LIBDIR="${depends_prefix}/lib/pkgconfig" CPPFLAGS="-I${depends_prefix}/include/ ${CPPFLAGS}" LDFLAGS="-L${depends_prefix}/lib ${LDFLAGS}" diff --git a/doc/developer-notes.md b/doc/developer-notes.md index 00a3b2ea6d..1d670d39f1 100644 --- a/doc/developer-notes.md +++ b/doc/developer-notes.md @@ -725,6 +725,47 @@ General Bitcoin Core - *Explanation*: If the test suite is to be updated for a change, this has to be done first. +Logging +------- + +The macros `LogInfo`, `LogDebug`, `LogTrace`, `LogWarning` and `LogError` are available for +logging messages. They should be used as follows: + +- `LogDebug(BCLog::CATEGORY, fmt, params...)` is what you want + most of the time, and it should be used for log messages that are + 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, eg for startup + messages or for infrequent and important events such as a new block tip + being found or a new outbound connection being made. These log messages + are unconditional so care must be taken that they can't be used by an + attacker to fill up storage. Note that `LogPrintf(fmt, params...)` is + a deprecated alias for `LogInfo`. + +- `LogError(fmt, params...)` should be used in place of `LogInfo` for + severe problems that require the node (or a subsystem) to shut down + entirely (eg, insufficient storage space). + +- `LogWarning(fmt, params...)` should be used in place of `LogInfo` for + severe problems that the node admin should address, but are not + severe enough to warrant shutting down the node (eg, system time + appears to be wrong, unknown soft fork appears to have activated). + +- `LogTrace(BCLog::CATEGORY, fmt, params...) should be used in place of + `LogDebug` for log messages that would be unusable on a production + system, eg due to being too noisy in normal use, or too resource + intensive to process. These will be logged if the startup + options `-debug=category -loglevel=category:trace` or `-debug=1 + -loglevel=trace` are selected. + +Note that the format strings and parameters of `LogDebug` and `LogTrace` +are only evaluated if the logging category is enabled, so you must be +careful to avoid side-effects in those expressions. + Wallet ------- @@ -887,7 +928,7 @@ Strings and formatting `wcstoll`, `wcstombs`, `wcstoul`, `wcstoull`, `wcstoumax`, `wcswidth`, `wcsxfrm`, `wctob`, `wctomb`, `wctrans`, `wctype`, `wcwidth`, `wprintf` -- For `strprintf`, `LogPrint`, `LogPrintf` formatting characters don't need size specifiers. +- For `strprintf`, `LogInfo`, `LogDebug`, etc formatting characters don't need size specifiers. - *Rationale*: Bitcoin Core uses tinyformat, which is type safe. Leave them out to avoid confusion. @@ -899,7 +940,7 @@ Strings and formatting - *Rationale*: Although this is guaranteed to be safe starting with C++11, `.data()` communicates the intent better. - - Do not use it when passing strings to `tfm::format`, `strprintf`, `LogPrint[f]`. + - Do not use it when passing strings to `tfm::format`, `strprintf`, `LogInfo`, `LogDebug`, etc. - *Rationale*: This is redundant. Tinyformat handles strings. diff --git a/src/bitcoin-cli.cpp b/src/bitcoin-cli.cpp index 45db7a9a66..03af80de75 100644 --- a/src/bitcoin-cli.cpp +++ b/src/bitcoin-cli.cpp @@ -406,6 +406,7 @@ private: std::string conn_type; std::string network; std::string age; + std::string transport_protocol_type; double min_ping; double ping; int64_t addr_processed; @@ -517,10 +518,11 @@ public: const std::string addr{peer["addr"].get_str()}; const std::string age{conn_time == 0 ? "" : ToString((time_now - conn_time) / 60)}; const std::string sub_version{peer["subver"].get_str()}; + const std::string transport{peer["transport_protocol_type"].get_str()}; const bool is_addr_relay_enabled{peer["addr_relay_enabled"].isNull() ? false : peer["addr_relay_enabled"].get_bool()}; const bool is_bip152_hb_from{peer["bip152_hb_from"].get_bool()}; const bool is_bip152_hb_to{peer["bip152_hb_to"].get_bool()}; - m_peers.push_back({addr, sub_version, conn_type, NETWORK_SHORT_NAMES[network_id], age, min_ping, ping, addr_processed, addr_rate_limited, last_blck, last_recv, last_send, last_trxn, peer_id, mapped_as, version, is_addr_relay_enabled, is_bip152_hb_from, is_bip152_hb_to, is_outbound, is_tx_relay}); + m_peers.push_back({addr, sub_version, conn_type, NETWORK_SHORT_NAMES[network_id], age, transport, min_ping, ping, addr_processed, addr_rate_limited, last_blck, last_recv, last_send, last_trxn, peer_id, mapped_as, version, is_addr_relay_enabled, is_bip152_hb_from, is_bip152_hb_to, is_outbound, is_tx_relay}); m_max_addr_length = std::max(addr.length() + 1, m_max_addr_length); m_max_addr_processed_length = std::max(ToString(addr_processed).length(), m_max_addr_processed_length); m_max_addr_rate_limited_length = std::max(ToString(addr_rate_limited).length(), m_max_addr_rate_limited_length); @@ -536,7 +538,7 @@ public: // Report detailed peer connections list sorted by direction and minimum ping time. if (DetailsRequested() && !m_peers.empty()) { std::sort(m_peers.begin(), m_peers.end()); - result += strprintf("<-> type net mping ping send recv txn blk hb %*s%*s%*s ", + result += strprintf("<-> type net tp mping ping send recv txn blk hb %*s%*s%*s ", m_max_addr_processed_length, "addrp", m_max_addr_rate_limited_length, "addrl", m_max_age_length, "age"); @@ -545,10 +547,11 @@ public: for (const Peer& peer : m_peers) { std::string version{ToString(peer.version) + peer.sub_version}; result += strprintf( - "%3s %6s %5s%7s%7s%5s%5s%5s%5s %2s %*s%*s%*s%*i %*s %-*s%s\n", + "%3s %6s %5s %2s%7s%7s%5s%5s%5s%5s %2s %*s%*s%*s%*i %*s %-*s%s\n", peer.is_outbound ? "out" : "in", ConnectionTypeForNetinfo(peer.conn_type), peer.network, + peer.transport_protocol_type == "detecting" ? "*" : peer.transport_protocol_type, PingTimeToString(peer.min_ping), PingTimeToString(peer.ping), peer.last_send ? ToString(time_now - peer.last_send) : "", @@ -570,7 +573,7 @@ public: IsAddressSelected() ? peer.addr : "", IsVersionSelected() && version != "0" ? version : ""); } - result += strprintf(" ms ms sec sec min min %*s\n\n", m_max_age_length, "min"); + result += strprintf(" ms ms sec sec min min %*s\n\n", m_max_age_length, "min"); } // Report peer connection totals by type. @@ -658,6 +661,7 @@ public: " \"feeler\" - short-lived connection for testing addresses\n" " \"addr\" - address fetch; short-lived connection for requesting addresses\n" " net Network the peer connected through (\"ipv4\", \"ipv6\", \"onion\", \"i2p\", \"cjdns\", or \"npr\" (not publicly routable))\n" + " tp Transport protocol used for the connection (\"v1\", \"v2\" or \"*\" if detecting)\n" " mping Minimum observed ping time, in milliseconds (ms)\n" " ping Last observed ping time, in milliseconds (ms)\n" " send Time since last message sent to the peer, in seconds\n" diff --git a/src/httpserver.cpp b/src/httpserver.cpp index e26ea6a596..71134d442f 100644 --- a/src/httpserver.cpp +++ b/src/httpserver.cpp @@ -463,7 +463,7 @@ bool InitHTTPServer(const util::SignalInterrupt& interrupt) LogPrint(BCLog::HTTP, "Initialized HTTP server\n"); int workQueueDepth = std::max((long)gArgs.GetIntArg("-rpcworkqueue", DEFAULT_HTTP_WORKQUEUE), 1L); - LogPrintfCategory(BCLog::HTTP, "creating work queue of depth %d\n", workQueueDepth); + LogDebug(BCLog::HTTP, "creating work queue of depth %d\n", workQueueDepth); g_work_queue = std::make_unique<WorkQueue<HTTPClosure>>(workQueueDepth); // transfer ownership to eventBase/HTTP via .release() @@ -485,9 +485,8 @@ static std::vector<std::thread> g_thread_http_workers; void StartHTTPServer() { - LogPrint(BCLog::HTTP, "Starting HTTP server\n"); int rpcThreads = std::max((long)gArgs.GetIntArg("-rpcthreads", DEFAULT_HTTP_THREADS), 1L); - LogPrintfCategory(BCLog::HTTP, "starting %d worker threads\n", rpcThreads); + LogInfo("Starting HTTP server with %d worker threads\n", rpcThreads); g_thread_http = std::thread(ThreadHTTP, eventBase); for (int i = 0; i < rpcThreads; i++) { diff --git a/src/i2p.cpp b/src/i2p.cpp index 685b43ba18..c891562d00 100644 --- a/src/i2p.cpp +++ b/src/i2p.cpp @@ -427,7 +427,7 @@ void Session::CreateIfNotCreatedAlready() const Reply& reply = SendRequestAndGetReply( *sock, strprintf("SESSION CREATE STYLE=STREAM ID=%s DESTINATION=TRANSIENT SIGNATURE_TYPE=7 " - "inbound.quantity=1 outbound.quantity=1", + "i2cp.leaseSetEncType=4,0 inbound.quantity=1 outbound.quantity=1", session_id)); m_private_key = DecodeI2PBase64(reply.Get("DESTINATION")); @@ -445,7 +445,7 @@ void Session::CreateIfNotCreatedAlready() SendRequestAndGetReply(*sock, strprintf("SESSION CREATE STYLE=STREAM ID=%s DESTINATION=%s " - "inbound.quantity=3 outbound.quantity=3", + "i2cp.leaseSetEncType=4,0 inbound.quantity=3 outbound.quantity=3", session_id, private_key_b64)); } diff --git a/src/init.cpp b/src/init.cpp index 39ee9fe60d..b825c8ce21 100644 --- a/src/init.cpp +++ b/src/init.cpp @@ -1545,7 +1545,7 @@ bool AppInitMain(NodeContext& node, interfaces::BlockAndHeaderTipInfo* tip_info) if (status == node::ChainstateLoadStatus::SUCCESS) { uiInterface.InitMessage(_("Verifying blocks…").translated); if (chainman.m_blockman.m_have_pruned && options.check_blocks > MIN_BLOCKS_TO_KEEP) { - LogPrintfCategory(BCLog::PRUNE, "pruned datadir may not have more than %d blocks; only checking available blocks\n", + LogWarning("pruned datadir may not have more than %d blocks; only checking available blocks\n", MIN_BLOCKS_TO_KEEP); } std::tie(status, error) = catch_exceptions([&]{ return VerifyLoadedChainstate(chainman, options);}); diff --git a/src/init/common.cpp b/src/init/common.cpp index f3f7c696c5..6560258ef5 100644 --- a/src/init/common.cpp +++ b/src/init/common.cpp @@ -40,6 +40,7 @@ void AddLoggingArgs(ArgsManager& argsman) #endif argsman.AddArg("-logsourcelocations", strprintf("Prepend debug output with name of the originating source location (source file, line number and function name) (default: %u)", DEFAULT_LOGSOURCELOCATIONS), ArgsManager::ALLOW_ANY, OptionsCategory::DEBUG_TEST); argsman.AddArg("-logtimemicros", strprintf("Add microsecond precision to debug timestamps (default: %u)", DEFAULT_LOGTIMEMICROS), ArgsManager::ALLOW_ANY | ArgsManager::DEBUG_ONLY, OptionsCategory::DEBUG_TEST); + argsman.AddArg("-loglevelalways", strprintf("Always prepend a category and level (default: %u)", DEFAULT_LOGLEVELALWAYS), ArgsManager::ALLOW_ANY, OptionsCategory::DEBUG_TEST); argsman.AddArg("-printtoconsole", "Send trace/debug info to console (default: 1 when no -daemon. To disable logging to file, set -nodebuglogfile)", ArgsManager::ALLOW_ANY, OptionsCategory::DEBUG_TEST); argsman.AddArg("-shrinkdebugfile", "Shrink debug.log file on client startup (default: 1 when no -debug)", ArgsManager::ALLOW_ANY, OptionsCategory::DEBUG_TEST); } @@ -55,6 +56,7 @@ void SetLoggingOptions(const ArgsManager& args) LogInstance().m_log_threadnames = args.GetBoolArg("-logthreadnames", DEFAULT_LOGTHREADNAMES); #endif LogInstance().m_log_sourcelocations = args.GetBoolArg("-logsourcelocations", DEFAULT_LOGSOURCELOCATIONS); + LogInstance().m_always_print_category_level = args.GetBoolArg("-loglevelalways", DEFAULT_LOGLEVELALWAYS); fLogIPs = args.GetBoolArg("-logips", DEFAULT_LOGIPS); } diff --git a/src/logging.cpp b/src/logging.cpp index 08bfa1f7a4..42f100ded6 100644 --- a/src/logging.cpp +++ b/src/logging.cpp @@ -126,9 +126,9 @@ bool BCLog::Logger::WillLogCategory(BCLog::LogFlags category) const bool BCLog::Logger::WillLogCategoryLevel(BCLog::LogFlags category, BCLog::Level level) const { - // Log messages at Warning and Error level unconditionally, so that + // Log messages at Info, Warning and Error level unconditionally, so that // important troubleshooting information doesn't get lost. - if (level >= BCLog::Level::Warning) return true; + if (level >= BCLog::Level::Info) return true; if (!WillLogCategory(category)) return false; @@ -202,7 +202,7 @@ bool GetLogCategory(BCLog::LogFlags& flag, const std::string& str) return false; } -std::string BCLog::Logger::LogLevelToStr(BCLog::Level level) const +std::string BCLog::Logger::LogLevelToStr(BCLog::Level level) { switch (level) { case BCLog::Level::Trace: @@ -215,8 +215,6 @@ std::string BCLog::Logger::LogLevelToStr(BCLog::Level level) const return "warning"; case BCLog::Level::Error: return "error"; - case BCLog::Level::None: - return ""; } assert(false); } @@ -307,8 +305,6 @@ static std::optional<BCLog::Level> GetLogLevel(const std::string& level_str) return BCLog::Level::Warning; } else if (level_str == "error") { return BCLog::Level::Error; - } else if (level_str == "none") { - return BCLog::Level::None; } else { return std::nullopt; } @@ -341,7 +337,7 @@ static constexpr std::array<BCLog::Level, 3> LogLevelsList() std::string BCLog::Logger::LogLevelsString() const { const auto& levels = LogLevelsList(); - return Join(std::vector<BCLog::Level>{levels.begin(), levels.end()}, ", ", [this](BCLog::Level level) { return LogLevelToStr(level); }); + return Join(std::vector<BCLog::Level>{levels.begin(), levels.end()}, ", ", [](BCLog::Level level) { return LogLevelToStr(level); }); } std::string BCLog::Logger::LogTimestampStr(const std::string& str) @@ -392,29 +388,39 @@ namespace BCLog { } } // namespace BCLog -void BCLog::Logger::LogPrintStr(const std::string& str, const std::string& logging_function, const std::string& source_file, int source_line, BCLog::LogFlags category, BCLog::Level level) +std::string BCLog::Logger::GetLogPrefix(BCLog::LogFlags category, BCLog::Level level) const { - StdLockGuard scoped_lock(m_cs); - std::string str_prefixed = LogEscapeMessage(str); + if (category == LogFlags::NONE) category = LogFlags::ALL; - if ((category != LogFlags::NONE || level != Level::None) && m_started_new_line) { - std::string s{"["}; + const bool has_category{m_always_print_category_level || category != LogFlags::ALL}; - if (category != LogFlags::NONE) { - s += LogCategoryToStr(category); - } + // If there is no category, Info is implied + if (!has_category && level == Level::Info) return {}; - if (category != LogFlags::NONE && level != Level::None) { - // Only add separator if both flag and level are not NONE - s += ":"; - } + std::string s{"["}; + if (has_category) { + s += LogCategoryToStr(category); + } - if (level != Level::None) { - s += LogLevelToStr(level); - } + if (m_always_print_category_level || !has_category || level != Level::Debug) { + // If there is a category, Debug is implied, so don't add the level + + // Only add separator if we have a category + if (has_category) s += ":"; + s += Logger::LogLevelToStr(level); + } + + s += "] "; + return s; +} - s += "] "; - str_prefixed.insert(0, s); +void BCLog::Logger::LogPrintStr(const std::string& str, const std::string& logging_function, const std::string& source_file, int source_line, BCLog::LogFlags category, BCLog::Level level) +{ + StdLockGuard scoped_lock(m_cs); + std::string str_prefixed = LogEscapeMessage(str); + + if (m_started_new_line) { + str_prefixed.insert(0, GetLogPrefix(category, level)); } if (m_log_sourcelocations && m_started_new_line) { diff --git a/src/logging.h b/src/logging.h index f7380d8928..525e0aec6d 100644 --- a/src/logging.h +++ b/src/logging.h @@ -25,6 +25,7 @@ static const bool DEFAULT_LOGIPS = false; static const bool DEFAULT_LOGTIMESTAMPS = true; static const bool DEFAULT_LOGTHREADNAMES = false; static const bool DEFAULT_LOGSOURCELOCATIONS = false; +static constexpr bool DEFAULT_LOGLEVELALWAYS = false; extern const char * const DEFAULT_DEBUGLOGFILE; extern bool fLogIPs; @@ -77,7 +78,6 @@ namespace BCLog { Info, // Default Warning, Error, - None, // Internal use only }; constexpr auto DEFAULT_LOG_LEVEL{Level::Debug}; @@ -120,10 +120,13 @@ namespace BCLog { bool m_log_time_micros = DEFAULT_LOGTIMEMICROS; bool m_log_threadnames = DEFAULT_LOGTHREADNAMES; bool m_log_sourcelocations = DEFAULT_LOGSOURCELOCATIONS; + bool m_always_print_category_level = DEFAULT_LOGLEVELALWAYS; fs::path m_file_path; std::atomic<bool> m_reopen_file{false}; + std::string GetLogPrefix(LogFlags category, Level level) const; + /** Send a string to the log output */ void LogPrintStr(const std::string& str, const std::string& logging_function, const std::string& source_file, int source_line, BCLog::LogFlags category, BCLog::Level level); @@ -194,7 +197,7 @@ namespace BCLog { std::string LogLevelsString() const; //! Returns the string representation of a log level. - std::string LogLevelToStr(BCLog::Level level) const; + static std::string LogLevelToStr(BCLog::Level level); bool DefaultShrinkDebugFile() const; }; @@ -234,22 +237,17 @@ static inline void LogPrintf_(const std::string& logging_function, const std::st #define LogPrintLevel_(category, level, ...) LogPrintf_(__func__, __FILE__, __LINE__, category, level, __VA_ARGS__) // Log unconditionally. -#define LogPrintf(...) LogPrintLevel_(BCLog::LogFlags::NONE, BCLog::Level::None, __VA_ARGS__) +#define LogInfo(...) LogPrintLevel_(BCLog::LogFlags::ALL, BCLog::Level::Info, __VA_ARGS__) +#define LogWarning(...) LogPrintLevel_(BCLog::LogFlags::ALL, BCLog::Level::Warning, __VA_ARGS__) +#define LogError(...) LogPrintLevel_(BCLog::LogFlags::ALL, BCLog::Level::Error, __VA_ARGS__) -// Log unconditionally, prefixing the output with the passed category name. -#define LogPrintfCategory(category, ...) LogPrintLevel_(category, BCLog::Level::None, __VA_ARGS__) +// Deprecated unconditional logging. +#define LogPrintf(...) LogInfo(__VA_ARGS__) +#define LogPrintfCategory(category, ...) LogPrintLevel_(category, BCLog::Level::Info, __VA_ARGS__) // Use a macro instead of a function for conditional logging to prevent // evaluating arguments when logging for the category is not enabled. -// Log conditionally, prefixing the output with the passed category name. -#define LogPrint(category, ...) \ - do { \ - if (LogAcceptCategory((category), BCLog::Level::Debug)) { \ - LogPrintLevel_(category, BCLog::Level::None, __VA_ARGS__); \ - } \ - } while (0) - // Log conditionally, prefixing the output with the passed category name and severity level. #define LogPrintLevel(category, level, ...) \ do { \ @@ -258,6 +256,13 @@ static inline void LogPrintf_(const std::string& logging_function, const std::st } \ } while (0) +// Log conditionally, prefixing the output with the passed category name. +#define LogDebug(category, ...) LogPrintLevel(category, BCLog::Level::Debug, __VA_ARGS__) +#define LogTrace(category, ...) LogPrintLevel(category, BCLog::Level::Trace, __VA_ARGS__) + +// Deprecated conditional logging +#define LogPrint(category, ...) LogDebug(category, __VA_ARGS__) + template <typename... Args> bool error(const char* fmt, const Args&... args) { diff --git a/src/net.cpp b/src/net.cpp index 41f5323d91..0cc794c2c3 100644 --- a/src/net.cpp +++ b/src/net.cpp @@ -2316,10 +2316,13 @@ void CConnman::ProcessAddrFetch() strDest = m_addr_fetches.front(); m_addr_fetches.pop_front(); } + // Attempt v2 connection if we support v2 - we'll reconnect with v1 if our + // peer doesn't support it or immediately disconnects us for another reason. + const bool use_v2transport(GetLocalServices() & NODE_P2P_V2); CAddress addr; CSemaphoreGrant grant(*semOutbound, /*fTry=*/true); if (grant) { - OpenNetworkConnection(addr, false, std::move(grant), strDest.c_str(), ConnectionType::ADDR_FETCH, /*use_v2transport=*/false); + OpenNetworkConnection(addr, false, std::move(grant), strDest.c_str(), ConnectionType::ADDR_FETCH, use_v2transport); } } @@ -2417,12 +2420,15 @@ void CConnman::ThreadOpenConnections(const std::vector<std::string> connect) // Connect to specific addresses if (!connect.empty()) { + // Attempt v2 connection if we support v2 - we'll reconnect with v1 if our + // peer doesn't support it or immediately disconnects us for another reason. + const bool use_v2transport(GetLocalServices() & NODE_P2P_V2); for (int64_t nLoop = 0;; nLoop++) { for (const std::string& strAddr : connect) { CAddress addr(CService(), NODE_NONE); - OpenNetworkConnection(addr, false, {}, strAddr.c_str(), ConnectionType::MANUAL, /*use_v2transport=*/false); + OpenNetworkConnection(addr, false, {}, strAddr.c_str(), ConnectionType::MANUAL, /*use_v2transport=*/use_v2transport); for (int i = 0; i < 10 && i < nLoop; i++) { if (!interruptNet.sleep_for(std::chrono::milliseconds(500))) @@ -2431,6 +2437,7 @@ void CConnman::ThreadOpenConnections(const std::vector<std::string> connect) } if (!interruptNet.sleep_for(std::chrono::milliseconds(500))) return; + PerformReconnections(); } } @@ -2840,11 +2847,11 @@ void CConnman::ThreadOpenAddedConnections() if (!interruptNet.sleep_for(std::chrono::milliseconds(500))) return; grant = CSemaphoreGrant(*semAddnode, /*fTry=*/true); } + // See if any reconnections are desired. + PerformReconnections(); // Retry every 60 seconds if a connection was attempted, otherwise two seconds if (!interruptNet.sleep_for(std::chrono::seconds(tried ? 60 : 2))) return; - // See if any reconnections are desired. - PerformReconnections(); } } @@ -1084,10 +1084,11 @@ public: vWhitelistedRange = connOptions.vWhitelistedRange; { LOCK(m_added_nodes_mutex); - + // Attempt v2 connection if we support v2 - we'll reconnect with v1 if our + // peer doesn't support it or immediately disconnects us for another reason. + const bool use_v2transport(GetLocalServices() & NODE_P2P_V2); for (const std::string& added_node : connOptions.m_added_nodes) { - // -addnode cli arg does not currently have a way to signal BIP324 support - m_added_node_params.push_back({added_node, false}); + m_added_node_params.push_back({added_node, use_v2transport}); } } m_onion_binds = connOptions.onion_binds; diff --git a/src/net_processing.cpp b/src/net_processing.cpp index df54a62f28..683a7aa10f 100644 --- a/src/net_processing.cpp +++ b/src/net_processing.cpp @@ -4405,7 +4405,7 @@ void PeerManagerImpl::ProcessMessage(CNode& pfrom, const std::string& msg_type, } if (received_new_header) { - LogPrintfCategory(BCLog::NET, "Saw new cmpctblock header hash=%s peer=%d\n", + LogInfo("Saw new cmpctblock header hash=%s peer=%d\n", blockhash.ToString(), pfrom.GetId()); } diff --git a/src/test/fuzz/connman.cpp b/src/test/fuzz/connman.cpp index 66f1e19b65..8f5f6a6071 100644 --- a/src/test/fuzz/connman.cpp +++ b/src/test/fuzz/connman.cpp @@ -40,7 +40,9 @@ FUZZ_TARGET(connman, .init = initialize_connman) fuzzed_data_provider.ConsumeBool()}; const uint64_t max_outbound_limit{fuzzed_data_provider.ConsumeIntegral<uint64_t>()}; - connman.Init({ .nMaxOutboundLimit = max_outbound_limit }); + CConnman::Options options; + options.nMaxOutboundLimit = max_outbound_limit; + connman.Init(options); CNetAddr random_netaddr; CNode random_node = ConsumeNode(fuzzed_data_provider); diff --git a/src/test/logging_tests.cpp b/src/test/logging_tests.cpp index e448805e69..88e3ec94b7 100644 --- a/src/test/logging_tests.cpp +++ b/src/test/logging_tests.cpp @@ -84,27 +84,32 @@ BOOST_FIXTURE_TEST_CASE(logging_LogPrintf_, LogSetup) { LogInstance().m_log_sourcelocations = true; LogPrintf_("fn1", "src1", 1, BCLog::LogFlags::NET, BCLog::Level::Debug, "foo1: %s\n", "bar1"); - LogPrintf_("fn2", "src2", 2, BCLog::LogFlags::NET, BCLog::Level::None, "foo2: %s\n", "bar2"); - LogPrintf_("fn3", "src3", 3, BCLog::LogFlags::NONE, BCLog::Level::Debug, "foo3: %s\n", "bar3"); - LogPrintf_("fn4", "src4", 4, BCLog::LogFlags::NONE, BCLog::Level::None, "foo4: %s\n", "bar4"); + LogPrintf_("fn2", "src2", 2, BCLog::LogFlags::NET, BCLog::Level::Info, "foo2: %s\n", "bar2"); + LogPrintf_("fn3", "src3", 3, BCLog::LogFlags::ALL, BCLog::Level::Debug, "foo3: %s\n", "bar3"); + LogPrintf_("fn4", "src4", 4, BCLog::LogFlags::ALL, BCLog::Level::Info, "foo4: %s\n", "bar4"); + LogPrintf_("fn5", "src5", 5, BCLog::LogFlags::NONE, BCLog::Level::Debug, "foo5: %s\n", "bar5"); + LogPrintf_("fn6", "src6", 6, BCLog::LogFlags::NONE, BCLog::Level::Info, "foo6: %s\n", "bar6"); std::ifstream file{tmp_log_path}; std::vector<std::string> log_lines; for (std::string log; std::getline(file, log);) { log_lines.push_back(log); } std::vector<std::string> expected = { - "[src1:1] [fn1] [net:debug] foo1: bar1", - "[src2:2] [fn2] [net] foo2: bar2", + "[src1:1] [fn1] [net] foo1: bar1", + "[src2:2] [fn2] [net:info] foo2: bar2", "[src3:3] [fn3] [debug] foo3: bar3", "[src4:4] [fn4] foo4: bar4", + "[src5:5] [fn5] [debug] foo5: bar5", + "[src6:6] [fn6] foo6: bar6", }; BOOST_CHECK_EQUAL_COLLECTIONS(log_lines.begin(), log_lines.end(), expected.begin(), expected.end()); } -BOOST_FIXTURE_TEST_CASE(logging_LogPrintMacros, LogSetup) +BOOST_FIXTURE_TEST_CASE(logging_LogPrintMacrosDeprecated, LogSetup) { LogPrintf("foo5: %s\n", "bar5"); LogPrint(BCLog::NET, "foo6: %s\n", "bar6"); + LogPrintLevel(BCLog::NET, BCLog::Level::Trace, "foo4: %s\n", "bar4"); // not logged LogPrintLevel(BCLog::NET, BCLog::Level::Debug, "foo7: %s\n", "bar7"); LogPrintLevel(BCLog::NET, BCLog::Level::Info, "foo8: %s\n", "bar8"); LogPrintLevel(BCLog::NET, BCLog::Level::Warning, "foo9: %s\n", "bar9"); @@ -118,11 +123,32 @@ BOOST_FIXTURE_TEST_CASE(logging_LogPrintMacros, LogSetup) std::vector<std::string> expected = { "foo5: bar5", "[net] foo6: bar6", - "[net:debug] foo7: bar7", + "[net] foo7: bar7", "[net:info] foo8: bar8", "[net:warning] foo9: bar9", "[net:error] foo10: bar10", - "[validation] foo11: bar11", + "[validation:info] foo11: bar11", + }; + BOOST_CHECK_EQUAL_COLLECTIONS(log_lines.begin(), log_lines.end(), expected.begin(), expected.end()); +} + +BOOST_FIXTURE_TEST_CASE(logging_LogPrintMacros, LogSetup) +{ + LogTrace(BCLog::NET, "foo6: %s\n", "bar6"); // not logged + LogDebug(BCLog::NET, "foo7: %s\n", "bar7"); + LogInfo("foo8: %s\n", "bar8"); + LogWarning("foo9: %s\n", "bar9"); + LogError("foo10: %s\n", "bar10"); + std::ifstream file{tmp_log_path}; + std::vector<std::string> log_lines; + for (std::string log; std::getline(file, log);) { + log_lines.push_back(log); + } + std::vector<std::string> expected = { + "[net] foo7: bar7", + "foo8: bar8", + "[warning] foo9: bar9", + "[error] foo10: bar10", }; BOOST_CHECK_EQUAL_COLLECTIONS(log_lines.begin(), log_lines.end(), expected.begin(), expected.end()); } diff --git a/src/torcontrol.cpp b/src/torcontrol.cpp index 11d13d050a..442c1c4d42 100644 --- a/src/torcontrol.cpp +++ b/src/torcontrol.cpp @@ -433,7 +433,7 @@ void TorController::add_onion_cb(TorControlConnection& _conn, const TorControlRe return; } service = LookupNumeric(std::string(service_id+".onion"), Params().GetDefaultPort()); - LogPrintfCategory(BCLog::TOR, "Got service ID %s, advertising service %s\n", service_id, service.ToStringAddrPort()); + LogInfo("Got tor service ID %s, advertising service %s\n", service_id, service.ToStringAddrPort()); if (WriteBinaryFile(GetPrivateKeyFile(), private_key)) { LogPrint(BCLog::TOR, "Cached service private key to %s\n", fs::PathToString(GetPrivateKeyFile())); } else { diff --git a/test/functional/feature_assumeutxo.py b/test/functional/feature_assumeutxo.py index 2e3589b020..f26a300f70 100755 --- a/test/functional/feature_assumeutxo.py +++ b/test/functional/feature_assumeutxo.py @@ -11,7 +11,6 @@ The assumeutxo value generated and used here is committed to in ## Possible test improvements -- TODO: test submitting a transaction and verifying it appears in mempool - TODO: test what happens with -reindex and -reindex-chainstate before the snapshot is validated, and make sure it's deleted successfully. @@ -35,11 +34,14 @@ Interesting starting states could be loading a snapshot when the current chain t """ from shutil import rmtree +from test_framework.messages import tx_from_hex from test_framework.test_framework import BitcoinTestFramework from test_framework.util import ( assert_equal, assert_raises_rpc_error, ) +from test_framework.wallet import getnewdestination + START_HEIGHT = 199 SNAPSHOT_BASE_HEIGHT = 299 @@ -207,6 +209,22 @@ class AssumeutxoTest(BitcoinTestFramework): assert_equal(n1.getblockchaininfo()["blocks"], SNAPSHOT_BASE_HEIGHT) + self.log.info("Submit a spending transaction for a snapshot chainstate coin to the mempool") + # spend the coinbase output of the first block that is not available on node1 + spend_coin_blockhash = n1.getblockhash(START_HEIGHT + 1) + assert_raises_rpc_error(-1, "Block not found on disk", n1.getblock, spend_coin_blockhash) + prev_tx = n0.getblock(spend_coin_blockhash, 3)['tx'][0] + prevout = {"txid": prev_tx['txid'], "vout": 0, "scriptPubKey": prev_tx['vout'][0]['scriptPubKey']['hex']} + privkey = n0.get_deterministic_priv_key().key + raw_tx = n1.createrawtransaction([prevout], {getnewdestination()[2]: 24.99}) + signed_tx = n1.signrawtransactionwithkey(raw_tx, [privkey], [prevout])['hex'] + signed_txid = tx_from_hex(signed_tx).rehash() + + assert n1.gettxout(prev_tx['txid'], 0) is not None + n1.sendrawtransaction(signed_tx) + assert signed_txid in n1.getrawmempool() + assert not n1.gettxout(prev_tx['txid'], 0) + PAUSE_HEIGHT = FINAL_HEIGHT - 40 self.log.info("Restarting node to stop at height %d", PAUSE_HEIGHT) diff --git a/test/functional/wallet_migration.py b/test/functional/wallet_migration.py index b171673be5..3d68dbe07a 100755 --- a/test/functional/wallet_migration.py +++ b/test/functional/wallet_migration.py @@ -932,6 +932,40 @@ class WalletMigrationTest(BitcoinTestFramework): assert_equal(len(watchonly_utxos), 1) assert_equal(watchonly_utxos[0]["reused"], True) + def test_preserve_tx_extra_info(self): + self.log.info("Test that tx extra data is preserved after migration") + def_wallet = self.nodes[0].get_wallet_rpc(self.default_wallet_name) + + # Create and fund wallet + wallet = self.create_legacy_wallet("persist_comments") + def_wallet.sendtoaddress(wallet.getnewaddress(), 2) + + self.generate(self.nodes[0], 6) + + # Create tx and bump it to store 'replaced_by_txid' and 'replaces_txid' data within the transactions. + # Additionally, store an extra comment within the original tx. + extra_comment = "don't discard me" + original_tx_id = wallet.sendtoaddress(address=wallet.getnewaddress(), amount=1, comment=extra_comment) + bumped_tx = wallet.bumpfee(txid=original_tx_id) + + def check_comments(): + for record in wallet.listtransactions(): + if record["txid"] == original_tx_id: + assert_equal(record["replaced_by_txid"], bumped_tx["txid"]) + assert_equal(record['comment'], extra_comment) + elif record["txid"] == bumped_tx["txid"]: + assert_equal(record["replaces_txid"], original_tx_id) + + # Pre-migration verification + check_comments() + # Migrate + wallet.migratewallet() + # Post-migration verification + check_comments() + + wallet.unloadwallet() + + def run_test(self): self.generate(self.nodes[0], 101) @@ -952,6 +986,7 @@ class WalletMigrationTest(BitcoinTestFramework): self.test_hybrid_pubkey() self.test_failed_migration_cleanup() self.test_avoidreuse() + self.test_preserve_tx_extra_info() if __name__ == '__main__': WalletMigrationTest().main() diff --git a/test/lint/lint-format-strings.py b/test/lint/lint-format-strings.py index 5ac5840ecf..09d858e131 100755 --- a/test/lint/lint-format-strings.py +++ b/test/lint/lint-format-strings.py @@ -20,6 +20,11 @@ FUNCTION_NAMES_AND_NUMBER_OF_LEADING_ARGUMENTS = [ 'fprintf,1', 'tfm::format,1', # Assuming tfm::::format(std::ostream&, ... 'LogConnectFailure,1', + 'LogError,0', + 'LogWarning,0', + 'LogInfo,0', + 'LogDebug,1', + 'LogTrace,1', 'LogPrint,1', 'LogPrintf,0', 'LogPrintfCategory,1', |