structured logs

This commit is contained in:
JCW
2025-08-21 14:37:53 +01:00
parent ceb0ce5634
commit 569fd56579
24 changed files with 1929 additions and 131 deletions

View File

@@ -31,6 +31,7 @@
#include <memory>
#include <mutex>
#include <utility>
#include <string_view>
namespace ripple {
@@ -130,27 +131,14 @@ private:
Does nothing if there is no associated system file.
*/
void
write(char const* text);
write(std::string_view text);
/** write to the log file and append an end of line marker.
Does nothing if there is no associated system file.
*/
void
writeln(char const* text);
writeln(std::string_view text);
/** Write to the log file using std::string. */
/** @{ */
void
write(std::string const& str)
{
write(str.c_str());
}
void
writeln(std::string const& str)
{
writeln(str.c_str());
}
/** @} */
private:
@@ -186,6 +174,14 @@ public:
beast::Journal::Sink&
operator[](std::string const& name);
template <typename AttributesFactory>
beast::Journal
journal(std::string const& name, AttributesFactory&& factory)
{
return beast::Journal{
get(name), name, std::forward<AttributesFactory>(factory)};
}
beast::Journal
journal(std::string const& name);
@@ -237,30 +233,34 @@ public:
static LogSeverity
fromString(std::string const& s);
private:
enum {
// Maximum line length for log messages.
// If the message exceeds this length it will be truncated with elipses.
maximumMessageCharacters = 12 * 1024
};
static void
format(
std::string& output,
std::string const& message,
beast::severities::Severity severity,
std::string const& partition);
private:
enum {
// Maximum line length for log messages.
// If the message exceeds this length it will be truncated with elipses.
maximumMessageCharacters = 12 * 1024
};
};
// Wraps a Journal::Stream to skip evaluation of
// expensive argument lists if the stream is not active.
#ifndef JLOG
#define JLOG_JOIN_(a,b) a##b
#define JLOG_JOIN(a,b) JLOG_JOIN_(a,b)
#define JLOG_UNIQUE(base) JLOG_JOIN(base, __LINE__) // line-based unique name
#define JLOG(x) \
if (!x) \
{ \
} \
else \
x
if (auto JLOG_UNIQUE(stream) = (x); !JLOG_UNIQUE(stream)) \
{ \
} \
else \
std::move(JLOG_UNIQUE(stream))
#endif
#ifndef CLOG

View File

