Compare commits

...

5 Commits

Author SHA1 Message Date
JCW
f3d1539766 Fix formatting
Signed-off-by: JCW <a1q123456@users.noreply.github.com>
2025-09-29 10:00:43 +01:00
JCW
80108d6652 Fix errors
Signed-off-by: JCW <a1q123456@users.noreply.github.com>
2025-09-29 09:59:12 +01:00
JCW
fd60e2d8d1 Fix formatting
Signed-off-by: JCW <a1q123456@users.noreply.github.com>
2025-09-26 15:44:57 +01:00
JCW
c74ab255c6 Set log style to json
Signed-off-by: JCW <a1q123456@users.noreply.github.com>
2025-09-26 15:44:37 +01:00
JCW
569fd56579 structured logs 2025-09-26 15:42:59 +01:00
24 changed files with 1932 additions and 133 deletions

View File

@@ -30,6 +30,7 @@
#include <map>
#include <memory>
#include <mutex>
#include <string_view>
#include <utility>
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(x) \
if (!x) \
{ \
} \
else \
x
#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 (auto JLOG_UNIQUE(stream) = (x); !JLOG_UNIQUE(stream)) \
{ \
} \
else \
std::move(JLOG_UNIQUE(stream))
#endif
#ifndef CLOG

View File

