Change time_window from 20s to 1h so Reset is not accidentally called
if the test takes a while.
Change num_lines from 1024 to 10 since LogRateLimiter is parameterized
and does not require logging 1MiB of data.
Co-Authored-By: stickies-v <stickies-v@protonmail.com>
Github-Pull: #33211
Rebased-From: 5dda364c4b1965da586db7b81de8be90b6919414
- Add helper functions and structs to improve readability and
reusability of test code
- Make tests more specific by comparing all produced log lines with
expected log lines instead of relying on approximations or proxies.
Github-Pull: #33011
Rebased-From: 9f3b017bcc067bba1d1682a5d4e65b5450dc10c4
This ensures log tests behave consistently when other tests modify
the log category mask.
Github-Pull: #33011
Rebased-From: 350193e5e2efabb3eb66197b91869b946ec5428c
This allows us to safely and explicitly manage the dual dependency
on the limiter: one for the Logger, and one for the CScheduler.
Github-Pull: #33011
Rebased-From: 3d630c2544e19480268426cda245796d4ce34ac3
Clean up the noisy LogLimitStats and remove references to the time
window.
Co-Authored-By: stickies-v <stickies-v@protonmail.com>
Github-Pull: #33011
Rebased-From: 3c7cae49b692bb6bf5cae5ee23479091bed0b8be
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>
Github-Pull: #32604
Rebased-From: d541409a64c60d127ff912dad9dea949d45dbd8c
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>
Github-Pull: #32604
Rebased-From: a6a35cc0c23d0d529bfeb2f40d83d61f15ca7b40
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>
Github-Pull: #32604
Rebased-From: afb9e39ec5552e598a5febaa81820d5509b7c5d2
This test checks m_log_sourcelocations, not the formatting with format
specifiers. Those are tested in logging_LogPrintMacros below.
So just use LogPrintStr directly in this test, without format specifiers
and format args.
This is required for a follow-up commit.
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.
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.
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.
for verbose log messages for development or debugging only, as bitcoind may run
more slowly, that are more granular/frequent than the Debug log level, i.e. for
very high-frequency, low-level messages to be logged distinctly from
higher-level, less-frequent debug logging that could still be usable in production.
An example would be to log higher-level peer events (connection, disconnection,
misbehavior, eviction) as Debug, versus Trace for low-level, high-volume p2p
messages in the BCLog::NET category. This will enable the user to log only the
former without the latter, in order to focus on high-level peer management events.
With respect to the name, "trace" is suggested as the most granular level
in resources like the following:
- https://sematext.com/blog/logging-levels
- https://howtodoinjava.com/log4j2/logging-levels
Update the test framework and add test coverage.
This is more consistent with the other functions, as well as with the
logging output itself. If we want to make this change, we should do it
before it's all over the place.
