mirror of
https://github.com/XRPLF/rippled.git
synced 2026-06-06 02:07:07 +00:00
Add Logger from clio and implement json logging
This commit is contained in:
JCW
622
src/libxrpl/basics/Logger.cpp
Normal file
622
src/libxrpl/basics/Logger.cpp
Normal file
@@ -0,0 +1,622 @@
|
||||
#include <xrpl/basics/Logger.h>
|
||||
|
||||
#include <xrpl/beast/utility/instrumentation.h>
|
||||
|
||||
#include <spdlog/async.h>
|
||||
#include <spdlog/async_logger.h>
|
||||
#include <spdlog/common.h>
|
||||
#include <spdlog/details/log_msg.h>
|
||||
#include <spdlog/formatter.h>
|
||||
#include <spdlog/logger.h>
|
||||
#include <spdlog/pattern_formatter.h>
|
||||
#include <spdlog/sinks/basic_file_sink.h>
|
||||
#include <spdlog/sinks/rotating_file_sink.h>
|
||||
#include <spdlog/sinks/stdout_color_sinks.h>
|
||||
#include <spdlog/spdlog.h>
|
||||
|
||||
#include <cstddef>
|
||||
#include <cstring>
|
||||
#include <filesystem>
|
||||
#include <memory>
|
||||
#include <optional>
|
||||
#include <source_location>
|
||||
#include <stdexcept>
|
||||
#include <string>
|
||||
#include <string_view>
|
||||
#include <system_error>
|
||||
#include <utility>
|
||||
|
||||
namespace xrpl {
|
||||
|
||||
bool LogServiceState::isAsync_{true};
|
||||
Severity LogServiceState::defaultSeverity_{Severity::NFO};
|
||||
std::vector<spdlog::sink_ptr> LogServiceState::sinks_{};
|
||||
bool LogServiceState::initialized_{false};
|
||||
bool LogServiceState::jsonMode_{false};
|
||||
std::optional<std::string> LogServiceState::logDir_{};
|
||||
std::string LogServiceState::format_{};
|
||||
|
||||
namespace {
|
||||
|
||||
spdlog::level::level_enum
|
||||
toSpdlogLevel(Severity sev)
|
||||
{
|
||||
switch (sev)
|
||||
{
|
||||
case Severity::TRC:
|
||||
return spdlog::level::trace;
|
||||
case Severity::DBG:
|
||||
return spdlog::level::debug;
|
||||
case Severity::NFO:
|
||||
return spdlog::level::info;
|
||||
case Severity::WRN:
|
||||
return spdlog::level::warn;
|
||||
case Severity::ERR:
|
||||
return spdlog::level::err;
|
||||
case Severity::FTL:
|
||||
return spdlog::level::critical;
|
||||
}
|
||||
return spdlog::level::info;
|
||||
}
|
||||
|
||||
std::string_view
|
||||
toString(Severity sev)
|
||||
{
|
||||
static constexpr std::array<std::string_view, 6> kLABELS = {
|
||||
"TRC",
|
||||
"DBG",
|
||||
"NFO",
|
||||
"WRN",
|
||||
"ERR",
|
||||
"FTL",
|
||||
};
|
||||
|
||||
return kLABELS.at(static_cast<int>(sev));
|
||||
}
|
||||
|
||||
} // namespace
|
||||
|
||||
/**
|
||||
* @brief Custom formatter that filters out critical messages
|
||||
*
|
||||
* This formatter only processes and formats messages with severity level less than critical.
|
||||
* Critical messages will be handled separately.
|
||||
*/
|
||||
class NonCriticalFormatter : public spdlog::formatter
|
||||
{
|
||||
public:
|
||||
NonCriticalFormatter(std::unique_ptr<spdlog::formatter> wrappedFormatter)
|
||||
: wrapped_formatter_(std::move(wrappedFormatter))
|
||||
{
|
||||
}
|
||||
|
||||
void
|
||||
format(spdlog::details::log_msg const& msg, spdlog::memory_buf_t& dest) override
|
||||
{
|
||||
// Only format messages with severity less than critical
|
||||
if (msg.level != spdlog::level::critical)
|
||||
{
|
||||
wrapped_formatter_->format(msg, dest);
|
||||
}
|
||||
}
|
||||
|
||||
[[nodiscard]] std::unique_ptr<formatter>
|
||||
clone() const override
|
||||
{
|
||||
return std::make_unique<NonCriticalFormatter>(wrapped_formatter_->clone());
|
||||
}
|
||||
|
||||
private:
|
||||
std::unique_ptr<spdlog::formatter> wrapped_formatter_;
|
||||
};
|
||||
|
||||
/**
|
||||
* @brief Custom spdlog flag formatter that outputs the three-letter severity
|
||||
* codes used by the legacy logging system: TRC, DBG, NFO, WRN, ERR, FTL.
|
||||
*
|
||||
* Registered as the '%K' custom flag in pattern formatters created by
|
||||
* @ref createPatternFormatter.
|
||||
*/
|
||||
class SeverityFlagFormatter final : public spdlog::custom_flag_formatter
|
||||
{
|
||||
public:
|
||||
void
|
||||
format(
|
||||
spdlog::details::log_msg const& msg,
|
||||
std::tm const& /*tm_time*/,
|
||||
spdlog::memory_buf_t& dest) override
|
||||
{
|
||||
static constexpr std::array<std::string_view, 7> kLABELS = {
|
||||
"TRC",
|
||||
"DBG",
|
||||
"NFO",
|
||||
"WRN",
|
||||
"ERR",
|
||||
"FTL",
|
||||
"OFF",
|
||||
};
|
||||
|
||||
auto const idx = static_cast<std::size_t>(msg.level);
|
||||
auto const label = idx < kLABELS.size() ? kLABELS[idx] : "???";
|
||||
dest.append(label.data(), label.data() + label.size());
|
||||
}
|
||||
|
||||
[[nodiscard]] std::unique_ptr<custom_flag_formatter>
|
||||
clone() const override
|
||||
{
|
||||
return std::make_unique<SeverityFlagFormatter>();
|
||||
}
|
||||
};
|
||||
|
||||
/**
|
||||
* @brief Creates a spdlog pattern_formatter with our custom '%K' severity flag
|
||||
* and UTC timestamps.
|
||||
*
|
||||
* @param pattern The spdlog pattern string (should use '%K' for severity)
|
||||
* @return A unique_ptr to the configured pattern_formatter
|
||||
*/
|
||||
static std::unique_ptr<spdlog::pattern_formatter>
|
||||
createPatternFormatter(std::string const& pattern)
|
||||
{
|
||||
auto formatter = std::make_unique<spdlog::pattern_formatter>(
|
||||
pattern, spdlog::pattern_time_type::utc, spdlog::details::os::default_eol);
|
||||
formatter->add_flag<SeverityFlagFormatter>('K');
|
||||
formatter->set_pattern(pattern);
|
||||
return formatter;
|
||||
}
|
||||
|
||||
/**
|
||||
* @brief Truncates a log message to the maximum allowed length, appending
|
||||
* an ellipsis if truncation occurs.
|
||||
*
|
||||
* Matches the legacy Logs::format behaviour with maximumMessageCharacters = 12 * 1024.
|
||||
*
|
||||
* @param message The message to potentially truncate (modified in-place)
|
||||
*/
|
||||
static void
|
||||
truncateMessage(std::string& message)
|
||||
{
|
||||
static constexpr std::size_t kMAX_MESSAGE_CHARS = 12 * 1024;
|
||||
if (message.size() > kMAX_MESSAGE_CHARS)
|
||||
{
|
||||
message.resize(kMAX_MESSAGE_CHARS - 3);
|
||||
message += "...";
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* @brief Scrubs sensitive fields from a log message by replacing their values
|
||||
* with asterisks.
|
||||
*
|
||||
* Ported from the legacy Logs::format scrubber. Looks for JSON-like tokens
|
||||
* such as "seed", "secret", "master_key", etc., finds the value enclosed in
|
||||
* double quotes immediately after the token, and replaces the value characters
|
||||
* with '*'.
|
||||
*
|
||||
* @param output The log message to scrub (modified in-place)
|
||||
*/
|
||||
static void
|
||||
scrubSecrets(std::string& output)
|
||||
{
|
||||
auto scrubber = [&output](char const* token) {
|
||||
auto first = output.find(token);
|
||||
|
||||
// If we have found the specified token, then attempt to isolate the
|
||||
// sensitive data (it's enclosed by double quotes) and mask it off:
|
||||
if (first != std::string::npos)
|
||||
{
|
||||
first = output.find('\"', first + std::strlen(token));
|
||||
|
||||
if (first != std::string::npos)
|
||||
{
|
||||
auto last = output.find('\"', ++first);
|
||||
|
||||
if (last == std::string::npos)
|
||||
last = output.size();
|
||||
|
||||
output.replace(first, last - first, last - first, '*');
|
||||
}
|
||||
}
|
||||
};
|
||||
|
||||
scrubber("\"seed\"");
|
||||
scrubber("\"seed_hex\"");
|
||||
scrubber("\"secret\"");
|
||||
scrubber("\"master_key\"");
|
||||
scrubber("\"master_seed\"");
|
||||
scrubber("\"master_seed_hex\"");
|
||||
scrubber("\"passphrase\"");
|
||||
}
|
||||
|
||||
/**
|
||||
* @brief Initializes console logging.
|
||||
*
|
||||
* @param logToConsole A boolean indicating whether to log to console.
|
||||
* @param format A string representing the log format.
|
||||
* @return Vector of sinks for console logging.
|
||||
*/
|
||||
static std::vector<spdlog::sink_ptr>
|
||||
createConsoleSinks(bool logToConsole, std::string const& format)
|
||||
{
|
||||
std::vector<spdlog::sink_ptr> sinks;
|
||||
|
||||
if (logToConsole)
|
||||
{
|
||||
auto consoleSink = std::make_shared<spdlog::sinks::stdout_color_sink_mt>();
|
||||
consoleSink->set_level(spdlog::level::trace);
|
||||
consoleSink->set_formatter(
|
||||
std::make_unique<NonCriticalFormatter>(createPatternFormatter(format)));
|
||||
sinks.push_back(std::move(consoleSink));
|
||||
}
|
||||
|
||||
// Always add stderr sink for fatal logs
|
||||
auto stderrSink = std::make_shared<spdlog::sinks::stderr_color_sink_mt>();
|
||||
stderrSink->set_level(spdlog::level::critical);
|
||||
stderrSink->set_formatter(createPatternFormatter(format));
|
||||
sinks.push_back(std::move(stderrSink));
|
||||
|
||||
return sinks;
|
||||
}
|
||||
|
||||
/**
|
||||
* @brief Initializes file logging.
|
||||
*
|
||||
* @param config The configuration object containing log settings.
|
||||
* @param dirPath The directory path where log files will be stored.
|
||||
* @return File sink for logging.
|
||||
*/
|
||||
spdlog::sink_ptr
|
||||
LogService::createFileSink(FileLoggingParams const& params, std::string const& format)
|
||||
{
|
||||
std::filesystem::path const dirPath(params.logDir);
|
||||
auto fileSink = [&]() -> std::shared_ptr<spdlog::sinks::sink> {
|
||||
auto const logPath = (dirPath / "xrpld.log").string();
|
||||
return std::make_shared<spdlog::sinks::basic_file_sink_mt>(logPath, /*truncate=*/false);
|
||||
}();
|
||||
|
||||
fileSink->set_level(spdlog::level::trace);
|
||||
fileSink->set_formatter(createPatternFormatter(format));
|
||||
|
||||
return fileSink;
|
||||
}
|
||||
|
||||
void
|
||||
LogServiceState::init(
|
||||
bool isAsync,
|
||||
Severity defaultSeverity,
|
||||
std::vector<spdlog::sink_ptr> const& sinks,
|
||||
bool jsonMode)
|
||||
{
|
||||
if (initialized_)
|
||||
{
|
||||
throw std::logic_error("LogServiceState is already initialized");
|
||||
}
|
||||
|
||||
isAsync_ = isAsync;
|
||||
defaultSeverity_ = defaultSeverity;
|
||||
sinks_ = sinks;
|
||||
jsonMode_ = jsonMode;
|
||||
initialized_ = true;
|
||||
|
||||
spdlog::apply_all([](std::shared_ptr<spdlog::logger> logger) {
|
||||
logger->set_level(toSpdlogLevel(defaultSeverity_));
|
||||
});
|
||||
|
||||
if (isAsync)
|
||||
{
|
||||
static constexpr size_t kQUEUE_SIZE = 8192;
|
||||
static constexpr size_t kTHREAD_COUNT = 1;
|
||||
spdlog::init_thread_pool(kQUEUE_SIZE, kTHREAD_COUNT);
|
||||
}
|
||||
}
|
||||
|
||||
bool
|
||||
LogServiceState::initialized()
|
||||
{
|
||||
return initialized_;
|
||||
}
|
||||
|
||||
bool
|
||||
LogServiceState::hasSinks()
|
||||
{
|
||||
return not sinks_.empty();
|
||||
}
|
||||
|
||||
void
|
||||
LogServiceState::reset()
|
||||
{
|
||||
if (not initialized())
|
||||
{
|
||||
throw std::logic_error("LogService is not initialized");
|
||||
}
|
||||
isAsync_ = true;
|
||||
defaultSeverity_ = Severity::NFO;
|
||||
sinks_.clear();
|
||||
jsonMode_ = false;
|
||||
logDir_.reset();
|
||||
format_.clear();
|
||||
initialized_ = false;
|
||||
}
|
||||
|
||||
std::shared_ptr<spdlog::logger>
|
||||
LogServiceState::registerLogger(std::string_view channel, std::optional<Severity> severity)
|
||||
{
|
||||
if (not initialized_)
|
||||
{
|
||||
throw std::logic_error("LogService is not initialized");
|
||||
}
|
||||
|
||||
std::string const channelStr{channel};
|
||||
|
||||
std::shared_ptr<spdlog::logger> existingLogger = spdlog::get(channelStr);
|
||||
if (existingLogger != nullptr)
|
||||
{
|
||||
if (severity.has_value())
|
||||
existingLogger->set_level(toSpdlogLevel(*severity));
|
||||
return existingLogger;
|
||||
}
|
||||
|
||||
std::shared_ptr<spdlog::logger> logger;
|
||||
if (isAsync_)
|
||||
{
|
||||
logger = std::make_shared<spdlog::async_logger>(
|
||||
channelStr,
|
||||
sinks_.begin(),
|
||||
sinks_.end(),
|
||||
spdlog::thread_pool(),
|
||||
spdlog::async_overflow_policy::block);
|
||||
}
|
||||
else
|
||||
{
|
||||
logger = std::make_shared<spdlog::logger>(channelStr, sinks_.begin(), sinks_.end());
|
||||
}
|
||||
|
||||
logger->set_level(toSpdlogLevel(severity.value_or(defaultSeverity_)));
|
||||
logger->flush_on(spdlog::level::err);
|
||||
|
||||
spdlog::register_logger(logger);
|
||||
|
||||
return logger;
|
||||
}
|
||||
|
||||
Expected<std::vector<spdlog::sink_ptr>, std::string>
|
||||
LogService::getSinks(LoggingConfiguration const& config)
|
||||
{
|
||||
std::string const format = config.format;
|
||||
|
||||
std::vector<spdlog::sink_ptr> allSinks = createConsoleSinks(config.enableConsole, format);
|
||||
|
||||
if (config.directory.has_value())
|
||||
{
|
||||
std::filesystem::path const dirPath{config.directory.value()};
|
||||
if (not std::filesystem::exists(dirPath))
|
||||
{
|
||||
if (std::error_code error; not std::filesystem::create_directories(dirPath, error))
|
||||
{
|
||||
return Unexpected{fmt::format(
|
||||
"Couldn't create logs directory '{}': {}", dirPath.string(), error.message())};
|
||||
}
|
||||
}
|
||||
|
||||
FileLoggingParams const params{
|
||||
.logDir = config.directory.value(),
|
||||
};
|
||||
allSinks.push_back(createFileSink(params, format));
|
||||
}
|
||||
return allSinks;
|
||||
}
|
||||
|
||||
Expected<void, std::string>
|
||||
LogService::init(LoggingConfiguration const& config)
|
||||
{
|
||||
auto const sinksMaybe = getSinks(config);
|
||||
if (!sinksMaybe.has_value())
|
||||
{
|
||||
return Unexpected{sinksMaybe.error()};
|
||||
}
|
||||
|
||||
logDir_ = config.directory;
|
||||
format_ = config.format;
|
||||
|
||||
LogServiceState::init(
|
||||
config.isAsync, config.defaultSeverity, std::move(sinksMaybe).value(), config.jsonMode);
|
||||
|
||||
// Register and set the "General" channel as the default logger.
|
||||
// All other channels are created dynamically at runtime via Logger(channel).
|
||||
spdlog::set_default_logger(registerLogger("General"));
|
||||
|
||||
LOG(LogService::info()) << "Default log level = " << toString(defaultSeverity_);
|
||||
return {};
|
||||
}
|
||||
|
||||
void
|
||||
LogService::shutdown()
|
||||
{
|
||||
if (initialized_ && isAsync_)
|
||||
{
|
||||
// We run in async mode in production, so we need to make sure all logs are flushed before
|
||||
// shutting down
|
||||
spdlog::shutdown();
|
||||
}
|
||||
}
|
||||
|
||||
std::string
|
||||
LogService::rotate()
|
||||
{
|
||||
if (!logDir_.has_value())
|
||||
{
|
||||
return "Log file rotation is not possible because file logging is not configured.";
|
||||
}
|
||||
|
||||
FileLoggingParams const params{.logDir = logDir_.value()};
|
||||
|
||||
auto newFileSink = createFileSink(params, format_);
|
||||
|
||||
// Replace any existing file sink with the new one
|
||||
for (auto& sink : sinks_)
|
||||
{
|
||||
if (dynamic_cast<spdlog::sinks::basic_file_sink_mt*>(sink.get()) != nullptr)
|
||||
{
|
||||
sink = newFileSink;
|
||||
break;
|
||||
}
|
||||
}
|
||||
|
||||
// Update all registered loggers with the new sinks
|
||||
spdlog::apply_all([](std::shared_ptr<spdlog::logger> logger) { logger->sinks() = sinks_; });
|
||||
|
||||
return "The log file was closed and reopened.";
|
||||
}
|
||||
|
||||
Logger::Pump
|
||||
LogService::trace(std::source_location const& loc)
|
||||
{
|
||||
return Logger(spdlog::default_logger()).trace(loc);
|
||||
}
|
||||
|
||||
Logger::Pump
|
||||
LogService::debug(std::source_location const& loc)
|
||||
{
|
||||
return Logger(spdlog::default_logger()).debug(loc);
|
||||
}
|
||||
|
||||
Logger::Pump
|
||||
LogService::info(std::source_location const& loc)
|
||||
{
|
||||
return Logger(spdlog::default_logger()).info(loc);
|
||||
}
|
||||
|
||||
Logger::Pump
|
||||
LogService::warn(std::source_location const& loc)
|
||||
{
|
||||
return Logger(spdlog::default_logger()).warn(loc);
|
||||
}
|
||||
|
||||
Logger::Pump
|
||||
LogService::error(std::source_location const& loc)
|
||||
{
|
||||
return Logger(spdlog::default_logger()).error(loc);
|
||||
}
|
||||
|
||||
Logger::Pump
|
||||
LogService::fatal(std::source_location const& loc)
|
||||
{
|
||||
return Logger(spdlog::default_logger()).fatal(loc);
|
||||
}
|
||||
|
||||
void
|
||||
LogServiceState::replaceSinks(std::vector<std::shared_ptr<spdlog::sinks::sink>> const& sinks)
|
||||
{
|
||||
sinks_ = sinks;
|
||||
spdlog::apply_all([](std::shared_ptr<spdlog::logger> logger) { logger->sinks() = sinks_; });
|
||||
}
|
||||
|
||||
std::unique_ptr<spdlog::formatter>
|
||||
LogServiceState::makeFormatter(std::string const& pattern)
|
||||
{
|
||||
return createPatternFormatter(pattern);
|
||||
}
|
||||
|
||||
Logger::Logger(std::string_view const channel) : logger_(LogServiceState::registerLogger(channel))
|
||||
{
|
||||
}
|
||||
|
||||
Logger::~Logger()
|
||||
{
|
||||
// One reference is held by logger_ and the other by spdlog registry
|
||||
static constexpr size_t kLAST_LOGGER_REF_COUNT = 2;
|
||||
|
||||
if (logger_ == nullptr)
|
||||
{
|
||||
return;
|
||||
}
|
||||
|
||||
if (logger_.use_count() == kLAST_LOGGER_REF_COUNT)
|
||||
{
|
||||
spdlog::drop(logger_->name());
|
||||
}
|
||||
}
|
||||
|
||||
Logger::Pump::Pump(
|
||||
std::shared_ptr<spdlog::logger> logger,
|
||||
Severity sev,
|
||||
std::source_location const& loc,
|
||||
bool jsonMode)
|
||||
: logger_(std::move(logger))
|
||||
, severity_(sev)
|
||||
, sourceLocation_(loc)
|
||||
, enabled_(logger_ != nullptr && logger_->should_log(toSpdlogLevel(sev)))
|
||||
, jsonMode_(jsonMode)
|
||||
{
|
||||
if (enabled_ && jsonMode_)
|
||||
{
|
||||
// Open the quoted message value
|
||||
stream_ += "\"";
|
||||
}
|
||||
}
|
||||
|
||||
Logger::Pump::~Pump()
|
||||
{
|
||||
if (enabled_)
|
||||
{
|
||||
spdlog::source_loc const sourceLocation{
|
||||
sourceLocation_.file_name(), static_cast<int>(sourceLocation_.line()), nullptr};
|
||||
|
||||
if (jsonMode_)
|
||||
{
|
||||
// Close the quoted message value
|
||||
stream_ += "\"";
|
||||
|
||||
// Append the parameters object if any were captured
|
||||
if (!parameters_.empty())
|
||||
{
|
||||
stream_ += ", \"values\": {";
|
||||
stream_ += parameters_;
|
||||
stream_ += "}";
|
||||
}
|
||||
}
|
||||
|
||||
// Apply legacy safeguards: truncate oversized messages and scrub secrets
|
||||
truncateMessage(stream_);
|
||||
scrubSecrets(stream_);
|
||||
|
||||
logger_->log(sourceLocation, toSpdlogLevel(severity_), stream_);
|
||||
}
|
||||
}
|
||||
|
||||
Logger::Pump
|
||||
Logger::trace(std::source_location const& loc) const
|
||||
{
|
||||
return {logger_, Severity::TRC, loc, LogServiceState::jsonMode_};
|
||||
}
|
||||
Logger::Pump
|
||||
Logger::debug(std::source_location const& loc) const
|
||||
{
|
||||
return {logger_, Severity::DBG, loc, LogServiceState::jsonMode_};
|
||||
}
|
||||
Logger::Pump
|
||||
Logger::info(std::source_location const& loc) const
|
||||
{
|
||||
return {logger_, Severity::NFO, loc, LogServiceState::jsonMode_};
|
||||
}
|
||||
Logger::Pump
|
||||
Logger::warn(std::source_location const& loc) const
|
||||
{
|
||||
return {logger_, Severity::WRN, loc, LogServiceState::jsonMode_};
|
||||
}
|
||||
Logger::Pump
|
||||
Logger::error(std::source_location const& loc) const
|
||||
{
|
||||
return {logger_, Severity::ERR, loc, LogServiceState::jsonMode_};
|
||||
}
|
||||
Logger::Pump
|
||||
Logger::fatal(std::source_location const& loc) const
|
||||
{
|
||||
return {logger_, Severity::FTL, loc, LogServiceState::jsonMode_};
|
||||
}
|
||||
|
||||
Logger::Logger(std::shared_ptr<spdlog::logger> logger) : logger_(std::move(logger))
|
||||
{
|
||||
}
|
||||
|
||||
} // namespace xrpl
|
||||
278
src/tests/libxrpl/basics/Logger.cpp
Normal file
278
src/tests/libxrpl/basics/Logger.cpp
Normal file
@@ -0,0 +1,278 @@
|
||||
#include <xrpl/basics/Logger.h>
|
||||
|
||||
#include <xrpl/basics/Number.h>
|
||||
#include <xrpl/protocol/XRPAmount.h>
|
||||
|
||||
#include <gtest/gtest.h>
|
||||
#include <spdlog/sinks/ostream_sink.h>
|
||||
#include <spdlog/spdlog.h>
|
||||
|
||||
#include <regex>
|
||||
#include <sstream>
|
||||
#include <string>
|
||||
|
||||
using namespace xrpl;
|
||||
|
||||
class LoggerFixture : public ::testing::Test
|
||||
{
|
||||
protected:
|
||||
std::ostringstream output_;
|
||||
|
||||
void
|
||||
initLogging(bool jsonMode, std::string const& pattern = "%v", Severity severity = Severity::TRC)
|
||||
{
|
||||
LoggingConfiguration config{
|
||||
.format = pattern,
|
||||
.enableConsole = false,
|
||||
.directory = std::nullopt,
|
||||
.isAsync = false,
|
||||
.defaultSeverity = severity,
|
||||
.jsonMode = jsonMode,
|
||||
};
|
||||
auto const result = LogService::init(config);
|
||||
ASSERT_TRUE(result);
|
||||
|
||||
// Replace the (empty) sinks with our ostream sink so we can
|
||||
// capture output in tests.
|
||||
auto sink = std::make_shared<spdlog::sinks::ostream_sink_mt>(output_);
|
||||
sink->set_level(spdlog::level::trace);
|
||||
sink->set_formatter(LogServiceState::makeFormatter(pattern));
|
||||
LogServiceState::replaceSinks({sink});
|
||||
}
|
||||
|
||||
void
|
||||
TearDown() override
|
||||
{
|
||||
spdlog::drop_all();
|
||||
if (LogService::initialized())
|
||||
LogService::reset();
|
||||
}
|
||||
};
|
||||
|
||||
// -- Plain text mode ---------------------------------------------------------
|
||||
|
||||
TEST_F(LoggerFixture, plain_text_simple_message)
|
||||
{
|
||||
initLogging(false);
|
||||
Logger logger("TestChannel");
|
||||
logger.info() << "hello world";
|
||||
EXPECT_EQ(output_.str(), "hello world\n");
|
||||
}
|
||||
|
||||
TEST_F(LoggerFixture, plain_text_multiple_values)
|
||||
{
|
||||
initLogging(false);
|
||||
Logger logger("TestChannel2");
|
||||
logger.info() << "count=" << 42 << " active=" << true;
|
||||
EXPECT_EQ(output_.str(), "count=42 active=true\n");
|
||||
}
|
||||
|
||||
TEST_F(LoggerFixture, plain_text_with_parameter)
|
||||
{
|
||||
initLogging(false);
|
||||
Logger logger("TestChannel3");
|
||||
logger.info() << "tx " << log::param("hash", "ABC");
|
||||
// In plain text mode, parameter value is just streamed
|
||||
EXPECT_EQ(output_.str(), "tx ABC\n");
|
||||
}
|
||||
|
||||
// -- JSON mode ---------------------------------------------------------------
|
||||
|
||||
TEST_F(LoggerFixture, json_mode_simple_message)
|
||||
{
|
||||
initLogging(true);
|
||||
Logger logger("JsonChannel");
|
||||
logger.info() << "hello world";
|
||||
// In JSON mode, message is quoted
|
||||
EXPECT_EQ(output_.str(), "\"hello world\"\n");
|
||||
}
|
||||
|
||||
TEST_F(LoggerFixture, json_mode_with_parameters)
|
||||
{
|
||||
initLogging(true);
|
||||
Logger logger("JsonChannel2");
|
||||
logger.info() << "processing " << log::param("tx_hash", std::string("ABC123"))
|
||||
<< " amount=" << log::param("amount", 42);
|
||||
// Message body is quoted, then values object appended
|
||||
EXPECT_EQ(
|
||||
output_.str(),
|
||||
"\"processing ABC123 amount=42\", "
|
||||
"\"values\": {\"tx_hash\":\"ABC123\",\"amount\":42}\n");
|
||||
}
|
||||
|
||||
TEST_F(LoggerFixture, json_mode_no_parameters)
|
||||
{
|
||||
initLogging(true);
|
||||
Logger logger("JsonChannel3");
|
||||
logger.info() << "simple message";
|
||||
// No values object when no parameters
|
||||
EXPECT_EQ(output_.str(), "\"simple message\"\n");
|
||||
}
|
||||
|
||||
TEST_F(LoggerFixture, json_mode_with_pattern)
|
||||
{
|
||||
std::string pattern =
|
||||
JsonLoggingPatternBuilder().add("level", "%l").add("channel", "%n").build();
|
||||
initLogging(true, pattern);
|
||||
Logger logger("Overlay");
|
||||
logger.info() << "peer connected";
|
||||
EXPECT_EQ(
|
||||
output_.str(),
|
||||
"{\"level\":\"info\",\"channel\":\"Overlay\","
|
||||
" \"message\": \"peer connected\" }\n");
|
||||
}
|
||||
|
||||
TEST_F(LoggerFixture, json_mode_bool_parameter)
|
||||
{
|
||||
initLogging(true);
|
||||
Logger logger("JsonChannel4");
|
||||
logger.info() << "status " << log::param("active", true);
|
||||
EXPECT_EQ(output_.str(), "\"status true\", \"values\": {\"active\":true}\n");
|
||||
}
|
||||
|
||||
// -- Severity filtering ------------------------------------------------------
|
||||
|
||||
TEST_F(LoggerFixture, severity_filtering)
|
||||
{
|
||||
initLogging(false, "%v", Severity::WRN);
|
||||
|
||||
Logger logger("FilterChannel");
|
||||
logger.info() << "should not appear";
|
||||
EXPECT_TRUE(output_.str().empty());
|
||||
|
||||
logger.warn() << "should appear";
|
||||
EXPECT_EQ(output_.str(), "should appear\n");
|
||||
}
|
||||
|
||||
// -- xrpl::to_string integration --------------------------------------------
|
||||
|
||||
TEST_F(LoggerFixture, text_mode_xrp_amount)
|
||||
{
|
||||
initLogging(false);
|
||||
Logger logger("AmountChannel");
|
||||
logger.info() << "balance: " << XRPAmount{1000};
|
||||
EXPECT_EQ(output_.str(), "balance: 1000\n");
|
||||
}
|
||||
|
||||
TEST_F(LoggerFixture, json_mode_xrp_amount)
|
||||
{
|
||||
initLogging(true);
|
||||
Logger logger("AmountChannel");
|
||||
logger.info() << "balance " << XRPAmount{500};
|
||||
EXPECT_EQ(output_.str(), "\"balance 500\"\n");
|
||||
}
|
||||
|
||||
TEST_F(LoggerFixture, json_mode_xrp_amount_parameter)
|
||||
{
|
||||
initLogging(true);
|
||||
Logger logger("AmountChannel");
|
||||
logger.info() << "tx" << log::param("fee", XRPAmount{10});
|
||||
EXPECT_EQ(output_.str(), "\"tx10\", \"values\": {\"fee\":\"10\"}\n");
|
||||
}
|
||||
|
||||
TEST_F(LoggerFixture, text_mode_number)
|
||||
{
|
||||
initLogging(false);
|
||||
Logger logger("NumberChannel");
|
||||
logger.info() << "result: " << Number{42};
|
||||
EXPECT_EQ(output_.str(), "result: 42\n");
|
||||
}
|
||||
|
||||
TEST_F(LoggerFixture, json_mode_number)
|
||||
{
|
||||
initLogging(true);
|
||||
Logger logger("NumberChannel");
|
||||
logger.info() << "value " << Number{25, -3};
|
||||
EXPECT_EQ(output_.str(), "\"value 0.025\"\n");
|
||||
}
|
||||
|
||||
TEST_F(LoggerFixture, json_mode_number_parameter)
|
||||
{
|
||||
initLogging(true);
|
||||
Logger logger("NumberChannel");
|
||||
logger.info() << "calc" << log::param("rate", Number{100});
|
||||
EXPECT_EQ(output_.str(), "\"calc100\", \"values\": {\"rate\":\"100\"}\n");
|
||||
}
|
||||
|
||||
// -- Legacy format matching ---------------------------------------------------
|
||||
|
||||
TEST_F(LoggerFixture, default_format_matches_legacy)
|
||||
{
|
||||
// Use the default format (kDEFAULT_LOG_FORMAT) which includes %K for severity
|
||||
initLogging(false, kDEFAULT_LOG_FORMAT);
|
||||
Logger logger("General");
|
||||
logger.info() << "hello world";
|
||||
auto const line = output_.str();
|
||||
|
||||
// The full output must be:
|
||||
// YYYY-Mon-DD HH:MM:SS.ffffff UTC General:NFO hello world\n
|
||||
std::regex const expected(
|
||||
R"(\d{4}-[A-Z][a-z]{2}-\d{2} \d{2}:\d{2}:\d{2}\.\d{6} UTC General:NFO hello world\n)");
|
||||
EXPECT_TRUE(std::regex_match(line, expected)) << "got: " << line;
|
||||
}
|
||||
|
||||
TEST_F(LoggerFixture, severity_codes_in_default_format)
|
||||
{
|
||||
initLogging(false, "%n:%K %v");
|
||||
Logger logger("Test");
|
||||
|
||||
logger.trace() << "t";
|
||||
logger.debug() << "d";
|
||||
logger.info() << "i";
|
||||
logger.warn() << "w";
|
||||
logger.error() << "e";
|
||||
logger.fatal() << "f";
|
||||
|
||||
EXPECT_EQ(
|
||||
output_.str(),
|
||||
"Test:TRC t\n"
|
||||
"Test:DBG d\n"
|
||||
"Test:NFO i\n"
|
||||
"Test:WRN w\n"
|
||||
"Test:ERR e\n"
|
||||
"Test:FTL f\n");
|
||||
}
|
||||
|
||||
// -- Secret scrubbing ---------------------------------------------------------
|
||||
|
||||
TEST_F(LoggerFixture, scrubs_seed)
|
||||
{
|
||||
initLogging(false);
|
||||
Logger logger("Scrub");
|
||||
logger.info() << R"({"seed":"sEdTM1uX8pu2do5XvTnutH6HsouMaM2"})";
|
||||
// 31 chars in the seed value → 31 asterisks
|
||||
EXPECT_EQ(output_.str(), "{\"seed\":\"*******************************\"}\n");
|
||||
}
|
||||
|
||||
TEST_F(LoggerFixture, scrubs_master_key)
|
||||
{
|
||||
initLogging(false);
|
||||
Logger logger("Scrub2");
|
||||
logger.info() << R"({"master_key":"SOME_SECRET_VALUE"})";
|
||||
EXPECT_EQ(output_.str(), "{\"master_key\":\"*****************\"}\n");
|
||||
}
|
||||
|
||||
TEST_F(LoggerFixture, scrubs_passphrase)
|
||||
{
|
||||
initLogging(false);
|
||||
Logger logger("Scrub3");
|
||||
logger.info() << R"({"passphrase":"my_secret_pass"})";
|
||||
EXPECT_EQ(output_.str(), "{\"passphrase\":\"**************\"}\n");
|
||||
}
|
||||
|
||||
// -- Message truncation -------------------------------------------------------
|
||||
|
||||
TEST_F(LoggerFixture, truncates_oversized_message)
|
||||
{
|
||||
initLogging(false);
|
||||
Logger logger("Trunc");
|
||||
// 12 * 1024 = 12288 max chars; create a message larger than that
|
||||
static constexpr std::size_t kMAX = 12 * 1024;
|
||||
std::string const bigMessage(13000, 'x');
|
||||
logger.info() << bigMessage;
|
||||
|
||||
// Expected: (kMAX - 3) 'x' chars + "..." + newline
|
||||
std::string expected(kMAX - 3, 'x');
|
||||
expected += "...\n";
|
||||
EXPECT_EQ(output_.str(), expected);
|
||||
}
|
||||
173
src/tests/libxrpl/basics/StructuredLogging.cpp
Normal file
173
src/tests/libxrpl/basics/StructuredLogging.cpp
Normal file
@@ -0,0 +1,173 @@
|
||||
#include <xrpl/basics/StructuredLogging.h>
|
||||
|
||||
#include <xrpl/basics/Number.h>
|
||||
#include <xrpl/protocol/XRPAmount.h>
|
||||
|
||||
#include <gtest/gtest.h>
|
||||
|
||||
#include <string>
|
||||
|
||||
using namespace xrpl;
|
||||
|
||||
// -- detail::appendJsonValue -------------------------------------------------
|
||||
|
||||
TEST(AppendJsonValue, bool_true)
|
||||
{
|
||||
std::string dest;
|
||||
detail::appendJsonValue(dest, true);
|
||||
EXPECT_EQ(dest, "true");
|
||||
}
|
||||
|
||||
TEST(AppendJsonValue, bool_false)
|
||||
{
|
||||
std::string dest;
|
||||
detail::appendJsonValue(dest, false);
|
||||
EXPECT_EQ(dest, "false");
|
||||
}
|
||||
|
||||
TEST(AppendJsonValue, integral_positive)
|
||||
{
|
||||
std::string dest;
|
||||
detail::appendJsonValue(dest, 42);
|
||||
EXPECT_EQ(dest, "42");
|
||||
}
|
||||
|
||||
TEST(AppendJsonValue, integral_negative)
|
||||
{
|
||||
std::string dest;
|
||||
detail::appendJsonValue(dest, -7);
|
||||
EXPECT_EQ(dest, "-7");
|
||||
}
|
||||
|
||||
TEST(AppendJsonValue, integral_zero)
|
||||
{
|
||||
std::string dest;
|
||||
detail::appendJsonValue(dest, 0);
|
||||
EXPECT_EQ(dest, "0");
|
||||
}
|
||||
|
||||
TEST(AppendJsonValue, string_quoted)
|
||||
{
|
||||
std::string dest;
|
||||
std::string val = "hello";
|
||||
detail::appendJsonValue(dest, val);
|
||||
EXPECT_EQ(dest, "\"hello\"");
|
||||
}
|
||||
|
||||
TEST(AppendJsonValue, appends_to_existing)
|
||||
{
|
||||
std::string dest = "prefix:";
|
||||
detail::appendJsonValue(dest, 99);
|
||||
EXPECT_EQ(dest, "prefix:99");
|
||||
}
|
||||
|
||||
// -- JsonLoggingPatternBuilder -----------------------------------------------
|
||||
|
||||
TEST(JsonLoggingPatternBuilder, empty_build)
|
||||
{
|
||||
JsonLoggingPatternBuilder builder;
|
||||
EXPECT_EQ(builder.build(), "{, \"message\": %v }");
|
||||
}
|
||||
|
||||
TEST(JsonLoggingPatternBuilder, single_string_field)
|
||||
{
|
||||
JsonLoggingPatternBuilder builder;
|
||||
builder.add("level", "%l");
|
||||
EXPECT_EQ(builder.build(), "{\"level\":\"%l\", \"message\": %v }");
|
||||
}
|
||||
|
||||
TEST(JsonLoggingPatternBuilder, multiple_string_fields)
|
||||
{
|
||||
JsonLoggingPatternBuilder builder;
|
||||
builder.add("level", "%l");
|
||||
builder.add("channel", "%n");
|
||||
EXPECT_EQ(builder.build(), "{\"level\":\"%l\",\"channel\":\"%n\", \"message\": %v }");
|
||||
}
|
||||
|
||||
TEST(JsonLoggingPatternBuilder, typed_fields)
|
||||
{
|
||||
JsonLoggingPatternBuilder builder;
|
||||
builder.add("enabled", true);
|
||||
builder.add("count", 5);
|
||||
EXPECT_EQ(builder.build(), "{\"enabled\":true,\"count\":5, \"message\": %v }");
|
||||
}
|
||||
|
||||
TEST(JsonLoggingPatternBuilder, chaining)
|
||||
{
|
||||
JsonLoggingPatternBuilder builder;
|
||||
builder.add("a", "1").add("b", "2").add("c", "3");
|
||||
EXPECT_EQ(builder.build(), "{\"a\":\"1\",\"b\":\"2\",\"c\":\"3\", \"message\": %v }");
|
||||
}
|
||||
|
||||
TEST(JsonLoggingPatternBuilder, from_existing_pattern)
|
||||
{
|
||||
JsonLoggingPatternBuilder original;
|
||||
original.add("level", "%l").add("channel", "%n");
|
||||
auto const pattern = original.build();
|
||||
|
||||
JsonLoggingPatternBuilder extended(pattern);
|
||||
extended.add("source", "%s:%#");
|
||||
EXPECT_EQ(
|
||||
extended.build(),
|
||||
"{\"level\":\"%l\",\"channel\":\"%n\",\"source\":\"%s:%#\", \"message\": %v }");
|
||||
}
|
||||
|
||||
// -- log::Parameter / log::param ---------------------------------------------
|
||||
|
||||
TEST(LogParameter, string_param)
|
||||
{
|
||||
auto const p = log::param("tx_hash", std::string("ABC123"));
|
||||
EXPECT_EQ(p.name(), "tx_hash");
|
||||
EXPECT_EQ(p.value(), "ABC123");
|
||||
}
|
||||
|
||||
TEST(LogParameter, int_param)
|
||||
{
|
||||
auto const p = log::param("count", 42);
|
||||
EXPECT_EQ(p.name(), "count");
|
||||
EXPECT_EQ(p.value(), 42);
|
||||
}
|
||||
|
||||
TEST(LogParameter, bool_param)
|
||||
{
|
||||
auto const p = log::param("active", true);
|
||||
EXPECT_EQ(p.name(), "active");
|
||||
EXPECT_EQ(p.value(), true);
|
||||
}
|
||||
|
||||
// -- detail::HasToString concept ---------------------------------------------
|
||||
|
||||
TEST(HasToString, xrp_amount_satisfies_concept)
|
||||
{
|
||||
static_assert(detail::HasToString<XRPAmount>);
|
||||
}
|
||||
|
||||
TEST(HasToString, number_satisfies_concept)
|
||||
{
|
||||
static_assert(detail::HasToString<Number>);
|
||||
}
|
||||
|
||||
TEST(HasToString, builtin_types_without_adl)
|
||||
{
|
||||
// Built-in types have no associated namespace for ADL, so unless
|
||||
// ToString.h is explicitly included they do not satisfy HasToString.
|
||||
// They are handled by the fmt::format fallback path instead.
|
||||
static_assert(!detail::HasToString<int>);
|
||||
static_assert(!detail::HasToString<double>);
|
||||
}
|
||||
|
||||
// -- appendJsonValue with to_string types ------------------------------------
|
||||
|
||||
TEST(AppendJsonValue, xrp_amount_quoted)
|
||||
{
|
||||
std::string dest;
|
||||
detail::appendJsonValue(dest, XRPAmount{1000});
|
||||
EXPECT_EQ(dest, "\"1000\"");
|
||||
}
|
||||
|
||||
TEST(AppendJsonValue, number_quoted)
|
||||
{
|
||||
std::string dest;
|
||||
detail::appendJsonValue(dest, Number{25, -3});
|
||||
EXPECT_EQ(dest, "\"0.025\"");
|
||||
}
|
||||
Reference in New Issue
Block a user