feat(logs): add -DBEAST_ENHANCED_LOGGING with file:line numbers for JLOG macro (#552)

This commit is contained in:
Niq Dudfield
2025-10-14 07:44:03 +07:00
committed by GitHub
parent ad0531ad6c
commit 1f12b9ec5a
12 changed files with 448 additions and 42 deletions

View File

@@ -84,6 +84,8 @@ runs:
- name: Install dependencies
shell: bash
env:
CONAN_REQUEST_TIMEOUT: 180 # Increase timeout to 3 minutes for slow mirrors
run: |
# Create build directory
mkdir -p ${{ inputs.build_dir }}

View File

@@ -50,6 +50,12 @@ target_sources (xrpl_core PRIVATE
src/ripple/beast/utility/src/beast_Journal.cpp
src/ripple/beast/utility/src/beast_PropertyStream.cpp)
# Conditionally add enhanced logging source when BEAST_ENHANCED_LOGGING is enabled
if(DEFINED BEAST_ENHANCED_LOGGING AND BEAST_ENHANCED_LOGGING)
target_sources(xrpl_core PRIVATE
src/ripple/beast/utility/src/beast_EnhancedLogging.cpp)
endif()
#[===============================[
core sources
#]===============================]
@@ -155,6 +161,13 @@ target_link_libraries (xrpl_core
ed25519::ed25519
date::date
Ripple::opts)
# Link date-tz library when enhanced logging is enabled
if(DEFINED BEAST_ENHANCED_LOGGING AND BEAST_ENHANCED_LOGGING)
if(TARGET date::date-tz)
target_link_libraries(xrpl_core PUBLIC date::date-tz)
endif()
endif()
#[=================================[
main/core headers installation
#]=================================]

View File

@@ -33,6 +33,25 @@ if(Git_FOUND)
endif()
endif() #git
# make SOURCE_ROOT_PATH define available for logging
set(SOURCE_ROOT_PATH "${CMAKE_CURRENT_SOURCE_DIR}/src/")
add_definitions(-DSOURCE_ROOT_PATH="${SOURCE_ROOT_PATH}")
# BEAST_ENHANCED_LOGGING option - adds file:line numbers and formatting to logs
# Default to ON for Debug builds, OFF for Release
if(CMAKE_BUILD_TYPE STREQUAL "Debug")
option(BEAST_ENHANCED_LOGGING "Include file and line numbers in log messages" ON)
else()
option(BEAST_ENHANCED_LOGGING "Include file and line numbers in log messages" OFF)
endif()
if(BEAST_ENHANCED_LOGGING)
add_definitions(-DBEAST_ENHANCED_LOGGING=1)
message(STATUS "Log line numbers enabled")
else()
message(STATUS "Log line numbers disabled")
endif()
if(thread_safety_analysis)
add_compile_options(-Wthread-safety -D_LIBCPP_ENABLE_THREAD_SAFETY_ANNOTATIONS -DRIPPLE_ENABLE_THREAD_SAFETY_ANNOTATIONS)
add_compile_options("-stdlib=libc++")

View File

@@ -26,7 +26,7 @@ class Xrpl(ConanFile):
}
requires = [
'date/3.0.1',
'date/3.0.3',
'libarchive/3.6.0',
'lz4/1.9.4',
'grpc/1.50.1',
@@ -52,7 +52,7 @@ class Xrpl(ConanFile):
'tool_requires_b2': False,
'cassandra-cpp-driver/*:shared': False,
'date/*:header_only': True,
'date/*:header_only': False,
'grpc/*:shared': False,
'grpc/*:secure': True,
'libarchive/*:shared': False,

View File

@@ -156,34 +156,22 @@ deserializeManifest(Slice s, beast::Journal journal)
}
}
template <class Stream>
Stream&
logMftAct(
Stream& s,
std::string const& action,
PublicKey const& pk,
std::uint32_t seq)
{
s << "Manifest: " << action
<< ";Pk: " << toBase58(TokenType::NodePublic, pk) << ";Seq: " << seq
<< ";";
return s;
}
// Helper macros to format manifest log messages while preserving line numbers
#define LOG_MANIFEST_ACTION(stream, action, pk, seq) \
do \
{ \
JLOG(stream) << "Manifest: " << action \
<< ";Pk: " << toBase58(TokenType::NodePublic, pk) \
<< ";Seq: " << seq << ";"; \
} while (0)
template <class Stream>
Stream&
logMftAct(
Stream& s,
std::string const& action,
PublicKey const& pk,
std::uint32_t seq,
std::uint32_t oldSeq)
{
s << "Manifest: " << action
<< ";Pk: " << toBase58(TokenType::NodePublic, pk) << ";Seq: " << seq
<< ";OldSeq: " << oldSeq << ";";
return s;
}
#define LOG_MANIFEST_ACTION_WITH_OLD(stream, action, pk, seq, oldSeq) \
do \
{ \
JLOG(stream) << "Manifest: " << action \
<< ";Pk: " << toBase58(TokenType::NodePublic, pk) \
<< ";Seq: " << seq << ";OldSeq: " << oldSeq << ";"; \
} while (0)
bool
Manifest::verify() const
@@ -381,7 +369,7 @@ ManifestCache::applyManifest(Manifest m)
// several cases including when we receive manifests from a peer who
// doesn't have the latest data.
if (auto stream = j_.debug())
logMftAct(
LOG_MANIFEST_ACTION_WITH_OLD(
stream,
"Stale",
m.masterKey,
@@ -393,7 +381,7 @@ ManifestCache::applyManifest(Manifest m)
if (checkSignature && !m.verify())
{
if (auto stream = j_.warn())
logMftAct(stream, "Invalid", m.masterKey, m.sequence);
LOG_MANIFEST_ACTION(stream, "Invalid", m.masterKey, m.sequence);
return ManifestDisposition::invalid;
}
@@ -407,7 +395,7 @@ ManifestCache::applyManifest(Manifest m)
bool const revoked = m.revoked();
if (auto stream = j_.warn(); stream && revoked)
logMftAct(stream, "Revoked", m.masterKey, m.sequence);
LOG_MANIFEST_ACTION(stream, "Revoked", m.masterKey, m.sequence);
// Sanity check: the master key of this manifest should not be used as
// the ephemeral key of another manifest:
@@ -476,7 +464,7 @@ ManifestCache::applyManifest(Manifest m)
if (iter == map_.end())
{
if (auto stream = j_.info())
logMftAct(stream, "AcceptedNew", m.masterKey, m.sequence);
LOG_MANIFEST_ACTION(stream, "AcceptedNew", m.masterKey, m.sequence);
if (!revoked)
signingToMasterKeys_[m.signingKey] = m.masterKey;
@@ -489,7 +477,7 @@ ManifestCache::applyManifest(Manifest m)
// An ephemeral key was revoked and superseded by a new key. This is
// expected, but should happen infrequently.
if (auto stream = j_.info())
logMftAct(
LOG_MANIFEST_ACTION_WITH_OLD(
stream,
"AcceptedUpdate",
m.masterKey,
@@ -584,4 +572,9 @@ ManifestCache::save(
saveManifests(*db, dbTable, isTrusted, map_, j_);
}
// Clean up macros to avoid namespace pollution
#undef LOG_MANIFEST_ACTION
#undef LOG_MANIFEST_ACTION_WITH_OLD
} // namespace ripple

View File

@@ -249,13 +249,22 @@ private:
// Wraps a Journal::Stream to skip evaluation of
// expensive argument lists if the stream is not active.
#ifndef JLOG
#ifdef BEAST_ENHANCED_LOGGING
#define JLOG(x) \
if (!x) \
if (!(x)) \
{ \
} \
else \
(x).withLocation(__FILE__, __LINE__)
#else
#define JLOG(x) \
if (!(x)) \
{ \
} \
else \
x
#endif
#endif
//------------------------------------------------------------------------------
// Debug logging:

View File

@@ -17,11 +17,19 @@
*/
//==============================================================================
#include <date/date.h>
#include <ripple/basics/Log.h>
#include <ripple/basics/chrono.h>
#include <ripple/basics/contract.h>
#ifdef BEAST_ENHANCED_LOGGING
#include <ripple/beast/utility/EnhancedLogging.h>
#include <date/tz.h>
#endif
#include <boost/algorithm/string.hpp>
#include <cassert>
#include <cstring>
#include <ctime>
#include <fstream>
#include <functional>
#include <iostream>
@@ -316,11 +324,46 @@ Logs::format(
{
output.reserve(message.size() + partition.size() + 100);
output = to_string(std::chrono::system_clock::now());
#ifdef BEAST_ENHANCED_LOGGING
// Environment variables are used instead of config file because:
// 1. Logging starts before config parsing (needed to debug config issues)
// 2. This is a developer feature - devs can easily set env vars
// 3. Allows per-run overrides without editing config files
static const char* fmt = []() {
const char* env = std::getenv("LOG_DATE_FORMAT");
return env ? env : "%Y-%b-%d %T %Z"; // Default format
}();
// Check if we should use local time
static const bool useLocalTime = []() {
const char* env = std::getenv("LOG_DATE_LOCAL");
return env && std::strcmp(env, "1") == 0;
}();
if (useLocalTime)
{
auto now = std::chrono::system_clock::now();
auto local = date::make_zoned(date::current_zone(), now);
output = date::format(fmt, local);
}
else
{
output = date::format(fmt, std::chrono::system_clock::now());
}
#else
output = to_string(std::chrono::system_clock::now());
#endif
if (!output.empty()) // Allow setting date format to an empty string
output += " ";
if (!partition.empty())
{
#ifdef BEAST_ENHANCED_LOGGING
output += beast::detail::get_log_highlight_color();
#endif
output += partition + ":";
}
using namespace beast::severities;
switch (severity)
@@ -348,6 +391,10 @@ Logs::format(
break;
}
#ifdef BEAST_ENHANCED_LOGGING
output += "\033[0m";
#endif
output += message;
// Limit the maximum length of the output

View File

@@ -0,0 +1,85 @@
//------------------------------------------------------------------------------
/*
This file is part of Beast: https://github.com/vinniefalco/Beast
Copyright 2013, Vinnie Falco <vinnie.falco@gmail.com>
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.
*/
//==============================================================================
#ifndef BEAST_UTILITY_ENHANCEDLOGGING_H_INCLUDED
#define BEAST_UTILITY_ENHANCEDLOGGING_H_INCLUDED
#include <cstddef> // for size_t
#include <iosfwd> // for std::ostream
namespace beast {
namespace detail {
// Check if we should use colors - cached at startup
bool
should_log_use_colors();
// Get the log highlight color - can be overridden via
// LOG_HIGHLIGHT_COLOR
const char*
get_log_highlight_color();
// Strip source root path from __FILE__ at compile time
// IMPORTANT: This MUST stay in the header as constexpr for compile-time
// evaluation!
constexpr const char*
strip_source_root(const char* file)
{
#ifdef SOURCE_ROOT_PATH
constexpr const char* sourceRoot = SOURCE_ROOT_PATH;
constexpr auto strlen_constexpr = [](const char* s) constexpr
{
const char* p = s;
while (*p)
++p;
return p - s;
};
constexpr auto strncmp_constexpr =
[](const char* a, const char* b, size_t n) constexpr
{
for (size_t i = 0; i < n; ++i)
{
if (a[i] != b[i])
return a[i] - b[i];
if (a[i] == '\0')
break;
}
return 0;
};
constexpr size_t sourceRootLen = strlen_constexpr(sourceRoot);
return (strncmp_constexpr(file, sourceRoot, sourceRootLen) == 0)
? file + sourceRootLen
: file;
#else
return file;
#endif
}
// Check if location info should be shown - cached at startup
bool
should_show_location();
// Helper to write location string (no leading/trailing space)
void
log_write_location_string(std::ostream& os, const char* file, int line);
} // namespace detail
} // namespace beast
#endif

View File

@@ -146,6 +146,10 @@ private:
ScopedStream(Sink& sink, Severity level);
#ifdef BEAST_ENHANCED_LOGGING
ScopedStream(Sink& sink, Severity level, const char* file, int line);
#endif
template <typename T>
ScopedStream(Stream const& stream, T const& t);
@@ -173,6 +177,10 @@ private:
Sink& m_sink;
Severity const m_level;
std::ostringstream mutable m_ostream;
#ifdef BEAST_ENHANCED_LOGGING
const char* file_ = nullptr;
int line_ = 0;
#endif
};
#ifndef __INTELLISENSE__
@@ -191,6 +199,33 @@ private:
//--------------------------------------------------------------------------
public:
/** Provide a light-weight way to check active() before string formatting */
#ifdef BEAST_ENHANCED_LOGGING
/** Stream with location information that prepends file:line to the first
* message */
class StreamWithLocation
{
public:
StreamWithLocation(Stream const& stream, const char* file, int line)
: file_(file), line_(line), stream_(stream)
{
}
/** Override to inject file:line before the first output */
template <typename T>
ScopedStream
operator<<(T const& t) const;
ScopedStream
operator<<(std::ostream& manip(std::ostream&)) const;
private:
const char* file_;
int line_;
const Stream& stream_;
};
#endif
class Stream
{
public:
@@ -255,6 +290,15 @@ public:
operator<<(T const& t) const;
/** @} */
#ifdef BEAST_ENHANCED_LOGGING
/** Create a StreamWithLocation that prepends file:line info */
StreamWithLocation
withLocation(const char* file, int line) const
{
return StreamWithLocation(*this, file, line);
}
#endif
private:
Sink& m_sink;
Severity m_level;
@@ -354,6 +398,8 @@ static_assert(std::is_nothrow_destructible<Journal>::value == true, "");
//------------------------------------------------------------------------------
//------------------------------------------------------------------------------
template <typename T>
Journal::ScopedStream::ScopedStream(Journal::Stream const& stream, T const& t)
: ScopedStream(stream.sink(), stream.level())
@@ -378,6 +424,21 @@ Journal::Stream::operator<<(T const& t) const
return ScopedStream(*this, t);
}
#ifdef BEAST_ENHANCED_LOGGING
//------------------------------------------------------------------------------
template <typename T>
Journal::ScopedStream
Journal::StreamWithLocation::operator<<(T const& t) const
{
// Create a ScopedStream with location info
ScopedStream scoped(stream_.sink(), stream_.level(), file_, line_);
scoped.ostream() << t;
return scoped;
}
#endif
namespace detail {
template <class CharT, class Traits = std::char_traits<CharT>>

View File

@@ -0,0 +1,114 @@
//------------------------------------------------------------------------------
/*
This file is part of Beast: https://github.com/vinniefalco/Beast
Copyright 2013, Vinnie Falco <vinnie.falco@gmail.com>
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 <ripple/beast/utility/EnhancedLogging.h>
#include <cstdlib>
#include <cstring>
#include <ostream>
#include <unistd.h>
namespace beast {
namespace detail {
// Check if we should use colors - cached at startup
bool
should_log_use_colors()
{
static const bool use_colors = []() {
// Honor NO_COLOR environment variable (standard)
if (std::getenv("NO_COLOR"))
return false;
// Honor FORCE_COLOR to override terminal detection
if (std::getenv("FORCE_COLOR"))
return true;
// Check if stderr is a terminal
return isatty(STDERR_FILENO) != 0;
}();
return use_colors;
}
// Get the log highlight color - can be overridden via
// LOG_HIGHLIGHT_COLOR
const char*
get_log_highlight_color()
{
static const char* escape = []() {
const char* env = std::getenv("LOG_HIGHLIGHT_COLOR");
if (!env)
return "\033[36m"; // Default: cyan
// Simple map of color names to escape sequences
if (std::strcmp(env, "red") == 0)
return "\033[31m";
if (std::strcmp(env, "green") == 0)
return "\033[32m";
if (std::strcmp(env, "yellow") == 0)
return "\033[33m";
if (std::strcmp(env, "blue") == 0)
return "\033[34m";
if (std::strcmp(env, "magenta") == 0)
return "\033[35m";
if (std::strcmp(env, "cyan") == 0)
return "\033[36m";
if (std::strcmp(env, "white") == 0)
return "\033[37m";
if (std::strcmp(env, "gray") == 0 || std::strcmp(env, "grey") == 0)
return "\033[90m"; // Bright black (gray)
if (std::strcmp(env, "orange") == 0)
return "\033[93m"; // Bright yellow (appears orange-ish)
if (std::strcmp(env, "none") == 0)
return "";
// Default to cyan if unknown color name
return "\033[36m";
}();
return escape;
}
// Check if location info should be shown - cached at startup
bool
should_show_location()
{
static const bool show = []() {
const char* env = std::getenv("LOG_DISABLE");
// Show location by default, hide if LOG_DISABLE=1
return !env || std::strcmp(env, "1") != 0;
}();
return show;
}
// Helper to write location string (no leading/trailing space)
void
log_write_location_string(std::ostream& os, const char* file, int line)
{
if (detail::should_log_use_colors())
{
os << detail::get_log_highlight_color() << "["
<< detail::strip_source_root(file) << ":" << line << "]\033[0m";
}
else
{
os << "[" << detail::strip_source_root(file) << ":" << line << "]";
}
}
} // namespace detail
} // namespace beast

View File

@@ -19,6 +19,11 @@
#include <ripple/beast/utility/Journal.h>
#include <cassert>
#ifdef BEAST_ENHANCED_LOGGING
#include <ripple/beast/utility/EnhancedLogging.h>
#include <cstdlib>
#include <cstring>
#endif
namespace beast {
@@ -131,9 +136,36 @@ Journal::ScopedStream::ScopedStream(
m_ostream << manip;
}
#ifdef BEAST_ENHANCED_LOGGING
Journal::ScopedStream::ScopedStream(
Sink& sink,
Severity level,
const char* file,
int line)
: m_sink(sink), m_level(level), file_(file), line_(line)
{
// Modifiers applied from all ctors
m_ostream << std::boolalpha << std::showbase;
}
#endif
Journal::ScopedStream::~ScopedStream()
{
std::string const& s(m_ostream.str());
std::string s(m_ostream.str());
#ifdef BEAST_ENHANCED_LOGGING
// Add suffix if location is enabled
if (file_ && detail::should_show_location() && !s.empty() && s != "\n")
{
std::ostringstream combined;
combined << s;
if (!s.empty() && s.back() != ' ')
combined << " ";
detail::log_write_location_string(combined, file_, line_);
s = combined.str();
}
#endif
if (!s.empty())
{
if (s == "\n")
@@ -157,4 +189,18 @@ Journal::Stream::operator<<(std::ostream& manip(std::ostream&)) const
return ScopedStream(*this, manip);
}
#ifdef BEAST_ENHANCED_LOGGING
// Implementation moved to use new constructor
Journal::ScopedStream
Journal::StreamWithLocation::operator<<(
std::ostream& manip(std::ostream&)) const
{
// Create a ScopedStream with location info
ScopedStream scoped(stream_.sink(), stream_.level(), file_, line_);
scoped.ostream() << manip;
return scoped;
}
#endif
} // namespace beast

View File

@@ -23,6 +23,7 @@
#include <ripple/beast/utility/Journal.h>
#include <ripple/protocol/STLedgerEntry.h>
#include <boost/algorithm/string/predicate.hpp>
#include <regex>
#include <test/jtx.h>
#include <test/jtx/Env.h>
@@ -90,10 +91,26 @@ class Invariants_test : public beast::unit_test::suite
{
terActual = ac.checkInvariants(terActual, fee);
BEAST_EXPECT(terExpect == terActual);
BEAST_EXPECT(
sink.messages().str().starts_with("Invariant failed:") ||
sink.messages().str().starts_with(
"Transaction caused an exception"));
// Handle both with and without BEAST_ENHANCED_LOGGING
auto const msg = sink.messages().str();
bool hasExpectedPrefix = false;
#ifdef BEAST_ENHANCED_LOGGING
// When BEAST_ENHANCED_LOGGING is enabled, messages may include ANSI
// color codes and start with [file:line]. Just search for the
// message content.
hasExpectedPrefix =
msg.find("Invariant failed:") != std::string::npos ||
msg.find("Transaction caused an exception") !=
std::string::npos;
#else
// Without BEAST_ENHANCED_LOGGING, messages start directly with the
// text
hasExpectedPrefix = msg.starts_with("Invariant failed:") ||
msg.starts_with("Transaction caused an exception");
#endif
BEAST_EXPECT(hasExpectedPrefix);
for (auto const& m : expect_logs)
{
if (sink.messages().str().find(m) == std::string::npos)