@@ -22,10 +22,262 @@
#include <xrpl/beast/utility/instrumentation.h>
#include <deque>
#include <atomic>
#include <charconv>
#include <cstring>
#include <mutex>
#include <shared_mutex>
#include <source_location>
#include <sstream>
#include <string>
#include <string_view>
#include <utility>
namespace ripple::log {
template <typename T>
class LogParameter
{
public:
template <typename TArg>
LogParameter(char const* name, TArg&& value)
: name_(name), value_(std::forward<TArg>(value))
{
}
private:
char const* name_;
T value_;
template <typename U>
friend std::ostream&
operator<<(std::ostream& os, LogParameter<U> const&);
};
template <typename T>
class LogField
{
public:
template <typename TArg>
LogField(char const* name, TArg&& value)
: name_(name), value_(std::forward<TArg>(value))
{
}
private:
char const* name_;
T value_;
template <typename U>
friend std::ostream&
operator<<(std::ostream& os, LogField<U> const&);
};
template <typename T>
std::ostream&
operator<<(std::ostream& os, LogField<T> const& param);
template <typename T>
std::ostream&
operator<<(std::ostream& os, LogParameter<T> const& param);
} // namespace ripple::log
namespace beast {
namespace detail {
class SimpleJsonWriter
{
public:
explicit SimpleJsonWriter(std::string* buffer) : buffer_(buffer)
{
}
SimpleJsonWriter() = default;
SimpleJsonWriter(SimpleJsonWriter const& other) = default;
SimpleJsonWriter& operator=(SimpleJsonWriter const& other) = default;
std::string&
buffer() { return *buffer_; }
void
startObject() const
{
buffer_->push_back('{');
}
void
endObject() const
{
using namespace std::string_view_literals;
if (buffer_->back() == ',')
buffer_->pop_back();
buffer_->append("},"sv);
}
void
writeKey(std::string_view key) const
{
writeString(key);
buffer_->back() = ':';
}
void
startArray() const
{
buffer_->push_back('[');
}
void
endArray() const
{
using namespace std::string_view_literals;
if (buffer_->back() == ',')
buffer_->pop_back();
buffer_->append("],"sv);
}
void
writeString(std::string_view str) const
{
using namespace std::string_view_literals;
buffer_->push_back('"');
escape(str, *buffer_);
buffer_->append("\","sv);
}
std::string_view
writeInt(std::int32_t val) const
{
return pushNumber(val, *buffer_);
}
std::string_view
writeInt(std::int64_t val) const
{
return pushNumber(val, *buffer_);
}
std::string_view
writeUInt(std::uint32_t val) const
{
return pushNumber(val, *buffer_);
}
std::string_view
writeUInt(std::uint64_t val) const
{
return pushNumber(val, *buffer_);
}
std::string_view
writeDouble(double val) const
{
return pushNumber(val, *buffer_);
}
std::string_view
writeBool(bool val) const
{
using namespace std::string_view_literals;
auto str = val ? "true,"sv : "false,"sv;
buffer_->append(str);
return str;
}
void
writeNull() const
{
using namespace std::string_view_literals;
buffer_->append("null,"sv);
}
void
writeRaw(std::string_view str) const
{
buffer_->append(str);
}
void
finish()
{
buffer_->pop_back();
}
private:
template <typename T>
static std::string_view
pushNumber(T val, std::string& str)
{
thread_local char buffer[128];
auto result = std::to_chars(std::begin(buffer), std::end(buffer), val);
auto ptr = result.ptr;
*ptr = ',';
auto len = ptr - std::begin(buffer);
str.append(buffer, len + 1);
return {buffer, static_cast<size_t>(len)};
}
static void
escape(std::string_view str, std::string& buffer)
{
static constexpr char HEX[] = "0123456789ABCDEF";
char const* p = str.data();
char const* end = p + str.size();
char const* chunk = p;
while (p < end)
{
auto c = static_cast<unsigned char>(*p);
// JSON requires escaping for <0x20 and the two specials below.
bool needsEscape = (c < 0x20) || (c == '"') || (c == '\\');
if (!needsEscape)
{
++p;
continue;
}
// Flush the preceding safe run in one go.
if (chunk != p)
buffer.append(chunk, p - chunk);
switch (c)
{
case '"':
buffer.append("\\\"", 2);
break;
case '\\':
buffer.append("\\\\", 2);
break;
case '\b':
buffer.append("\\b", 2);
break;
case '\f':
buffer.append("\\f", 2);
break;
case '\n':
buffer.append("\\n", 2);
break;
case '\r':
buffer.append("\\r", 2);
break;
case '\t':
buffer.append("\\t", 2);
break;
default: {
// Other C0 controls -> \u00XX (JSON compliant)
char buf[6]{
'\\', 'u', '0', '0', HEX[(c >> 4) & 0xF], HEX[c & 0xF]};
buffer.append(buf, 6);
break;
}
}
++p;
chunk = p;
}
// Flush trailing safe run
if (chunk != p)
buffer.append(chunk, p - chunk);
}
std::string* buffer_ = nullptr;
};
} // namespace detail
/** A namespace for easy access to logging severity values. */
namespace severities {
/** Severity level / threshold of a Journal message. */
@@ -42,6 +294,9 @@ enum Severity {
kDisabled,
kNone = kDisabled
};
std::string_view
to_string(Severity severity);
} // namespace severities
/** A generic endpoint for log messages.
@@ -59,18 +314,112 @@ enum Severity {
class Journal
{
public:
template <typename T>
friend std::ostream&
ripple::log::operator<<(
std::ostream& os,
ripple::log::LogField<T> const& param);
template <typename T>
friend std::ostream&
ripple::log::operator<<(
std::ostream& os,
ripple::log::LogParameter<T> const& param);
class Sink;
class JsonLogContext
{
std::string messageBuffer_;
detail::SimpleJsonWriter jsonWriter_;
bool hasMessageParams_ = false;
std::size_t messageOffset_ = 0;
public:
JsonLogContext()
: jsonWriter_(&messageBuffer_)
{
messageBuffer_.reserve(4 * 1024);
}
std::string&
messageBuffer() { return messageBuffer_; }
void
startMessageParams()
{
if (!hasMessageParams_)
{
writer().writeKey("Dt");
writer().startObject();
hasMessageParams_ = true;
}
}
void
endMessageParams()
{
if (hasMessageParams_)
{
writer().endObject();
}
}
detail::SimpleJsonWriter&
writer()
{
return jsonWriter_;
}
void
reuseJson();
void
finish();
void
start(
std::source_location location,
severities::Severity severity,
std::string_view moduleName,
std::string_view journalAttributes) noexcept;
};
private:
// Severity level / threshold of a Journal message.
using Severity = severities::Severity;
std::string name_;
std::string attributes_;
static std::string globalLogAttributes_;
static std::shared_mutex globalLogAttributesMutex_;
static bool jsonLogsEnabled_;
static thread_local JsonLogContext currentJsonLogContext_;
// Invariant: m_sink always points to a valid Sink
Sink* m_sink;
Sink* m_sink = nullptr;
void
initMessageContext(
std::source_location location,
severities::Severity severity) const;
static std::string&
formatLog(std::string const& message);
public:
//--------------------------------------------------------------------------
static void
enableStructuredJournal();
static void
disableStructuredJournal();
static bool
isStructuredJournalEnabled();
/** Abstraction for the underlying message destination. */
class Sink
{
@@ -261,11 +610,32 @@ public:
/** Output stream support. */
/** @{ */
ScopedStream
operator<<(std::ostream& manip(std::ostream&)) const;
operator<<(std::ostream& manip(std::ostream&)) const &&
{
return {*this, manip};
}
template <typename T>
ScopedStream
operator<<(T const& t) const;
operator<<(T const& t) const &&
{
return {*this, t};
}
ScopedStream
operator<<(std::ostream& manip(std::ostream&)) const &
{
currentJsonLogContext_.reuseJson();
return {*this, manip};
}
template <typename T>
ScopedStream
operator<<(T const& t) const &
{
currentJsonLogContext_.reuseJson();
return {*this, t};
}
/** @} */
private:
@@ -287,11 +657,73 @@ public:
/** Journal has no default constructor. */
Journal() = delete;
/** Create a journal that writes to the specified sink. */
explicit Journal(Sink& sink) : m_sink(&sink)
Journal(Journal const& other)
: name_(other.name_)
, attributes_(other.attributes_)
, m_sink(other.m_sink)
{
}
template <typename TAttributesFactory>
Journal(Journal const& other, TAttributesFactory&& attributesFactory)
: name_(other.name_), m_sink(other.m_sink)
{
std::string buffer{other.attributes_};
detail::SimpleJsonWriter writer{&buffer};
if (other.attributes_.empty() && jsonLogsEnabled_)
{
writer.startObject();
}
attributesFactory(writer);
attributes_ = std::move(buffer);
}
/** Create a journal that writes to the specified sink. */
explicit Journal(Sink& sink, std::string const& name = {})
: name_(name), m_sink(&sink)
{
}
/** Create a journal that writes to the specified sink. */
template <typename TAttributesFactory>
explicit Journal(
Sink& sink,
std::string const& name,
TAttributesFactory&& attributesFactory)
: name_(name), m_sink(&sink)
{
std::string buffer;
buffer.reserve(128);
detail::SimpleJsonWriter writer{&buffer};
if (jsonLogsEnabled_)
{
writer.startObject();
}
attributesFactory(writer);
attributes_ = std::move(buffer);
}
Journal&
operator=(Journal const& other)
{
if (&other == this)
return *this; // LCOV_EXCL_LINE
m_sink = other.m_sink;
name_ = other.name_;
attributes_ = other.attributes_;
return *this;
}
Journal&
operator=(Journal&& other) noexcept
{
m_sink = other.m_sink;
name_ = std::move(other.name_);
attributes_ = std::move(other.attributes_);
return *this;
}
/** Returns the Sink associated with this Journal. */
Sink&
sink() const
@@ -301,8 +733,11 @@ public:
/** Returns a stream for this sink, with the specified severity level. */
Stream
stream(Severity level) const
stream(
Severity level,
std::source_location location = std::source_location::current()) const
{
initMessageContext(location, level);
return Stream(*m_sink, level);
}
@@ -319,41 +754,69 @@ public:
/** Severity stream access functions. */
/** @{ */
Stream
trace() const
trace(std::source_location location = std::source_location::current()) const
{
initMessageContext(location, severities::kTrace);
return {*m_sink, severities::kTrace};
}
Stream
debug() const
debug(std::source_location location = std::source_location::current()) const
{
initMessageContext(location, severities::kDebug);
return {*m_sink, severities::kDebug};
}
Stream
info() const
info(std::source_location location = std::source_location::current()) const
{
initMessageContext(location, severities::kInfo);
return {*m_sink, severities::kInfo};
}
Stream
warn() const
warn(std::source_location location = std::source_location::current()) const
{
initMessageContext(location, severities::kWarning);
return {*m_sink, severities::kWarning};
}
Stream
error() const
error(std::source_location location = std::source_location::current()) const
{
initMessageContext(location, severities::kError);
return {*m_sink, severities::kError};
}
Stream
fatal() const
fatal(std::source_location location = std::source_location::current()) const
{
initMessageContext(location, severities::kFatal);
return {*m_sink, severities::kFatal};
}
/** @} */
static void
resetGlobalAttributes()
{
std::unique_lock lock(globalLogAttributesMutex_);
globalLogAttributes_.clear();
}
template <typename TAttributesFactory>
static void
addGlobalAttributes(TAttributesFactory&& factory)
{
std::unique_lock lock(globalLogAttributesMutex_);
globalLogAttributes_.reserve(1024);
auto isEmpty = globalLogAttributes_.empty();
detail::SimpleJsonWriter writer{&globalLogAttributes_};
if (isEmpty && jsonLogsEnabled_)
{
writer.startObject();
}
factory(writer);
}
};
#ifndef __INTELLISENSE__
@@ -368,7 +831,7 @@ static_assert(std::is_nothrow_destructible<Journal>::value == true, "");
//------------------------------------------------------------------------------
template <typename T>
Journal::ScopedStream::ScopedStream(Journal::Stream const& stream, T const& t)
Journal::ScopedStream::ScopedStream(Stream const& stream, T const& t)
: ScopedStream(stream.sink(), stream.level())
{
m_ostream << t;
@@ -384,13 +847,6 @@ Journal::ScopedStream::operator<<(T const& t) const
//------------------------------------------------------------------------------
template <typename T>
Journal::ScopedStream
Journal::Stream::operator<<(T const& t) const
{
return ScopedStream(*this, t);
}
namespace detail {
template <class CharT, class Traits = std::char_traits<CharT>>
@@ -460,4 +916,242 @@ using logwstream = basic_logstream<wchar_t>;
} // namespace beast
namespace ripple::log {
namespace detail {
template <typename T>
concept ToCharsFormattable = requires(T val) {
{
to_chars(std::declval<char*>(), std::declval<char*>(), val)
} -> std::convertible_to<std::to_chars_result>;
};
template <typename T>
concept StreamFormattable = requires(T val) {
{
std::declval<std::ostream&>() << val
} -> std::convertible_to<std::ostream&>;
};
template <typename T>
void
setTextValue(
beast::detail::SimpleJsonWriter& writer,
char const* name,
T&& value)
{
using ValueType = std::decay_t<T>;
writer.buffer() += name;
writer.buffer() += ": ";
if constexpr (
std::is_same_v<ValueType, std::string> ||
std::is_same_v<ValueType, std::string_view> ||
std::is_same_v<ValueType, char const*> ||
std::is_same_v<ValueType, char*>)
{
writer.buffer() += value;
}
else
{
std::ostringstream oss;
oss << value;
writer.buffer() += value;;
}
writer.buffer() += " ";
}
template <typename T>
void
setJsonValue(
beast::detail::SimpleJsonWriter& writer,
char const* name,
T&& value,
std::ostream* outStream)
{
using ValueType = std::decay_t<T>;
writer.writeKey(name);
if constexpr (std::is_same_v<ValueType, bool>)
{
auto sv = writer.writeBool(value);
if (outStream)
{
outStream->write(sv.data(), sv.size());
}
}
else if constexpr (std::is_integral_v<ValueType>)
{
std::string_view sv;
if constexpr (std::is_signed_v<ValueType>)
{
if constexpr (sizeof(ValueType) > 4)
{
sv = writer.writeInt(static_cast<std::int64_t>(value));
}
else
{
sv = writer.writeInt(static_cast<std::int32_t>(value));
}
}
else
{
if constexpr (sizeof(ValueType) > 4)
{
sv = writer.writeUInt(static_cast<std::uint64_t>(value));
}
else
{
sv = writer.writeUInt(static_cast<std::uint32_t>(value));
}
}
if (outStream)
{
outStream->write(sv.data(), sv.size());
}
}
else if constexpr (std::is_floating_point_v<ValueType>)
{
auto sv = writer.writeDouble(value);
if (outStream)
{
outStream->write(sv.data(), sv.size());
}
}
else if constexpr (
std::is_same_v<ValueType, char const*> ||
std::is_same_v<ValueType, char*>)
{
writer.writeString(value);
if (outStream)
{
outStream->write(value, std::strlen(value));
}
}
else if constexpr (
std::is_same_v<ValueType, std::string> ||
std::is_same_v<ValueType, std::string_view>)
{
writer.writeString(value);
if (outStream)
{
outStream->write(value.data(), value.size());
}
}
else
{
if constexpr (ToCharsFormattable<ValueType>)
{
char buffer[1024];
std::to_chars_result result =
to_chars(std::begin(buffer), std::end(buffer), value);
if (result.ec == std::errc{})
{
std::string_view sv{std::begin(buffer), result.ptr};
writer.writeString(sv);
if (outStream)
{
outStream->write(sv.data(), sv.size());
}
return;
}
}
if constexpr (StreamFormattable<ValueType>)
{
std::ostringstream oss;
oss.imbue(std::locale::classic());
oss << value;
auto str = oss.str();
writer.writeString(str);
if (outStream)
{
outStream->write(
str.c_str(), static_cast<std::streamsize>(str.size()));
}
return;
}
static_assert(
ToCharsFormattable<ValueType> || StreamFormattable<ValueType>);
}
}
} // namespace detail
template <typename T>
std::ostream&
operator<<(std::ostream& os, LogParameter<T> const& param)
{
if (!beast::Journal::jsonLogsEnabled_)
{
os << param.value_;
return os;
}
beast::Journal::currentJsonLogContext_.startMessageParams();
detail::setJsonValue(
beast::Journal::currentJsonLogContext_.writer(),
param.name_,
param.value_,
&os);
return os;
}
template <typename T>
std::ostream&
operator<<(std::ostream& os, LogField<T> const& param)
{
if (!beast::Journal::jsonLogsEnabled_)
return os;
beast::Journal::currentJsonLogContext_.startMessageParams();
detail::setJsonValue(
beast::Journal::currentJsonLogContext_.writer(),
param.name_,
param.value_,
nullptr);
return os;
}
template <typename T>
LogParameter<T>
param(char const* name, T&& value)
{
return LogParameter<T>{name, std::forward<T>(value)};
}
template <typename T>
LogField<T>
field(char const* name, T&& value)
{
return LogField<T>{name, std::forward<T>(value)};
}
template <typename... Pair>
[[nodiscard]] auto
attributes(Pair&&... pairs)
{
return [&](beast::detail::SimpleJsonWriter& writer) {
if (beast::Journal::isStructuredJournalEnabled())
{
(detail::setJsonValue(writer, pairs.first, pairs.second, nullptr), ...);
}
else
{
(detail::setTextValue(writer, pairs.first, pairs.second), ...);
}
};
}
template <typename T>
[[nodiscard]] std::pair<char const*, std::decay_t<T>>
attr(char const* name, T&& value)
{
return std::make_pair(name, std::forward<T>(value));
}
} // namespace ripple::log
#endif

View File

@@ -47,7 +47,6 @@ protected:
Port const& port_;
Handler& handler_;
endpoint_type remote_address_;
beast::WrappedSink sink_;
beast::Journal const j_;
boost::asio::executor_work_guard<boost::asio::executor> work_;
@@ -84,13 +83,13 @@ BasePeer<Handler, Impl>::BasePeer(
: port_(port)
, handler_(handler)
, remote_address_(remote_address)
, sink_(
journal.sink(),
[] {
static std::atomic<unsigned> id{0};
return "##" + std::to_string(++id) + " ";
}())
, j_(sink_)
, j_(journal,
log::attributes(log::attr(
"PeerID",
[] {
static std::atomic<unsigned> id{0};
return "##" + std::to_string(++id) + " ";
}())))
, work_(executor)
, strand_(executor)
{