@@ -22,10 +22,266 @@
#include <xrpl/beast/utility/instrumentation.h>
#include <atomic>
#include <charconv>
#include <cstring>
#include <deque>
#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 +298,9 @@ enum Severity {
kDisabled,
kNone = kDisabled
};
std::string_view
to_string(Severity severity);
} // namespace severities
/** A generic endpoint for log messages.
@@ -59,18 +318,114 @@ 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 +616,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 +663,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 +739,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 +760,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 +837,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 +853,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 +922,244 @@ 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)
{

View File

@@ -113,14 +113,14 @@ Logs::File::close()
}
void
Logs::File::write(char const* text)
Logs::File::write(std::string_view text)
{
if (m_stream != nullptr)
(*m_stream) << text;
}
void
Logs::File::writeln(char const* text)
Logs::File::writeln(std::string_view text)
{
if (m_stream != nullptr)
{
@@ -196,11 +196,15 @@ Logs::write(
bool console)
{
std::string s;
format(s, text, level, partition);
std::string_view result = text;
if (!beast::Journal::isStructuredJournalEnabled())
{
format(s, text, level, partition);
result = text;
}
std::lock_guard lock(mutex_);
file_.writeln(s);
if (!silent_)
std::cerr << s << '\n';
file_.writeln(result);
// VFALCO TODO Fix console output
// if (console)
// out_.write_console(s);

View File

@@ -19,12 +19,102 @@
#include <xrpl/beast/utility/Journal.h>
#include <chrono>
#include <ios>
#include <ostream>
#include <ranges>
#include <string>
#include <thread>
namespace beast {
namespace {
// Fast timestamp to ISO string conversion
// Returns string like "2024-01-15T10:30:45.123Z"
std::string_view
fastTimestampToString(std::int64_t milliseconds_since_epoch)
{
thread_local char buffer[64]; // "2024-01-15T10:30:45.123Z"
// Precomputed lookup table for 2-digit numbers 00-99
static constexpr char digits[200] = {
'0', '0', '0', '1', '0', '2', '0', '3', '0', '4', '0', '5', '0', '6',
'0', '7', '0', '8', '0', '9', '1', '0', '1', '1', '1', '2', '1', '3',
'1', '4', '1', '5', '1', '6', '1', '7', '1', '8', '1', '9', '2', '0',
'2', '1', '2', '2', '2', '3', '2', '4', '2', '5', '2', '6', '2', '7',
'2', '8', '2', '9', '3', '0', '3', '1', '3', '2', '3', '3', '3', '4',
'3', '5', '3', '6', '3', '7', '3', '8', '3', '9', '4', '0', '4', '1',
'4', '2', '4', '3', '4', '4', '4', '5', '4', '6', '4', '7', '4', '8',
'4', '9', '5', '0', '5', '1', '5', '2', '5', '3', '5', '4', '5', '5',
'5', '6', '5', '7', '5', '8', '5', '9', '6', '0', '6', '1', '6', '2',
'6', '3', '6', '4', '6', '5', '6', '6', '6', '7', '6', '8', '6', '9',
'7', '0', '7', '1', '7', '2', '7', '3', '7', '4', '7', '5', '7', '6',
'7', '7', '7', '8', '7', '9', '8', '0', '8', '1', '8', '2', '8', '3',
'8', '4', '8', '5', '8', '6', '8', '7', '8', '8', '8', '9', '9', '0',
'9', '1', '9', '2', '9', '3', '9', '4', '9', '5', '9', '6', '9', '7',
'9', '8', '9', '9'};
constexpr std::int64_t UNIX_EPOCH_DAYS =
719468; // Days from year 0 to 1970-01-01
std::int64_t seconds = milliseconds_since_epoch / 1000;
int ms = milliseconds_since_epoch % 1000;
std::int64_t days = seconds / 86400 + UNIX_EPOCH_DAYS;
int sec_of_day = seconds % 86400;
// Calculate year, month, day from days using Gregorian calendar algorithm
int era = (days >= 0 ? days : days - 146096) / 146097;
int doe = days - era * 146097;
int yoe = (doe - doe / 1460 + doe / 36524 - doe / 146096) / 365;
int year = yoe + era * 400;
int doy = doe - (365 * yoe + yoe / 4 - yoe / 100);
int mp = (5 * doy + 2) / 153;
int day = doy - (153 * mp + 2) / 5 + 1;
int month = mp + (mp < 10 ? 3 : -9);
year += (month <= 2);
// Calculate hour, minute, second
int hour = sec_of_day / 3600;
int min = (sec_of_day % 3600) / 60;
int sec = sec_of_day % 60;
// Format: "2024-01-15T10:30:45.123Z"
buffer[0] = '0' + year / 1000;
buffer[1] = '0' + (year / 100) % 10;
buffer[2] = '0' + (year / 10) % 10;
buffer[3] = '0' + year % 10;
buffer[4] = '-';
buffer[5] = digits[month * 2];
buffer[6] = digits[month * 2 + 1];
buffer[7] = '-';
buffer[8] = digits[day * 2];
buffer[9] = digits[day * 2 + 1];
buffer[10] = 'T';
buffer[11] = digits[hour * 2];
buffer[12] = digits[hour * 2 + 1];
buffer[13] = ':';
buffer[14] = digits[min * 2];
buffer[15] = digits[min * 2 + 1];
buffer[16] = ':';
buffer[17] = digits[sec * 2];
buffer[18] = digits[sec * 2 + 1];
buffer[19] = '.';
buffer[20] = '0' + ms / 100;
buffer[21] = '0' + (ms / 10) % 10;
buffer[22] = '0' + ms % 10;
buffer[23] = 'Z';
return {buffer, 24};
}
} // anonymous namespace
std::string Journal::globalLogAttributes_;
std::shared_mutex Journal::globalLogAttributesMutex_;
bool Journal::jsonLogsEnabled_ = false;
thread_local Journal::JsonLogContext Journal::currentJsonLogContext_{};
//------------------------------------------------------------------------------
// A Sink that does nothing.
@@ -87,6 +177,186 @@ Journal::getNullSink()
//------------------------------------------------------------------------------
std::string_view
severities::to_string(Severity severity)
{
using namespace std::string_view_literals;
switch (severity)
{
case kDisabled:
return "disabled"sv;
case kTrace:
return "trace"sv;
case kDebug:
return "debug"sv;
case kInfo:
return "info"sv;
case kWarning:
return "warning"sv;
case kError:
return "error"sv;
case kFatal:
return "fatal"sv;
default:
UNREACHABLE("Unexpected severity value!");
}
return ""sv;
}
void
Journal::JsonLogContext::start(
std::source_location location,
severities::Severity severity,
std::string_view moduleName,
std::string_view journalAttributes) noexcept
{
struct ThreadIdStringInitializer
{
std::string value;
ThreadIdStringInitializer()
{
std::stringstream threadIdStream;
threadIdStream << std::this_thread::get_id();
value = threadIdStream.str();
}
};
thread_local ThreadIdStringInitializer const threadId;
messageOffset_ = 0;
messageBuffer_.clear();
jsonWriter_ = detail::SimpleJsonWriter{&messageBuffer_};
if (!jsonLogsEnabled_)
{
messageBuffer_ = journalAttributes;
return;
}
writer().startObject();
if (!journalAttributes.empty())
{
writer().writeKey("Jnl");
writer().writeRaw(journalAttributes);
writer().endObject();
}
{
std::shared_lock lock(globalLogAttributesMutex_);
if (!globalLogAttributes_.empty())
{
writer().writeKey("Glb");
writer().writeRaw(globalLogAttributes_);
writer().endObject();
}
}
writer().writeKey("Mtd");
writer().startObject();
writer().writeKey("Mdl");
writer().writeString(moduleName);
writer().writeKey("Fl");
constexpr size_t FILE_NAME_KEEP_CHARS = 20;
std::string_view fileName = location.file_name();
std::string_view trimmedFileName = (fileName.size() > FILE_NAME_KEEP_CHARS)
? fileName.substr(fileName.size() - FILE_NAME_KEEP_CHARS)
: fileName;
writer().writeString(trimmedFileName);
writer().writeKey("Ln");
writer().writeUInt(location.line());
writer().writeKey("ThId");
writer().writeString(threadId.value);
auto severityStr = to_string(severity);
writer().writeKey("Lv");
writer().writeString(severityStr);
auto nowMs = std::chrono::duration_cast<std::chrono::milliseconds>(
std::chrono::system_clock::now().time_since_epoch())
.count();
writer().writeKey("Tm");
writer().writeString(fastTimestampToString(nowMs));
writer().endObject();
hasMessageParams_ = false;
}
void
Journal::JsonLogContext::reuseJson()
{
messageOffset_ = messageBuffer_.size();
}
void
Journal::JsonLogContext::finish()
{
if (messageOffset_ != 0)
{
messageBuffer_.erase(messageOffset_);
}
else
{
messageBuffer_.clear();
}
jsonWriter_ = detail::SimpleJsonWriter{&messageBuffer_};
}
void
Journal::initMessageContext(
std::source_location location,
severities::Severity severity) const
{
currentJsonLogContext_.start(location, severity, name_, attributes_);
}
std::string&
Journal::formatLog(std::string const& message)
{
if (!jsonLogsEnabled_)
{
currentJsonLogContext_.writer().buffer() += message;
return currentJsonLogContext_.messageBuffer();
}
auto& writer = currentJsonLogContext_.writer();
currentJsonLogContext_.endMessageParams();
writer.writeKey("Msg");
writer.writeString(message);
writer.endObject();
writer.finish();
return currentJsonLogContext_.messageBuffer();
}
void
Journal::enableStructuredJournal()
{
jsonLogsEnabled_ = true;
}
void
Journal::disableStructuredJournal()
{
jsonLogsEnabled_ = false;
resetGlobalAttributes();
}
bool
Journal::isStructuredJournalEnabled()
{
return jsonLogsEnabled_;
}
Journal::Sink::Sink(Severity thresh, bool console)
: thresh_(thresh), m_console(console)
{
@@ -143,13 +413,14 @@ Journal::ScopedStream::ScopedStream(
Journal::ScopedStream::~ScopedStream()
{
std::string const& s(m_ostream.str());
std::string s = m_ostream.str();
if (!s.empty())
{
if (s == "\n")
m_sink.write(m_level, "");
else
m_sink.write(m_level, s);
s = "";
m_sink.write(m_level, formatLog(s));
currentJsonLogContext_.finish();
}
}
@@ -159,12 +430,4 @@ Journal::ScopedStream::operator<<(std::ostream& manip(std::ostream&)) const
return m_ostream << manip;
}
//------------------------------------------------------------------------------
Journal::ScopedStream
Journal::Stream::operator<<(std::ostream& manip(std::ostream&)) const
{
return ScopedStream(*this, manip);
}
} // namespace beast

View File

@@ -178,7 +178,6 @@ struct Peer
using NodeKey = Validation::NodeKey;
//! Logging support that prefixes messages with the peer ID
beast::WrappedSink sink;
beast::Journal j;
//! Generic consensus
@@ -284,8 +283,7 @@ struct Peer
TrustGraph<Peer*>& tg,
CollectorRefs& c,
beast::Journal jIn)
: sink(jIn, "Peer " + to_string(i) + ": ")
, j(sink)
: j(jIn, log::attributes(log::attr("Peer", "Peer " + to_string(i))))
, consensus(s.clock(), *this, j)
, id{i}
, key{id, 0}

View File

@@ -0,0 +1,766 @@
//------------------------------------------------------------------------------
/*
This file is part of rippled: https://github.com/ripple/rippled
Copyright (c) 2012 Ripple Labs Inc.
Permission to use, copy, modify, and/or distribute this software for any
purpose with or without fee is hereby granted, provided that the above
copyright notice and this permission notice appear in all copies.
THE SOFTWARE IS PROVIDED "AS IS" AND THE AUTHOR DISCLAIMS ALL WARRANTIES
WITH REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF
MERCHANTABILITY AND FITNESS. IN NO EVENT SHALL THE AUTHOR BE LIABLE FOR
ANY SPECIAL , DIRECT, INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES
WHATSOEVER RESULTING FROM LOSS OF USE, DATA OR PROFITS, WHETHER IN AN
ACTION OF CONTRACT, NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT OF
OR IN CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE.
*/
//==============================================================================
#include <xrpl/basics/Log.h>
#include <boost/json.hpp>
#include <doctest/doctest.h>
#include <iostream>
#include <numbers>
using namespace ripple;
class MockLogs : public Logs
{
private:
class Sink : public beast::Journal::Sink
{
private:
MockLogs& logs_;
std::string partition_;
public:
Sink(
std::string const& partition,
beast::severities::Severity thresh,
MockLogs& logs)
: beast::Journal::Sink(thresh, false)
, logs_(logs)
, partition_(partition)
{
}
Sink(Sink const&) = delete;
Sink&
operator=(Sink const&) = delete;
void
write(beast::severities::Severity level, std::string const& text)
override
{
logs_.write(level, partition_, text, false);
}
void
writeAlways(beast::severities::Severity level, std::string const& text)
override
{
logs_.write(level, partition_, text, false);
}
};
std::string& logStream_;
public:
MockLogs(std::string& logStream, beast::severities::Severity level)
: Logs(level), logStream_(logStream)
{
}
std::unique_ptr<beast::Journal::Sink>
makeSink(
std::string const& partition,
beast::severities::Severity startingLevel) override
{
return std::make_unique<Sink>(partition, startingLevel, *this);
}
void
write(
beast::severities::Severity level,
std::string const& partition,
std::string const& text,
bool console)
{
std::string s;
std::string_view result = text;
if (!beast::Journal::isStructuredJournalEnabled())
{
format(s, text, level, partition);
result = s;
}
logStream_.append(result);
}
};
TEST_CASE("Text logs")
{
std::string logStream;
MockLogs logs{logStream, beast::severities::kAll};
logs.journal("Test").debug() << "Test";
CHECK(logStream.find("Test") != std::string::npos);
logStream.clear();
logs.journal("Test").debug() << "\n";
CHECK(logStream.find("\n") == std::string::npos);
}
TEST_CASE("Test format output")
{
std::string output;
Logs::format(output, "Msg", beast::severities::kDebug, "Test");
CHECK(output.find("Msg") != std::string::npos);
CHECK(output != "Msg");
}
TEST_CASE("Enable json logs")
{
std::string logStream;
MockLogs logs{logStream, beast::severities::kAll};
logs.journal("Test ").debug() << "Test123";
CHECK(logStream.find("Test123") != std::string::npos);
logStream.clear();
beast::Journal::enableStructuredJournal();
logs.journal("Test").debug() << "\n";
boost::system::error_code ec;
auto doc = boost::json::parse(logStream, ec);
CHECK(ec == boost::system::errc::success);
CHECK(doc.is_object());
CHECK(doc.as_object().contains("Msg"));
CHECK(doc.as_object()["Msg"].is_string());
CHECK(doc.as_object()["Msg"].get_string() == "");
beast::Journal::disableStructuredJournal();
}
TEST_CASE("Global attributes")
{
std::string logStream;
MockLogs logs{logStream, beast::severities::kAll};
beast::Journal::enableStructuredJournal();
beast::Journal::addGlobalAttributes(
log::attributes(log::attr("Field1", "Value1")));
logs.journal("Test").debug() << "Test";
boost::system::error_code ec;
auto jsonLog = boost::json::parse(logStream, ec);
CHECK(ec == boost::system::errc::success);
CHECK(jsonLog.is_object());
CHECK(jsonLog.as_object().contains("Glb"));
CHECK(jsonLog.as_object()["Glb"].is_object());
CHECK(jsonLog.as_object()["Glb"].as_object().contains("Field1"));
CHECK(jsonLog.as_object()["Glb"].as_object()["Field1"].is_string());
CHECK(
jsonLog.as_object()["Glb"].as_object()["Field1"].get_string() ==
"Value1");
beast::Journal::disableStructuredJournal();
}
TEST_CASE("Global attributes inheritable")
{
std::string logStream;
MockLogs logs{logStream, beast::severities::kAll};
beast::Journal::enableStructuredJournal();
beast::Journal::addGlobalAttributes(
log::attributes(log::attr("Field1", "Value1")));
logs.journal(
"Test",
log::attributes(
log::attr("Field1", "Value3"), log::attr("Field2", "Value2")))
.debug()
<< "Test";
boost::system::error_code ec;
auto jsonLog = boost::json::parse(logStream, ec);
CHECK(ec == boost::system::errc::success);
CHECK(jsonLog.is_object());
CHECK(jsonLog.as_object()["Glb"].as_object().contains("Field1"));
CHECK(jsonLog.as_object()["Glb"].as_object()["Field1"].is_string());
CHECK(
jsonLog.as_object()["Glb"].as_object()["Field1"].get_string() ==
"Value1");
CHECK(
jsonLog.as_object()["Jnl"].as_object()["Field1"].get_string() ==
"Value3");
CHECK(
jsonLog.as_object()["Jnl"].as_object()["Field2"].get_string() ==
"Value2");
beast::Journal::disableStructuredJournal();
}
TEST_CASE("Test JsonWriter")
{
{
std::string buffer;
beast::detail::SimpleJsonWriter writer{&buffer};
writer.writeString("\n\r\t123\b\f123");
writer.finish();
CHECK(writer.buffer() == "\"\\n\\r\\t123\\b\\f123\"");
}
{
std::string buffer;
beast::detail::SimpleJsonWriter writer{&buffer};
writer.writeString("\t");
writer.finish();
CHECK(writer.buffer() == "\"\\t\"");
}
{
std::string buffer;
beast::detail::SimpleJsonWriter writer{&buffer};
writer.writeString(std::string_view{"\0", 1});
writer.finish();
CHECK(writer.buffer() == "\"\\u0000\"");
}
{
std::string buffer;
beast::detail::SimpleJsonWriter writer{&buffer};
writer.writeString("\"\\");
writer.finish();
CHECK(writer.buffer() == "\"\\\"\\\\\"");
}
{
std::string buffer;
beast::detail::SimpleJsonWriter writer{&buffer};
writer.startArray();
writer.writeBool(true);
writer.writeBool(false);
writer.writeNull();
writer.endArray();
writer.finish();
CHECK(writer.buffer() == "[true,false,null]");
}
}
namespace test_detail {
struct ToCharsStruct
{
};
std::to_chars_result
to_chars(char* first, char* last, ToCharsStruct)
{
*first = '0';
return std::to_chars_result{first + 1, std::errc{}};
}
struct StreamStruct
{
};
std::ostream&
operator<<(std::ostream& os, StreamStruct)
{
os << "0";
return os;
}
} // namespace test_detail
TEST_CASE("Test setJsonValue")
{
std::ostringstream stringBuf;
std::string buffer;
beast::detail::SimpleJsonWriter writer{&buffer};
writer.startObject();
log::detail::setJsonValue<bool>(writer, "testBool", true, &stringBuf);
log::detail::setJsonValue<std::int32_t>(
writer, "testInt32", -1, &stringBuf);
log::detail::setJsonValue<std::uint32_t>(
writer, "testUInt32", 1, &stringBuf);
log::detail::setJsonValue<std::int64_t>(
writer, "testInt64", -1, &stringBuf);
log::detail::setJsonValue<std::uint64_t>(
writer, "testUInt64", 1, &stringBuf);
log::detail::setJsonValue<double>(writer, "testDouble", 1.1, &stringBuf);
log::detail::setJsonValue<char const*>(
writer, "testCharStar", "Char*", &stringBuf);
log::detail::setJsonValue<std::string>(
writer, "testStdString", "StdString", &stringBuf);
log::detail::setJsonValue<std::string_view>(
writer, "testStdStringView", "StdStringView", &stringBuf);
log::detail::setJsonValue<test_detail::ToCharsStruct>(
writer, "testToChars", {}, &stringBuf);
log::detail::setJsonValue<test_detail::StreamStruct>(
writer, "testStream", {}, &stringBuf);
writer.endObject();
writer.finish();
CHECK(
writer.buffer() ==
R"AAA({"testBool":true,"testInt32":-1,"testUInt32":1,"testInt64":-1,"testUInt64":1,"testDouble":1.1,"testCharStar":"Char*","testStdString":"StdString","testStdStringView":"StdStringView","testToChars":"0","testStream":"0"})AAA");
}
TEST_CASE("Test json logging not enabled")
{
std::string logStream;
MockLogs logs{logStream, beast::severities::kAll};
beast::Journal::disableStructuredJournal();
beast::Journal::addGlobalAttributes(
log::attributes(log::attr("Field1", "Value1")));
logs.journal("Test123").debug()
<< "Test " << log::param(" Field1", "Value1")
<< log::field("Field2", "Value2");
CHECK(logStream.find("Test Value1") != std::string::npos);
}
/**
* @brief sink for writing all log messages to a stringstream
*/
class MockSink : public beast::Journal::Sink
{
std::stringstream& strm_;
public:
MockSink(beast::severities::Severity threshold, std::stringstream& strm)
: beast::Journal::Sink(threshold, false), strm_(strm)
{
}
void
write(beast::severities::Severity level, std::string const& text) override
{
strm_ << text;
}
void
writeAlways(beast::severities::Severity level, std::string const& text)
override
{
strm_ << text;
}
};
class JsonLogStreamFixture
{
public:
JsonLogStreamFixture()
: sink_(beast::severities::kAll, logStream_)
, j_(beast::Journal::getNullSink())
{
beast::Journal::resetGlobalAttributes();
beast::Journal::enableStructuredJournal();
j_ = beast::Journal{
sink_, "Test", log::attributes(log::attr("Field1", "Value1"))};
}
~JsonLogStreamFixture()
{
beast::Journal::disableStructuredJournal();
}
std::stringstream&
stream()
{
return logStream_;
}
beast::Journal&
journal()
{
return j_;
}
private:
MockSink sink_;
std::stringstream logStream_;
beast::Journal j_;
};
TEST_CASE_FIXTURE(JsonLogStreamFixture, "Test json log fields")
{
beast::Journal::addGlobalAttributes(
log::attributes(log::attr("Field2", "Value2")));
journal().debug() << std::boolalpha << true << std::noboolalpha << " Test "
<< std::boolalpha << false
<< log::field("Field3", "Value3");
boost::system::error_code ec;
auto logValue = boost::json::parse(stream().str(), ec);
CHECK(ec == boost::system::errc::success);
CHECK(logValue.is_object());
CHECK(logValue.as_object().contains("Glb"));
CHECK(logValue.as_object().contains("Jnl"));
CHECK(logValue.as_object().contains("Mtd"));
CHECK(logValue.as_object().contains("Msg"));
CHECK(logValue.as_object()["Glb"].is_object());
CHECK(logValue.as_object()["Jnl"].is_object());
CHECK(logValue.as_object()["Mtd"].is_object());
CHECK(logValue.as_object()["Msg"].is_string());
CHECK(logValue.as_object()["Mtd"].as_object().contains("Fl"));
CHECK(logValue.as_object()["Mtd"].as_object().contains("Ln"));
CHECK(logValue.as_object()["Mtd"].as_object().contains("ThId"));
CHECK(logValue.as_object()["Mtd"].as_object().contains("Lv"));
CHECK(logValue.as_object()["Mtd"].as_object().contains("Tm"));
CHECK(logValue.as_object()["Mtd"].as_object()["Fl"].is_string());
CHECK(logValue.as_object()["Mtd"].as_object()["Ln"].is_number());
CHECK(
logValue.as_object()["Msg"].get_string() ==
std::string{"true Test false"});
}
TEST_CASE_FIXTURE(JsonLogStreamFixture, "Test json log levels")
{
{
stream().str("");
journal().trace() << "Test";
boost::system::error_code ec;
auto logValue = boost::json::parse(stream().str(), ec);
CHECK(ec == boost::system::errc::success);
CHECK(
logValue.as_object()["Mtd"].as_object()["Lv"].get_string() ==
beast::severities::to_string(beast::severities::kTrace));
}
{
stream().str("");
journal().debug() << "Test";
boost::system::error_code ec;
auto logValue = boost::json::parse(stream().str(), ec);
CHECK(ec == boost::system::errc::success);
CHECK(
logValue.as_object()["Mtd"].as_object()["Lv"].get_string() ==
beast::severities::to_string(beast::severities::kDebug));
}
{
stream().str("");
journal().info() << "Test";
boost::system::error_code ec;
auto logValue = boost::json::parse(stream().str(), ec);
CHECK(ec == boost::system::errc::success);
CHECK(
logValue.as_object()["Mtd"].as_object()["Lv"].get_string() ==
beast::severities::to_string(beast::severities::kInfo));
}
{
stream().str("");
journal().warn() << "Test";
boost::system::error_code ec;
auto logValue = boost::json::parse(stream().str(), ec);
CHECK(ec == boost::system::errc::success);
CHECK(
logValue.as_object()["Mtd"].as_object()["Lv"].get_string() ==
beast::severities::to_string(beast::severities::kWarning));
}
{
stream().str("");
journal().error() << "Test";
boost::system::error_code ec;
auto logValue = boost::json::parse(stream().str(), ec);
CHECK(ec == boost::system::errc::success);
CHECK(
logValue.as_object()["Mtd"].as_object()["Lv"].get_string() ==
beast::severities::to_string(beast::severities::kError));
}
{
stream().str("");
journal().fatal() << "Test";
boost::system::error_code ec;
auto logValue = boost::json::parse(stream().str(), ec);
CHECK(ec == boost::system::errc::success);
CHECK(
logValue.as_object()["Mtd"].as_object()["Lv"].get_string() ==
beast::severities::to_string(beast::severities::kFatal));
}
}
TEST_CASE_FIXTURE(JsonLogStreamFixture, "Test json log stream")
{
journal().stream(beast::severities::kError) << "Test";
boost::system::error_code ec;
auto logValue = boost::json::parse(stream().str(), ec);
CHECK(ec == boost::system::errc::success);
CHECK(
logValue.as_object()["Mtd"].as_object()["Lv"].get_string() ==
beast::severities::to_string(beast::severities::kError));
}
TEST_CASE_FIXTURE(JsonLogStreamFixture, "Test json log params")
{
journal().debug() << "Test: " << log::param("Field1", 1) << ", "
<< log::param(
"Field2",
std::numeric_limits<std::uint64_t>::max())
<< ", " << log::param("Field3", std::numbers::pi);
boost::system::error_code ec;
auto logValue = boost::json::parse(stream().str(), ec);
CHECK(ec == boost::system::errc::success);
CHECK(logValue.as_object()["Dt"].is_object());
CHECK(logValue.as_object()["Dt"].as_object()["Field1"].is_number());
CHECK(logValue.as_object()["Dt"].as_object()["Field1"].get_int64() == 1);
CHECK(logValue.as_object()["Dt"].as_object()["Field2"].is_number());
CHECK(
logValue.as_object()["Dt"].as_object()["Field2"].get_uint64() ==
std::numeric_limits<std::uint64_t>::max());
auto field3Val =
logValue.as_object()["Dt"].as_object()["Field3"].get_double();
auto difference = std::abs(field3Val - std::numbers::pi);
CHECK(difference < 1e-4);
CHECK(logValue.as_object()["Msg"].is_string());
CHECK(
logValue.as_object()["Msg"].get_string() ==
std::string{"Test: 1, 18446744073709551615, 3.141592653589793"});
}
TEST_CASE_FIXTURE(JsonLogStreamFixture, "Test json log fields")
{
journal().debug() << "Test" << log::field("Field1", 1)
<< log::field(
"Field2",
std::numeric_limits<std::uint64_t>::max());
boost::system::error_code ec;
auto logValue = boost::json::parse(stream().str(), ec);
CHECK(ec == boost::system::errc::success);
CHECK(logValue.as_object()["Dt"].is_object());
CHECK(logValue.as_object()["Dt"].as_object()["Field1"].is_number());
CHECK(logValue.as_object()["Dt"].as_object()["Field1"].get_int64() == 1);
// UInt64 doesn't fit in Json::Value so it should be converted to a string
// NOTE: We should expect it to be an int64 after we make the json library
// support in64 and uint64
CHECK(logValue.as_object()["Dt"].as_object()["Field2"].is_number());
CHECK(
logValue.as_object()["Dt"].as_object()["Field2"].get_uint64() ==
std::numeric_limits<std::uint64_t>::max());
CHECK(logValue.as_object()["Msg"].is_string());
CHECK(logValue.as_object()["Msg"].get_string() == "Test");
}
TEST_CASE_FIXTURE(JsonLogStreamFixture, "Test journal attributes")
{
beast::Journal j{
journal(),
log::attributes(log::attr("Field1", "Value1"), log::attr("Field2", 2))};
j.debug() << "Test";
boost::system::error_code ec;
auto logValue = boost::json::parse(stream().str(), ec);
CHECK(ec == boost::system::errc::success);
CHECK(logValue.as_object()["Jnl"].as_object()["Field1"].is_string());
CHECK(
logValue.as_object()["Jnl"].as_object()["Field1"].get_string() ==
std::string{"Value1"});
CHECK(logValue.as_object()["Jnl"].as_object()["Field2"].is_number());
CHECK(logValue.as_object()["Jnl"].as_object()["Field2"].get_int64() == 2);
}
TEST_CASE_FIXTURE(JsonLogStreamFixture, "Test journal attributes inheritable")
{
beast::Journal j{
journal(),
log::attributes(log::attr("Field1", "Value1"), log::attr("Field2", 2))};
beast::Journal j2{j, log::attributes(log::attr("Field3", "Value3"))};
j2.debug() << "Test";
boost::system::error_code ec;
auto logValue = boost::json::parse(stream().str(), ec);
CHECK(ec == boost::system::errc::success);
CHECK(logValue.as_object()["Jnl"].as_object()["Field1"].is_string());
CHECK(
logValue.as_object()["Jnl"].as_object()["Field1"].get_string() ==
std::string{"Value1"});
CHECK(logValue.as_object()["Jnl"].as_object()["Field3"].is_string());
CHECK(
logValue.as_object()["Jnl"].as_object()["Field3"].get_string() ==
std::string{"Value3"});
CHECK(logValue.as_object()["Jnl"].as_object()["Field2"].is_number());
CHECK(logValue.as_object()["Jnl"].as_object()["Field2"].get_int64() == 2);
}
TEST_CASE_FIXTURE(JsonLogStreamFixture, "Test copying journal")
{
{
beast::Journal j{
journal(),
log::attributes(
log::attr("Field1", "Value1"), log::attr("Field2", 2))};
beast::Journal j2{j};
j2.debug() << "Test";
boost::system::error_code ec;
auto logValue = boost::json::parse(stream().str(), ec);
CHECK(ec == boost::system::errc::success);
CHECK(logValue.as_object()["Jnl"].as_object()["Field1"].is_string());
CHECK(
logValue.as_object()["Jnl"].as_object()["Field1"].get_string() ==
std::string{"Value1"});
CHECK(logValue.as_object()["Jnl"].as_object()["Field2"].is_number());
CHECK(
logValue.as_object()["Jnl"].as_object()["Field2"].get_int64() == 2);
}
{
stream().str("");
beast::Journal j{journal().sink()};
beast::Journal j2{
j,
log::attributes(
log::attr("Field1", "Value1"), log::attr("Field2", 2))};
j2.debug() << "Test";
boost::system::error_code ec;
auto logValue = boost::json::parse(stream().str(), ec);
CHECK(ec == boost::system::errc::success);
CHECK(logValue.as_object()["Jnl"].as_object()["Field1"].is_string());
CHECK(
logValue.as_object()["Jnl"].as_object()["Field1"].get_string() ==
std::string{"Value1"});
CHECK(logValue.as_object()["Jnl"].as_object()["Field2"].is_number());
CHECK(
logValue.as_object()["Jnl"].as_object()["Field2"].get_int64() == 2);
}
}
TEST_CASE_FIXTURE(
JsonLogStreamFixture,
"Test journal attributes inheritable after moving")
{
beast::Journal j{
journal(),
log::attributes(log::attr("Field1", "Value1"), log::attr("Field2", 2))};
beast::Journal j2{j, log::attributes(log::attr("Field3", "Value3"))};
j2.debug() << "Test";
boost::system::error_code ec;
auto logValue = boost::json::parse(stream().str(), ec);
CHECK(ec == boost::system::errc::success);
CHECK(logValue.as_object()["Jnl"].as_object()["Field1"].is_string());
CHECK(
logValue.as_object()["Jnl"].as_object()["Field1"].get_string() ==
std::string{"Value1"});
CHECK(logValue.as_object()["Jnl"].as_object()["Field3"].is_string());
CHECK(
logValue.as_object()["Jnl"].as_object()["Field3"].get_string() ==
std::string{"Value3"});
// Field2 should be overwritten to 0
CHECK(logValue.as_object()["Jnl"].as_object()["Field2"].is_number());
CHECK(logValue.as_object()["Jnl"].as_object()["Field2"].get_int64() == 2);
}
TEST_CASE_FIXTURE(
JsonLogStreamFixture,
"Test journal attributes inheritable after copy assignment")
{
beast::Journal j{
std::move(journal()),
log::attributes(log::attr("Field1", "Value1"), log::attr("Field2", 2))};
beast::Journal j2{beast::Journal::getNullSink()};
j2 = j;
j2.debug() << "Test";
boost::system::error_code ec;
auto logValue = boost::json::parse(stream().str(), ec);
CHECK(ec == boost::system::errc::success);
CHECK(logValue.as_object()["Jnl"].as_object()["Field1"].is_string());
CHECK(
logValue.as_object()["Jnl"].as_object()["Field1"].get_string() ==
std::string{"Value1"});
CHECK(logValue.as_object()["Jnl"].as_object()["Field2"].is_number());
CHECK(logValue.as_object()["Jnl"].as_object()["Field2"].get_int64() == 2);
}
TEST_CASE_FIXTURE(
JsonLogStreamFixture,
"Test journal attributes inheritable after move assignment")
{
beast::Journal j{
journal(),
log::attributes(log::attr("Field1", "Value1"), log::attr("Field2", 2))};
beast::Journal j2{beast::Journal::getNullSink()};
j2 = std::move(j);
j2.debug() << "Test";
boost::system::error_code ec;
auto logValue = boost::json::parse(stream().str(), ec);
CHECK(ec == boost::system::errc::success);
CHECK(logValue.as_object()["Jnl"].as_object()["Field1"].is_string());
CHECK(
logValue.as_object()["Jnl"].as_object()["Field1"].get_string() ==
std::string{"Value1"});
CHECK(logValue.as_object()["Jnl"].as_object()["Field2"].is_number());
CHECK(logValue.as_object()["Jnl"].as_object()["Field2"].get_int64() == 2);
}

