Support structured logging

[a1q123456]

High Level Overview of Change

This PR adds support for structured logs to rippled.

Before:

2025-Aug-21 13:46:37.129968 UTC NodeStore:DBG Stop request completed in 0 millseconds

After:

{
    "GlobalParams": {
        "Application": "rippled",
        "NetworkID": 0,
        "RippledVersion": "rippled-2.6.0",
        "InstanceCookie": "1576655243317954634"
    },
    "MessageParams": {
        "Function": "auto ripple::Resource::Logic::charge(Entry &, const Charge &, std::string)::(anonymous class)::operator()(Resource::Charge::value_type, beast::Journal &) const",
        "File": "/Users/xxx/rippled/cmake-build-release/modules/xrpl.libxrpl.resource/xrpl/resource/detail/Logic.h",
        "Line": 472,
        "ThreadId": "0x16fa17000",
        "Level": "debug",
        "Time": 1756841131362,
        "Entry": "x.x.x.x:51235",
        "Fee": "useless data ($150)"
    },
    "Message": "Charging x.x.x.x:51235 for useless data ($150) (validator_list_collection duplicate)"
}

To enable it, we'll need to add the following to the config file.

[log_style]
json

Context of Change

rippled currently produces plain text logs, which is human-readable but it makes debugging harder because contextual values are missing from logs (e.g. the current transaction id or the current account id we're processing), and parameters we push to logs get formatted directly into the message so that we don't have a chance to extract them later programmatically when debugging.

For example, if we'd like to debug an error and we have AMM Bid: not in range 10 5 hiding in millions of lines of logs, we'd have to write a regex to match logs like it and then we'd have to go through each log message and find the related error.

With structured logging, we're allowed to filter logs using javascript or whatever query languages, so that we could do:

ammBidLogs = logs
  .where(log => log.Module == "AMM Bid" && log.Message.contains("not in range") && log.Params.Price == 10)

// or
ammBidLogs = logs
  .where(log => log.Module == "AMM Bid" && log.Message.contains("not in range") && log.Params.Price > log.Params.BidMax)


// ammBidLogs contains logs produced by AMMBid and the message contains "not in range" and the price is 10 but max bid is 5
ammBidLogs

if we have logs like:

{
    "Message": "AMM Bid: not in range 10 5",
    "Params": {
        "Price": "10",
        "BidMax": "5"
    }
}

Type of Change

• Bug fix (non-breaking change which fixes an issue)
• New feature (non-breaking change which adds functionality)
• Breaking change (fix or feature that would cause existing functionality to not work as expected)
• Refactor (non-breaking change that only restructures code)
• Performance (increase or change in throughput and/or latency)
• Tests (you added tests for code that already exists, or your new feature included in this PR)
• Documentation update
• Chore (no impact to binary, e.g. .gitignore, formatting, dropping support for older tooling)
• Release

API Impact

• Public API: New feature (new methods and/or new fields)
• Public API: Breaking change (in general, breaking changes should only impact the next api_version)
• libxrpl change (any change that may affect libxrpl or dependents of libxrpl)
• Peer protocol change (must be backward compatible or bump the peer protocol version)

Future Tasks

1. The class beast::detail::SimpleJsonWriter only pushes strings into the final json structure and it doesn't and can't make sure the json object is valid. (i.e. you can add duplicate keys into an object and it won't complain) We should be careful when we add parameters to ensure that we don't have duplicate keys.
2. Add log::param and log::field to existing logs so that we can get more information to filter on in grafana.
   e.g.

We should change code like the following

JLOG(ctx_.journal.debug()) << "AMM Bid: not in range "
                           << computedPrice << " " << *bidMax;

to

JLOG(ctx_.journal.debug()) << "AMM Bid: not in range "
                           << log::param("Price", computedPrice) << " " << log::param("BidMax", *bidMax);

so that we can get logs with parameters instead of

{
    "Message": "AMM Bid: not in range 10 5",
    "Params": null
}

3. We should consider adding some sort of trace id to logs so that it makes it easier to extract all the logs related to a transaction or an action.

[codecov]

Codecov Report

❌ Patch coverage is 34.82353% with 277 lines in your changes missing coverage. Please review.
✅ Project coverage is 78.7%. Comparing base (cfd26f4) to head (4001748).
⚠️ Report is 16 commits behind head on develop.

Files with missing lines	Patch %	Lines
include/xrpl/beast/utility/Journal.h	40.5%	113 Missing ⚠️
src/libxrpl/beast/utility/beast_Journal.cpp	23.6%	110 Missing ⚠️
src/xrpld/overlay/detail/PeerImp.h	0.0%	14 Missing ⚠️
src/xrpld/app/consensus/RCLConsensus.cpp	0.0%	13 Missing ⚠️
src/libxrpl/basics/Log.cpp	0.0%	7 Missing ⚠️
src/xrpld/overlay/detail/PeerImp.cpp	70.0%	6 Missing ⚠️
src/xrpld/core/detail/Config.cpp	16.7%	5 Missing ⚠️
include/xrpl/basics/Log.h	0.0%	2 Missing ⚠️
src/xrpld/app/main/Application.h	50.0%	2 Missing ⚠️
src/xrpld/app/main/Application.cpp	75.0%	1 Missing ⚠️
... and 4 more

Additional details and impacted files

@@            Coverage Diff            @@
##           develop   #5710     +/-   ##
=========================================
- Coverage     78.9%   78.7%   -0.2%     
=========================================
  Files          816     816             
  Lines        72246   72709    +463     
  Branches      8418    8486     +68     
=========================================
+ Hits         56993   57210    +217     
- Misses       15253   15499    +246     

Files with missing lines	Coverage Δ
include/xrpl/server/detail/BasePeer.h	60.0% <100.0%> (ø)
src/xrpld/app/main/Main.cpp	79.1% <ø> (ø)
src/xrpld/app/paths/Flow.cpp	94.7% <100.0%> (+0.3%)	⬆️
src/xrpld/app/tx/detail/Transactor.cpp	89.3% <100.0%> (-0.1%)	⬇️
src/xrpld/app/tx/detail/Transactor.h	100.0% <ø> (ø)
src/xrpld/core/Config.h	84.6% <ø> (ø)
src/xrpld/core/ConfigSections.h	100.0% <ø> (ø)
src/xrpld/overlay/Slot.h	84.6% <100.0%> (ø)
src/xrpld/overlay/detail/ConnectAttempt.h	0.0% <ø> (ø)
src/xrpld/overlay/detail/OverlayImpl.h	37.5% <ø> (ø)
... and 14 more

... and 70 files with indirect coverage changes

🚀 New features to boost your workflow:

• ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

[Tapanito]

This is a big PR, it'll take some time for me to review it. This is part 1 :)

All in all, I think it would be great to have a side by side performance comparison of the current logger and the one you're proposing. Specifically:

• Execution time
• Log file size (i.e. how does the log file size differ between structured and unstructured logging)

[a1q123456]

This is a big PR, it'll take some time for me to review it. This is part 1 :)

All in all, I think it would be great to have a side by side performance comparison of the current logger and the one you're proposing. Specifically:

• Execution time
• Log file size (i.e. how does the log file size differ between structured and unstructured logging)

The log file size is going to be 100% to 300% larger than before I believe, as we'll be logging extra information.

[a1q123456]

Performance test results

Code used for testing

TEST_CASE("Performance test")
{
    std::string logStream;
    logStream.reserve(1024 * 5);

    MockLogs logs{logStream, beast::severities::kAll};

    beast::Journal::enableStructuredJournal();
    beast::Journal::addGlobalAttributes(log::attributes(
        log::attr("Field1", "Value1"),
        log::attr("Field2", "Value2")
    ));
    auto j = logs.journal("Test", log::attributes(
        log::attr("Field1", "Value1"),
        log::attr("Field2", "Value2")
    ));

    std::chrono::steady_clock::time_point startTime = std::chrono::steady_clock::now(); 
    auto iterations = 10'000'000; 
    if (beast::Journal::isStructuredJournalEnabled())
    {
        for (std::int64_t i = 0; i < iterations; i ++)
        {
            j.debug()
                    << "Test, "
                    << log::param("Field1", 1)
                    << log::param("Field2", "2")
                    << log::param("Field3", 121.2);
            logStream.clear();
        }
    }
    else
    {
        for (std::int64_t i = 0; i < iterations; i ++)
        {
            j.debug()
                    <<
                    R"AAA({"JournalParams":{"Field1":"Value1","Field2":"Value2"},"GlobalParams":{"Field1":"Value1","Field2":"Value2"},"MessageParams":{"Function":"void
                    DOCTEST_ANON_FUNC_14()","File":"rippled/src/tests/libxrpl/basics/log.cpp","Line":249,"ThreadId":"0x1f4fd20c0","Level":"debug","Time":1756807007389,"Field1":1,"Field2":"2","Field3":1.2},"Message":"Test,
                    121.2"})AAA";
            logStream.clear();
        }
    }
    std::chrono::steady_clock::time_point endTime = std::chrono::steady_clock::now();

    std::cout << "Time: " << endTime - startTime << std::endl;
}

Total time when json logging is enabled

26493392625ns

Total time when json logging is disabled

32366780250ns

Conclusion

This feature uses beast::detail::SimpleJsonWriter so that it turns JSON object operations into string manipulation, which is faster than ripple::Logs::format because it copies the log string twice.

[a1q123456]

There's some small issues with my lates change. Going to make this PR available tomorrow after I fix those issues.

[a1q123456]

Add a human readable time field
move message parameters into another object
Chop off the path and leave the file name only

[Tapanito]

@a1q123456 regarding your previous comment:

The log file size is going to be 100% to 300% larger than before I believe, as we'll be logging extra information.

Could you also run a benchmark comapring the size of the logs? Operators are already concerned that rippled logs are very large. It would be good to know exactly by how much they might grow.

[a1q123456]

Performance comparison: http://34.217.226.116//rippled/00MixedLoad/report_comparison/comparison_performance_benchmark_testing_rippled_mixload_no_test_name_specified_2233_20250929_090108_performance_on_demand_testing_rippled_mixload_no_test_name_specified_2233_20250929_090108.txt

Performance test result shows around -0.5% throughput drop when json logging is enabled. Given the isolated test, I believe it's because we're logging more text. I can optimise the log performance in a separate PR.