With this change, callers can use util/log.h to emit log messages and do not need to
include the full logging implementation in logging.h.
There's a potential performance impact with this change from an extra
`strprintf` call in log statements where `Logger::WillLogCategoryLevel` returns
true but `Logger::Enabled` returns false. This happens when bitcoind is run
with `-noprinttoconsole -nodebuglogfile` options.
For background, log macro arguments are supposed to be evaluated when
`Logger::WillLogCategoryLevel` returns true, even if log output is not enabled.
Changing this behavior would be reasonable but needs consideration in a
separate PR since not evaluating arguments in log statements has the potential
to change non-logging behavior.
The extra `strprintf` call could have been avoided by expanding this change and
making the `ShouldLog()` function return a tri-state DO_LOG / DO_NOT_LOG /
DO_NOT_LOG_ONLY_EVALUATE_ARGS value instead of a bool, but this complexity did
not seem warranted.
Review with --color-moved=dimmed-zebra --color-moved-ws=ignore-all-space
Co-authored-by: Ryan Ofsky <ryan@ofsky.org>
Move logging macros to util/log.h so the entire codebase can use the same
macros.
Review with --color-moved=dimmed-zebra --color-moved-ws=ignore-all-space
Co-authored-by: Ryan Ofsky <ryan@ofsky.org>
This is not strictly move-only because BCLog::Level is now defined as a type
alias for util::log::Level;
Review with --color-moved=dimmed-zebra --color-moved-ws=ignore-all-space
Co-authored-by: Ryan Ofsky <ryan@ofsky.org>
Logging categories are currently shared between node and kernel. This
separation allows future commits to completely remove kernel's
dependency on logging.h.
Also applies clang-format suggestions to the moved code.
Review with --color-moved=dimmed-zebra --color-moved-ws=ignore-all-space
Co-authored-by: Ryan Ofsky <ryan@ofsky.org>
Introduce util/log.h as a lightweight header for code that only needs to emit
log messages. Move SourceLocation into this header so log-emitting code no
longer needs to include logging.h and depend on the full log management API.
This is a move-only change and the first change of several changes that
separate log generation from log handling. It also applies clang-format
suggestions to the moved code.
Review with --color-moved=dimmed-zebra --color-moved-ws=ignore-all-space
Co-authored-by: Ryan Ofsky <ryan@ofsky.org>
89372213048adf37a47427112a1ff836ee84c50e doc: add release notes for 29415 (Vasil Dimov)
582016fa5f013817db650bbba0a40d9195c18e2e test: add unit test for the private broadcast storage (Vasil Dimov)
e74d54e04896a86cad4e4b1bd9641afcc3a026c2 test: add functional test for private broadcast (Vasil Dimov)
818b780a05db126dcfe7efe12c46c84b5cfc3de6 rpc: use private broadcast from sendrawtransaction RPC if -privatebroadcast is ON (Vasil Dimov)
eab595f9cf13f7cb1d25a0db51409535cfe053b1 net_processing: retry private broadcast (Vasil Dimov)
37b79f9c39db5a4a61d360a6a29c8853bb5c7ac0 net_processing: stop private broadcast of a transaction after round-trip (Vasil Dimov)
2de53eee742da11b0e3f6fc44c39f2b5b5929da1 net_processing: handle ConnectionType::PRIVATE_BROADCAST connections (Vasil Dimov)
30a9853ad35365af8545e8e766d75cf398968480 net_processing: move a debug check in VERACK processing earlier (Vasil Dimov)
d1092e5d48ce67bd517068550c78bfcab062a554 net_processing: modernize PushNodeVersion() (Vasil Dimov)
9937a12a2fd5a0033f37f4dda5d75bfc5f15c3b6 net_processing: move the debug log about receiving VERSION earlier (Vasil Dimov)
a098f37b9e240291077a7f440e9f57e61f30e158 net_processing: reorder the code that handles the VERSION message (Vasil Dimov)
679ce3a0b8df6e8cab07965301382d2036ef2368 net_processing: store transactions for private broadcast in PeerManager (Vasil Dimov)
a3faa6f944a672faccac5dd201c8d33a638d9091 node: extend node::TxBroadcast with a 3rd option (Vasil Dimov)
95c051e21051bd469fda659fe7c495d5e264d221 net_processing: rename RelayTransaction() to better describe what it does (Vasil Dimov)
bb49d26032c57714c62a4b31ff1fdd969751683f net: implement opening PRIVATE_BROADCAST connections (Vasil Dimov)
01dad4efe2b38b7a71c96b6222147f395e0c11d9 net: introduce a new connection type for private broadcast (Vasil Dimov)
94aaa5d31b6ff1d0122319fc70e70a7e27e1a0ba init: introduce a new option to enable/disable private broadcast (Vasil Dimov)
d6ee490e0a9a81b69a4751087918303163ba8869 log: introduce a new category for private broadcast (Vasil Dimov)
Pull request description:
_Parts of this PR are isolated in independent smaller PRs to ease review:_
* [x] _https://github.com/bitcoin/bitcoin/pull/29420_
* [x] _https://github.com/bitcoin/bitcoin/pull/33454_
* [x] _https://github.com/bitcoin/bitcoin/pull/33567_
* [x] _https://github.com/bitcoin/bitcoin/pull/33793_
---
To improve privacy, broadcast locally submitted transactions (from the `sendrawtransaction` RPC) to the P2P network only via Tor or I2P short-lived connections, or to IPv4/IPv6 peers but through the Tor network.
* Introduce a new connection type for private broadcast of transactions with the following properties:
* started whenever there are local transactions to be sent
* opened to Tor or I2P peers or IPv4/IPv6 via the Tor proxy
* opened regardless of max connections limits
* after handshake is completed one local transaction is pushed to the peer, `PING` is sent and after receiving `PONG` the connection is closed
* ignore all incoming messages after handshake is completed (except `PONG`)
* Broadcast transactions submitted via `sendrawtransaction` using this new mechanism, to a few peers. Keep doing this until we receive back this transaction from one of our ordinary peers (this takes about 1 second on mainnet).
* The transaction is stored in peerman and does not enter the mempool.
* Once we get an `INV` from one of our ordinary peers, then the normal flow executes: we request the transaction with `GETDATA`, receive it with a `TX` message, put it in our mempool and broadcast it to all our existent connections (as if we see it for the first time).
* After we receive the full transaction as a `TX` message, in reply to our `GETDATA` request, only then consider the transaction has propagated through the network and remove it from the storage in peerman, ending the private broadcast attempts.
The messages exchange should look like this:
```
tx-sender >--- connect -------> tx-recipient
tx-sender >--- VERSION -------> tx-recipient (dummy VERSION with no revealing data)
tx-sender <--- VERSION -------< tx-recipient
tx-sender <--- WTXIDRELAY ----< tx-recipient (maybe)
tx-sender <--- SENDADDRV2 ----< tx-recipient (maybe)
tx-sender <--- SENDTXRCNCL ---< tx-recipient (maybe)
tx-sender <--- VERACK --------< tx-recipient
tx-sender >--- VERACK --------> tx-recipient
tx-sender >--- INV/TX --------> tx-recipient
tx-sender <--- GETDATA/TX ----< tx-recipient
tx-sender >--- TX ------------> tx-recipient
tx-sender >--- PING ----------> tx-recipient
tx-sender <--- PONG ----------< tx-recipient
tx-sender disconnects
```
Whenever a new transaction is received from `sendrawtransaction` RPC, the node will send it to a few (`NUM_PRIVATE_BROADCAST_PER_TX`) recipients right away. If after some time we still have not heard anything about the transaction from the network, then it will be sent to 1 more peer (see `PeerManagerImpl::ReattemptPrivateBroadcast()`).
A few considerations:
* The short-lived private broadcast connections are very cheap and fast wrt network traffic. It is expected that some of those peers could blackhole the transaction. Just one honest/proper peer is enough for successful propagation.
* The peers that receive the transaction could deduce that this is initial transaction broadcast from the transaction originator. This is ok, they can't identify the sender.
---
<details>
<summary>How to test this?</summary>
Thank you, @stratospher and @andrewtoth!
Start `bitcoind` with `-privatebroadcast=1 -debug=privatebroadcast`.
Create a wallet and get a new address, go to the Signet faucet and request some coins to that address:
```bash
build/bin/bitcoin-cli -chain="signet" createwallet test
build/bin/bitcoin-cli -chain="signet" getnewaddress
```
Get a new address for the test transaction recipient:
```bash
build/bin/bitcoin-cli -chain="signet" loadwallet test
new_address=$(build/bin/bitcoin-cli -chain="signet" getnewaddress)
```
Create the transaction:
```bash
# Option 1: `createrawtransaction` and `signrawtransactionwithwallet`:
txid=$(build/bin/bitcoin-cli -chain="signet" listunspent | jq -r '.[0] | .txid')
vout=$(build/bin/bitcoin-cli -chain="signet" listunspent | jq -r '.[0] | .vout')
echo "txid: $txid"
echo "vout: $vout"
tx=$(build/bin/bitcoin-cli -chain="signet" createrawtransaction "[{\"txid\": \"$txid\", \"vout\": $vout}]" "[{\"$new_address\": 0.00001000}]" 0 false)
echo "tx: $tx"
signed_tx=$(build/bin/bitcoin-cli -chain="signet" signrawtransactionwithwallet "$tx" | jq -r '.hex')
echo "signed_tx: $signed_tx"
# OR Option 2: `walletcreatefundedpsbt` and `walletprocesspsbt`:
# This makes it not have to worry about inputs and also automatically sends back change to the wallet.
# Start `bitcoind` with `-fallbackfee=0.00003000` for instance for 3 sat/vbyte fee.
psbt=$(build/bin/bitcoin-cli -chain="signet" walletcreatefundedpsbt "[]" "[{\"$new_address\": 0.00001000}]" | jq -r '.psbt')
echo "psbt: $psbt"
signed_tx=$(build/bin/bitcoin-cli -chain="signet" walletprocesspsbt "$psbt" | jq -r '.hex')
echo "signed_tx: $signed_tx"
```
Finally, send the transaction:
```bash
raw_tx=$(build/bin/bitcoin-cli -chain="signet" sendrawtransaction "$signed_tx")
echo "raw_tx: $raw_tx"
```
</details>
---
<details>
<summary>High-level explanation of the commits</summary>
* New logging category and config option to enable private broadcast
* `log: introduce a new category for private broadcast`
* `init: introduce a new option to enable/disable private broadcast`
* Implement the private broadcast connection handling on the `CConnman` side:
* `net: introduce a new connection type for private broadcast`
* `net: implement opening PRIVATE_BROADCAST connections`
* Prepare `BroadcastTransaction()` for private broadcast requests:
* `net_processing: rename RelayTransaction to better describe what it does`
* `node: extend node::TxBroadcast with a 3rd option`
* `net_processing: store transactions for private broadcast in PeerManager`
* Implement the private broadcast connection handling on the `PeerManager` side:
* `net_processing: reorder the code that handles the VERSION message`
* `net_processing: move the debug log about receiving VERSION earlier`
* `net_processing: modernize PushNodeVersion()`
* `net_processing: move a debug check in VERACK processing earlier`
* `net_processing: handle ConnectionType::PRIVATE_BROADCAST connections`
* `net_processing: stop private broadcast of a transaction after round-trip`
* `net_processing: retry private broadcast`
* Engage the new functionality from `sendrawtransaction`:
* `rpc: use private broadcast from sendrawtransaction RPC if -privatebroadcast is ON`
* New tests:
* `test: add functional test for private broadcast`
* `test: add unit test for the private broadcast storage`
</details>
---
**This PR would resolve the following issues:**
https://github.com/bitcoin/bitcoin/issues/3828 Clients leak IPs if they are recipients of a transaction
https://github.com/bitcoin/bitcoin/issues/14692 Can't configure bitocoind to only send tx via Tor but receive clearnet transactions
https://github.com/bitcoin/bitcoin/issues/19042 Tor-only transaction broadcast onlynet=onion alternative
https://github.com/bitcoin/bitcoin/issues/24557 Option for receive events with all networks, but send transactions and/or blocks only with anonymous network[s]?
https://github.com/bitcoin/bitcoin/issues/25450 Ability to broadcast wallet transactions only via dedicated oneshot Tor connections
https://github.com/bitcoin/bitcoin/issues/32235 Tor: TX circuit isolation
**Issues that are related, but (maybe?) not to be resolved by this PR:**
https://github.com/bitcoin/bitcoin/issues/21876 Broadcast a transaction to specific nodes
https://github.com/bitcoin/bitcoin/issues/28636 new RPC: sendrawtransactiontopeer
---
Further extensions:
* Have the wallet do the private broadcast as well, https://github.com/bitcoin/bitcoin/issues/11887 would have to be resolved.
* Have the `submitpackage` RPC do the private broadcast as well, [draft diff in the comment below](https://github.com/bitcoin/bitcoin/pull/29415#pullrequestreview-2972293733), thanks ismaelsadeeq!
* Add some stats via RPC, so that the user can better monitor what is going on during and after the broadcast. Currently this can be done via the debug log, but that is not convenient.
* Make the private broadcast storage, currently in peerman, persistent over node restarts.
* Add (optional) random delay before starting to broadcast the transaction in order to avoid correlating unrelated transactions based on the time when they were broadcast. Suggested independently of this PR [here](https://github.com/bitcoin/bitcoin/issues/30471).
* Consider periodically sending transactions that did not originate from the node as decoy, discussed [here](https://github.com/bitcoin/bitcoin/pull/29415#discussion_r2035414972).
* Consider waiting for peer's FEEFILTER message and if the transaction that was sent to the peer is below that threshold, then assume the peer is going to drop it. Then use this knowledge to retry more aggressively with another peer, instead of the current 10 min. See [comment below](https://github.com/bitcoin/bitcoin/pull/29415#issuecomment-3258611648).
* It may make sense to be able to override the default policy -- eg so submitrawtransaction can go straight to the mempool and relay, even if txs are normally privately relayed. See [comment below](https://github.com/bitcoin/bitcoin/pull/29415#issuecomment-3427086681).
* As a side effect we have a new metric available - the time it takes for a transaction to reach a random node in the network (from the point of view of the private broadcast recipient the tx originator is a random node somewhere in the network). This can be useful for monitoring, unrelated to privacy characteristics of this feature.
---
_A previous incarnation of this can be found at https://github.com/bitcoin/bitcoin/pull/27509. It puts the transaction in the mempool and (tries to) hide it from the outside observers. This turned out to be too error prone or maybe even impossible._
ACKs for top commit:
l0rinc:
code review diff ACK 89372213048adf37a47427112a1ff836ee84c50e
andrewtoth:
ACK 89372213048adf37a47427112a1ff836ee84c50e
pinheadmz:
ACK 89372213048adf37a47427112a1ff836ee84c50e
w0xlt:
ACK 8937221304 with nit https://github.com/bitcoin/bitcoin/pull/29415#discussion_r2654849875
mzumsande:
re-ACK 89372213048adf37a47427112a1ff836ee84c50e
Tree-SHA512: d51dadc865c2eb080c903cbe2f669e69a967e5f9fc64e9a20a68f39a67bf0db6ac2ad682af7fa24ef9f0942a41c89959341a16ba7b616475e1c5ab8e563b9b96
Exposing logging in the kernel library allows users to follow
operations. Users of the C header can use
`kernel_logging_connection_create(...)` to pass a callback function to
Bitcoin Core's internal logger. Additionally the level and category can
be globally configured.
By default, the logger buffers messages until
`kernel_loggin_connection_create(...)` is called. If the user does not
want any logging messages, it is recommended that
`kernel_disable_logging()` is called, which permanently disables the
logging and any buffering of messages.
Co-authored-by: stringintech <stringintech@gmail.com>
To mitigate disk-filling attacks caused by unsafe usages of LogPrintf and
friends, we rate-limit them by passing a should_ratelimit bool that
eventually makes its way to LogPrintStr which may call
LogRateLimiter::Consume. The rate limiting is accomplished by
adding a LogRateLimiter member to BCLog::Logger which tracks source
code locations for the given logging window.
Every hour, a source location can log up to 1MiB of data. Source
locations that exceed the limit will have their logs suppressed for the
rest of the window determined by m_limiter.
This change affects the public LogPrintLevel function if called with
a level >= BCLog::Level::Info.
The UpdateTipLog function has been changed to use the private LogPrintLevel_
macro with should_ratelimit set to false. This allows UpdateTipLog to log
during IBD without hitting the rate limit.
Note that on restart, a source location that was rate limited before the
restart will be able to log until it hits the rate limit again.
Co-Authored-By: Niklas Gogge <n.goeggi@gmail.com>
Co-Authored-By: stickies-v <stickies-v@protonmail.com>
The std::source_location conveniently stores the file name, line number,
and function name of a source code location. We switch to using it instead
of the __func__ identifier and the __FILE__ and __LINE__ macros.
BufferedLog is changed to have a std::source_location member, replacing the
source_file, source_line, and logging_function members. As a result,
MemUsage no longer explicitly counts source_file or logging_function as the
std::source_location memory usage is included in the MallocUsage call.
This also changes the behavior of -logsourcelocations as std::source_location
includes the entire function signature. Because of this, the functional test
feature_config_args.py must be changed to no longer include the function
signature as the function signature can differ across platforms.
Co-Authored-By: Niklas Gogge <n.goeggi@gmail.com>
Co-Authored-By: stickies-v <stickies-v@protonmail.com>
LogRateLimiter will be used to keep track of source locations and our
current time-based logging window. It contains an unordered_map and a
m_suppressions_active bool to track source locations. The map is keyed
by std::source_location, so a custom Hash function (SourceLocationHasher)
and custom KeyEqual function (SourceLocationEqual) is provided.
SourceLocationHasher uses CSipHasher(0,0) under the hood to get a
uniform distribution.
A public Reset method is provided so that a scheduler (e.g. the
"b-scheduler" thread) can periodically reset LogRateLimiter's state when
the time window has elapsed.
The LogRateLimiter::Consume method checks if we have enough available
bytes in our rate limiting budget to log an additional string. It
returns a Status enum that denotes the rate limiting status and can
be used by the caller to emit a warning, skip logging, etc.
The Status enum has three states:
- UNSUPPRESSED (logging was successful)
- NEWLY_SUPPRESSED (logging was succcesful, next log will be suppressed)
- STILL_SUPPRESSED (logging was unsuccessful)
LogLimitStats counts the available bytes left for logging per source
location for the current logging window. It does not track actual source
locations; it is used as a value in m_source_locations.
Also exposes a SuppressionsActive() method so the logger can use
that in a later commit to prefix [*] to logs whenenever suppressions
are active.
Co-Authored-By: Niklas Gogge <n.goeggi@gmail.com>
Co-Authored-By: stickies-v <stickies-v@protonmail.com>
This changes all logging (including the wallet logging) to produce a
ConstevalFormatString at compile time, so that the format string can be
validated at compile-time.
Also, while touching the wallet logging, avoid a copy of the template
Params by using const Params&.
Put the warning closer to where it is relevant. That is, put it close to
the functions that actually do unconditional logging.
Also, remove a stray empty line.
LogPrint*ThreadNames is redundant with LogWith(out)ThreadNames, because
they all measure toggling the thread names (and check that it has no
effect on performance).
This also allows to remove unused and deprecated macros.
b31a0cd0378184b2b9eb8f4bd3120cbd32c62005 log: expand BCLog::LogFlags (categories) to 64 bits (Larry Ruane)
Pull request description:
Increase the maximum number of logging categories from 32 to 64.
We're currently using 29 of the 32 available logging categories (there are only 3 remaining). It would be good to increase the limit soon; the fourth PR to be merged that adds a new logging category will be blocked until something like this is done.
This PR also adds a `TEST` category that uses the new range (`1ULL << 63`) in case there's a hidden assumption somewhere that the `BCLog::LogFlags` type is 32 bits. (Also added a test for this test category.) It also provides an example showing that the expression must be `1ULL << <shift>` for shift value 31 and beyond.
ACKs for top commit:
achow101:
ACK b31a0cd0378184b2b9eb8f4bd3120cbd32c62005
vasild:
ACK b31a0cd0378184b2b9eb8f4bd3120cbd32c62005
ryanofsky:
Code review ACK b31a0cd0378184b2b9eb8f4bd3120cbd32c62005, just dropping mask_bit constant since last review. I still think
theStack:
Code-review ACK b31a0cd0378184b2b9eb8f4bd3120cbd32c62005
Tree-SHA512: de422dbeb479848d370aed42d415f42461457ab0eda62b245dc7ff9f0e111626e7d4c0d62ff13082ec664d05fbb0db04c71eb4b6f22eb8f19198826a67c4035e
* Make the standalone function `LogCategoryToStr()` private inside
`logging.cpp` (aka `static`) - it is only used in that file.
* Make the method `Logger::GetLogPrefix()` `private` - it is only
used within the class.
* Use `BCLog::NONE` to initialize `m_categories` instead of `0`.
We later check whether it is `BCLog::NONE` (in
`Logger::DefaultShrinkDebugFile()`).
The formatting of log messages isn't defined until StartLogging() is
called; so can't be correctly applied to early log messages from prior
to that call. Instead of saving the output log message, save the inputs
to the logging invocation (including time, mocktime and thread name),
and format those inputs into a log message when StartLogging() is called.
There are no changes to behavior. Changes in this commit are all additions, and
are easiest to review using "git diff -U0 --word-diff-regex=." options.
Motivation for this change is to keep util functions with really generic names
like "Split" and "Join" out of the global namespace so it is easier to see
where these functions are defined, and so they don't interfere with function
overloading, especially since the util library is a dependency of the kernel
library and intended to be used with external code.
b0344c219a641b759fb0cc4f53afebe675b8ca27 logging: remove unused BCLog::UTIL (Vasil Dimov)
d3b3af90343b7671231afd7dff87e87ff86d31d7 log: deduplicate category names and improve logging.cpp (Vasil Dimov)
Pull request description:
The code in `logging.cpp` needs to:
* Get the category name given the flag (e.g. `BCLog::PRUNE` -> `"prune"`)
* Get the flag given the category name (e.g. `"prune"` -> `BCLog::PRUNE`)
* Get the list of category names sorted in alphabetical order
Achieve this by using the proper std containers. The result is
* less code (the diff of the first commit is +62 / -129)
* faster code (to linear search and no copy+sort)
* more maintainable code (the categories are no longer duplicated in `LogCategories[]` and `LogCategoryToStr()`)
This behavior is preserved:
`BCLog::NONE` -> `""` (lookup by `LogCategoryToStr()`)
`""` -> `BCLog::ALL` (lookup by `GetLogCategory("")`)
---
Also remove unused `BCLog::UTIL`.
---
These changes (modulo the `BCLog::UTIL` removal) are part of https://github.com/bitcoin/bitcoin/pull/29415 but they make sense on their own and would be good to have them, regardless of the fate of https://github.com/bitcoin/bitcoin/pull/29415. Also, if this is merged, that would reduce the size of https://github.com/bitcoin/bitcoin/pull/29415, thus the current standalone PR.
ACKs for top commit:
davidgumberg:
crACK b0344c219a
pinheadmz:
ACK b0344c219a641b759fb0cc4f53afebe675b8ca27
ryanofsky:
Code review ACK b0344c219a641b759fb0cc4f53afebe675b8ca27. Nice cleanup! Having to maintain multiple copies of the same mapping seemed messy and a like a possible footgun. I checked old and new mappings in both directions and confirmed no behavior should be changing.
Tree-SHA512: 57f87a090932f9b33dc8e075d1855dba9b71a3243a0758511745483dec2d9c46d3b532eadab297e78164c9b7caba370986ee380696a45f0778a841082f8e21a7
These provide simple and clear ways to write the most common logging
operations:
LogInfo("msg");
LogDebug(BCLog::LogFlags::NET, "msg");
LogError("msg");
LogWarning("msg");
LogTrace(BCLog::LogFlags::NET, "msg");
For cases where the level cannot be hardcoded, LogPrintLevel(category,
level, ...) remains available.
This option tells the logging system to always include a "[cat:level]"
prefix, so [net] becomes [net:debug], LogInfo/LogPrint statements will have
an [all:info] prefix, and LogWarning and LogError logs will become
[all:warning] and [all:error]. This may be easier for automated parsing
of logs, particularly if additional prefixes such as thread or source
location are enabled.
The fs.* files are already part of the libbitcoin_util library. With the
introduction of the fs_helpers.* it makes sense to move fs.* into the
util/ directory as well.
error is a low-level function with a sole dependency on LogPrintf, which
is defined in logging.h
The background of this commit is an ongoing effort to decouple the
libbitcoinkernel library from the ArgsManager defined in system.h.
Moving the function out of system.h allows including it from a separate
source file without including the ArgsManager definitions from system.h.