View File

@@ -1129,7 +1129,25 @@ RclConsensusLogger::~RclConsensusLogger()
outSs << header_ << "duration " << (duration.count() / 1000) << '.'
<< std::setw(3) << std::setfill('0') << (duration.count() % 1000)
<< "s. " << ss_->str();
j_.sink().writeAlways(beast::severities::kInfo, outSs.str());
thread_local std::string buffer;
if (beast::Journal::isStructuredJournalEnabled())
{
buffer.resize(5 * 1024);
beast::detail::SimpleJsonWriter writer{&buffer};
writer.startObject();
writer.writeKey("Msg");
writer.writeString(outSs.str());
writer.writeKey("Tm");
writer.writeString(to_string(std::chrono::system_clock::now()));
writer.endObject();
writer.finish();
}
else
{
buffer = outSs.str();
}
j_.sink().writeAlways(beast::severities::kInfo, buffer);
}
} // namespace ripple

View File

@@ -832,9 +832,6 @@ public:
bool
serverOkay(std::string& reason) override;
beast::Journal
journal(std::string const& name) override;
//--------------------------------------------------------------------------
bool
@@ -1212,8 +1209,11 @@ ApplicationImp::setup(boost::program_options::variables_map const& cmdline)
}
JLOG(m_journal.info()) << "Process starting: "
<< BuildInfo::getFullVersionString()
<< ", Instance Cookie: " << instanceCookie_;
<< log::param(
"RippledVersion",
BuildInfo::getFullVersionString())
<< ", Instance Cookie: "
<< log::param("InstanceCookie", instanceCookie_);
if (numberOfThreads(*config_) < 2)
{
@@ -2160,12 +2160,6 @@ ApplicationImp::serverOkay(std::string& reason)
return true;
}
beast::Journal
ApplicationImp::journal(std::string const& name)
{
return logs_->journal(name);
}
void
ApplicationImp::setMaxDisallowedLedger()
{

View File

@@ -257,8 +257,18 @@ public:
virtual bool
serverOkay(std::string& reason) = 0;
virtual beast::Journal
journal(std::string const& name) = 0;
template <typename TAttributesFactory>
beast::Journal
journal(std::string const& name, TAttributesFactory&& factory)
{
return logs().journal(name, std::forward<TAttributesFactory>(factory));
}
beast::Journal
journal(std::string const& name)
{
return logs().journal(name);
}
/* Returns the number of file descriptors the application needs */
virtual int

View File

@@ -788,6 +788,11 @@ run(int argc, char** argv)
else if (vm.count("verbose"))
thresh = kTrace;
if (config->LOG_STYLE == LogStyle::Json)
{
beast::Journal::enableStructuredJournal();
}
auto logs = std::make_unique<Logs>(thresh);
// No arguments. Run server.

View File

@@ -111,19 +111,22 @@ flow(
ammContext.setMultiPath(strands.size() > 1);
if (j.trace())
if (auto stream = j.trace())
{
j.trace() << "\nsrc: " << src << "\ndst: " << dst
<< "\nsrcIssue: " << srcIssue << "\ndstIssue: " << dstIssue;
j.trace() << "\nNumStrands: " << strands.size();
std::stringstream ss;
ss << "\nsrc: " << src << "\ndst: " << dst << "\nsrcIssue: " << srcIssue
<< "\ndstIssue: " << dstIssue;
ss << "\nNumStrands: " << strands.size();
for (auto const& curStrand : strands)
{
j.trace() << "NumSteps: " << curStrand.size();
ss << "NumSteps: " << curStrand.size();
for (auto const& step : curStrand)
{
j.trace() << '\n' << *step << '\n';
ss << '\n' << *step << '\n';
}
}
std::move(stream) << ss.str();
}
bool const srcIsXRP = isXRP(srcIssue.currency);

View File

@@ -565,8 +565,7 @@ getHashesByIndex(
if (!lhO || !phO)
{
auto stream = j.trace();
JLOG(stream) << "Don't have ledger " << ledgerIndex;
JLOG(j.trace()) << "Don't have ledger " << ledgerIndex;
return {};
}

View File

@@ -77,6 +77,16 @@ struct FeeSetup
* values.) */
};
/**
* We support producing plain text logs and structured json logs.
*/
namespace LogStyle {
enum LogStyle { LogFmt, Json };
LogStyle
fromString(std::string const&);
}; // namespace LogStyle
// This entire derived class is deprecated.
// For new config information use the style implied
// in the base class. For existing config information
@@ -299,6 +309,9 @@ public:
std::optional<std::size_t> VALIDATOR_LIST_THRESHOLD;
// Set it to LogStyle::Json to get structured json logs.
LogStyle::LogStyle LOG_STYLE = LogStyle::LogFmt;
public:
Config();

View File

@@ -48,6 +48,7 @@ struct ConfigSection
#define SECTION_CLUSTER_NODES "cluster_nodes"
#define SECTION_COMPRESSION "compression"
#define SECTION_DEBUG_LOGFILE "debug_logfile"
#define SECTION_LOG_STYLE "log_style"
#define SECTION_ELB_SUPPORT "elb_support"
#define SECTION_FEE_DEFAULT "fee_default"
#define SECTION_FETCH_DEPTH "fetch_depth"

View File

@@ -690,6 +690,11 @@ Config::loadFromString(std::string const& fileContents)
if (getSingleSection(secConfig, SECTION_DEBUG_LOGFILE, strTemp, j_))
DEBUG_LOGFILE = strTemp;
if (getSingleSection(secConfig, SECTION_LOG_STYLE, strTemp, j_))
LOG_STYLE = LogStyle::fromString(strTemp);
LOG_STYLE = LogStyle::Json;
if (getSingleSection(secConfig, SECTION_SWEEP_INTERVAL, strTemp, j_))
{
SWEEP_INTERVAL = beast::lexicalCastThrow<std::size_t>(strTemp);
@@ -1078,6 +1083,14 @@ Config::loadFromString(std::string const& fileContents)
}
}
LogStyle::LogStyle
LogStyle::fromString(std::string const& str)
{
if (str == "json")
return Json;
return LogFmt;
}
boost::filesystem::path
Config::getDebugLogFile() const
{

View File

@@ -406,7 +406,7 @@ Slot<clock_type>::update(
v.state = PeerState::Selected;
else if (v.state != PeerState::Squelched)
{
if (journal_.trace())
if (journal_.active(beast::severities::kTrace))
str << k << " ";
v.state = PeerState::Squelched;
std::chrono::seconds duration =

View File

@@ -39,8 +39,7 @@ ConnectAttempt::ConnectAttempt(
: Child(overlay)
, app_(app)
, id_(id)
, sink_(journal, OverlayImpl::makePrefix(id))
, journal_(sink_)
, journal_(journal, log::attributes(log::attr("NodeID", id)))
, remote_endpoint_(remote_endpoint)
, usage_(usage)
, strand_(io_service)

View File

@@ -46,7 +46,6 @@ private:
Application& app_;
std::uint32_t const id_;
beast::WrappedSink sink_;
beast::Journal const journal_;
endpoint_type remote_endpoint_;
Resource::Consumer usage_;

View File

@@ -165,8 +165,8 @@ OverlayImpl::onHandoff(
endpoint_type remote_endpoint)
{
auto const id = next_id_++;
beast::WrappedSink sink(app_.logs()["Peer"], makePrefix(id));
beast::Journal journal(sink);
auto journal =
app_.journal("Peer", log::attributes(log::attr("NodeID", id)));
Handoff handoff;
if (processRequest(request, handoff))
@@ -332,14 +332,6 @@ OverlayImpl::isPeerUpgrade(http_request_type const& request)
return !versions.empty();
}
std::string
OverlayImpl::makePrefix(std::uint32_t id)
{
std::stringstream ss;
ss << "[" << std::setfill('0') << std::setw(3) << id << "] ";
return ss.str();
}
std::shared_ptr<Writer>
OverlayImpl::makeRedirectResponse(
std::shared_ptr<PeerFinder::Slot> const& slot,

View File

@@ -341,9 +341,6 @@ public:
return true;
}
static std::string
makePrefix(std::uint32_t id);
void
reportInboundTraffic(TrafficCount::category cat, int bytes);

View File

@@ -77,10 +77,22 @@ PeerImp::PeerImp(
: Child(overlay)
, app_(app)
, id_(id)
, sink_(app_.journal("Peer"), makePrefix(id))
, p_sink_(app_.journal("Protocol"), makePrefix(id))
, journal_(sink_)
, p_journal_(p_sink_)
, journal_(
app_.journal("Peer"),
log::attributes(
log::attr("NodeID", id),
log::attr("RemoteAddress", to_string(slot->remote_endpoint())),
log::attr(
"PublicKey",
toBase58(TokenType::NodePublic, publicKey))))
, p_journal_(
app_.journal("Protocol"),
log::attributes(
log::attr("NodeID", id),
log::attr("RemoteAddress", to_string(slot->remote_endpoint())),
log::attr(
"PublicKey",
toBase58(TokenType::NodePublic, publicKey))))
, stream_ptr_(std::move(stream_ptr))
, socket_(stream_ptr_->next_layer().socket())
, stream_(*stream_ptr_)
@@ -903,9 +915,10 @@ PeerImp::onReadMessage(error_code ec, std::size_t bytes_transferred)
if (auto stream = journal_.trace())
{
if (bytes_transferred > 0)
stream << "onReadMessage: " << bytes_transferred << " bytes";
std::move(stream)
<< "onReadMessage: " << bytes_transferred << " bytes";
else
stream << "onReadMessage";
std::move(stream) << "onReadMessage";
}
metrics_.recv.add_message(bytes_transferred);
@@ -962,9 +975,10 @@ PeerImp::onWriteMessage(error_code ec, std::size_t bytes_transferred)
if (auto stream = journal_.trace())
{
if (bytes_transferred > 0)
stream << "onWriteMessage: " << bytes_transferred << " bytes";
std::move(stream)
<< "onWriteMessage: " << bytes_transferred << " bytes";
else
stream << "onWriteMessage";
std::move(stream) << "onWriteMessage";
}
metrics_.sent.add_message(bytes_transferred);

View File

@@ -71,8 +71,6 @@ private:
Application& app_;
id_t const id_;
beast::WrappedSink sink_;
beast::WrappedSink p_sink_;
beast::Journal const journal_;
beast::Journal const p_journal_;
std::unique_ptr<stream_type> stream_ptr_;
@@ -662,10 +660,22 @@ PeerImp::PeerImp(
: Child(overlay)
, app_(app)
, id_(id)
, sink_(app_.journal("Peer"), makePrefix(id))
, p_sink_(app_.journal("Protocol"), makePrefix(id))
, journal_(sink_)
, p_journal_(p_sink_)
, journal_(
app_.journal("Peer"),
log::attributes(
log::attr("NodeID", id),
log::attr("RemoteAddress", to_string(slot->remote_endpoint())),
log::attr(
"PublicKey",
toBase58(TokenType::NodePublic, publicKey))))
, p_journal_(
app_.journal("Protocol"),
log::attributes(
log::attr("NodeID", id),
log::attr("RemoteAddress", to_string(slot->remote_endpoint())),
log::attr(
"PublicKey",
toBase58(TokenType::NodePublic, publicKey))))
, stream_ptr_(std::move(stream_ptr))
, socket_(stream_ptr_->next_layer().socket())
, stream_(*stream_ptr_)

View File

@@ -950,15 +950,15 @@ SHAMap::fetchRoot(SHAMapHash const& hash, SHAMapSyncFilter* filter)
{
if (type_ == SHAMapType::TRANSACTION)
{
stream << "Fetch root TXN node " << hash;
std::move(stream) << "Fetch root TXN node " << hash;
}
else if (type_ == SHAMapType::STATE)
{
stream << "Fetch root STATE node " << hash;
std::move(stream) << "Fetch root STATE node " << hash;
}
else
{
stream << "Fetch root SHAMap node " << hash;
std::move(stream) << "Fetch root SHAMap node " << hash;
}
}