ARCHIVE/rippled
1
0
Fork 0
mirror of https://github.com/XRPLF/rippled.git synced 2025-12-03 01:15:53 +00:00
Code Issues Packages Projects Releases Wiki Activity

better WASM logging to match rippled (#5395)

Browse Source 
* basic logging

* pass in Journal

* log level based on journal level

* clean up

* attempt at adding WAMR logging properly

* improve logline

* maybe_unused

* fix

* fix

* fix segfault

* add test
This commit is contained in:
Mayukha Vadari
2025-05-23 10:31:02 -04:00
committed by GitHub
parent 5b43ec7f73
commit aef32ead2c
7 changed files with 213 additions and 69 deletions
Download Patch File Download Diff File Expand all files Collapse all files

43
external/wamr/conanfile.py vendored
View File

@@ -1,11 +1,16 @@
from conans import ConanFile, tools
from conan.tools.cmake import CMake, CMakeToolchain, CMakeDeps, cmake_layout
from conan.tools.files import apply_conandata_patches, export_conandata_patches, get, copy
import os
import json
from conan.tools.files import (
apply_conandata_patches,
export_conandata_patches,
# get,
)
# import os
required_conan_version = ">=1.55.0"
class WamrConan(ConanFile):
name = "wamr"
version = "2.2.0"
@@ -17,31 +22,30 @@ class WamrConan(ConanFile):
options = {"shared": [True, False], "fPIC": [True, False]}
default_options = {"shared": False, "fPIC": True}
generators = "CMakeToolchain", "CMakeDeps"
#requires = [("llvm/20.1.1@")]
# requires = [("llvm/20.1.1@")]
def export_sources(self):
export_conandata_patches(self)
pass
#def build_requirements(self):
# def build_requirements(self):
# self.tool_requires("llvm/20.1.1")
def config_options(self):
if self.settings.os == "Windows":
del self.options.fPIC
def layout(self):
cmake_layout(self, src_folder="src")
def source(self):
git = tools.Git()
git.clone("https://github.com/bytecodealliance/wasm-micro-runtime.git", "c883fafead005e87ad3122b05409886f507c1cb0",shallow=True)
#get(self, **self.conan_data["sources"][self.version], strip_root=True)
git.clone(
"https://github.com/bytecodealliance/wasm-micro-runtime.git",
"c883fafead005e87ad3122b05409886f507c1cb0",
shallow=True,
)
# get(self, **self.conan_data["sources"][self.version], strip_root=True)
def generate(self):
tc = CMakeToolchain(self)
@@ -54,37 +58,34 @@ class WamrConan(ConanFile):
tc.variables["WAMR_BUILD_FAST_JIT"] = 0
tc.variables["WAMR_DISABLE_HW_BOUND_CHECK"] = 1
tc.variables["WAMR_DISABLE_STACK_HW_BOUND_CHECK"] = 1
#tc.variables["WAMR_BUILD_FAST_JIT"] = 0 if self.settings.os == "Windows" else 1
#ll_dep = self.dependencies["llvm"]
#self.output.info(f"-----------package_folder: {type(ll_dep.__dict__)}")
#tc.variables["LLVM_DIR"] = os.path.join(ll_dep.package_folder, "lib", "cmake", "llvm")
tc.variables["WAMR_BH_LOG"] = "wamr_log_to_rippled"
# tc.variables["WAMR_BUILD_FAST_JIT"] = 0 if self.settings.os == "Windows" else 1
# ll_dep = self.dependencies["llvm"]
# self.output.info(f"-----------package_folder: {type(ll_dep.__dict__)}")
# tc.variables["LLVM_DIR"] = os.path.join(ll_dep.package_folder, "lib", "cmake", "llvm")
tc.generate()
# This generates "foo-config.cmake" and "bar-config.cmake" in self.generators_folder
deps = CMakeDeps(self)
deps.generate()
def build(self):
apply_conandata_patches(self)
cmake = CMake(self)
cmake.verbose = True
cmake.configure()
cmake.build()
#self.run(f'echo {self.source_folder}')
# self.run(f'echo {self.source_folder}')
# Explicit way:
# self.run('cmake %s/hello %s' % (self.source_folder, cmake.command_line))
# self.run("cmake --build . %s" % cmake.build_config)
def package(self):
cmake = CMake(self)
cmake.verbose = True
cmake.install()
def package_info(self):
self.cpp_info.libs = ["iwasm"]
self.cpp_info.names["cmake_find_package"] = "wamr"
self.cpp_info.names["cmake_find_package_multi"] = "wamr"

103
src/test/app/Wasm_test.cpp
View File

@@ -127,41 +127,58 @@ struct Wasm_test : public beast::unit_test::suite
using namespace test::jtx;
struct TestHostFunctions : public HostFunctions
{
Env* env;
Bytes accountID;
Bytes data;
int clock_drift = 0;
Env* env_;
Bytes accountID_;
Bytes data_;
int clock_drift_ = 0;
test::StreamSink sink_;
beast::Journal jlog_;
public:
explicit TestHostFunctions(Env* env, int cd = 0)
: env(env), clock_drift(cd)
: env_(env)
, clock_drift_(cd)
, sink_(beast::severities::kTrace)
, jlog_(sink_)
{
std::string s = "rHb9CJAWyB4rj91VRWn96DkukG4bwdtyTh";
accountID = Bytes{s.begin(), s.end()};
accountID_ = Bytes{s.begin(), s.end()};
std::string t = "10000";
data = Bytes{t.begin(), t.end()};
data_ = Bytes{t.begin(), t.end()};
}
test::StreamSink&
getSink()
{
return sink_;
}
beast::Journal
getJournal() override
{
return jlog_;
}
int32_t
getLedgerSqn() override
{
return (int32_t)env->current()->seq();
return (int32_t)env_->current()->seq();
}
int32_t
getParentLedgerTime() override
{
return env->current()
return env_->current()
->parentCloseTime()
.time_since_epoch()
.count() +
clock_drift;
clock_drift_;
}
std::optional<Bytes>
getTxField(std::string const& fname) override
{
return accountID;
return accountID_;
}
std::optional<Bytes>
@@ -170,19 +187,19 @@ struct Wasm_test : public beast::unit_test::suite
Bytes const& kdata,
std::string const& fname) override
{
return data;
return data_;
}
std::optional<Bytes>
getCurrentLedgerEntryField(std::string const& fname) override
{
if (fname == "Destination" || fname == "Account")
return accountID;
return accountID_;
else if (fname == "Data")
return data;
return data_;
else if (fname == "FinishAfter")
{
auto t = env->current()
auto t = env_->current()
->parentCloseTime()
.time_since_epoch()
.count();
@@ -197,14 +214,14 @@ struct Wasm_test : public beast::unit_test::suite
Env env{*this};
{
TestHostFunctions nfs(&env);
TestHostFunctions nfs(&env, 0);
std::string funcName("finish");
auto re = runEscrowWasm(wasm, funcName, &nfs, 100000);
if (BEAST_EXPECT(re.has_value()))
{
BEAST_EXPECT(re.value().result);
std::cout << "good case result " << re.value().result
<< " cost: " << re.value().cost << std::endl;
// std::cout << "good case result " << re.value().result
// << " cost: " << re.value().cost << std::endl;
}
}
@@ -214,17 +231,17 @@ struct Wasm_test : public beast::unit_test::suite
env.close();
{ // fail because current time < escrow_finish_after time
TestHostFunctions nfs(&env);
nfs.clock_drift = -1;
TestHostFunctions nfs(&env, -1);
std::string funcName("finish");
auto re = runEscrowWasm(wasm, funcName, &nfs, 100000);
if (BEAST_EXPECT(re.has_value()))
{
BEAST_EXPECT(!re.value().result);
std::cout << "bad case (current time < escrow_finish_after "
"time) result "
<< re.value().result << " cost: " << re.value().cost
<< std::endl;
// std::cout << "bad case (current time < escrow_finish_after "
// "time) result "
// << re.value().result << " cost: " <<
// re.value().cost
// << std::endl;
}
}
@@ -244,8 +261,8 @@ struct Wasm_test : public beast::unit_test::suite
std::string funcName("finish");
auto re = runEscrowWasm(wasm, funcName, &nfs, 100000);
BEAST_EXPECT(re.error());
std::cout << "bad case (access nonexistent field) result "
<< re.error() << std::endl;
// std::cout << "bad case (access nonexistent field) result "
// << re.error() << std::endl;
}
{ // fail because trying to allocate more than MAX_PAGES memory
@@ -263,9 +280,9 @@ struct Wasm_test : public beast::unit_test::suite
BadTestHostFunctions nfs(&env);
std::string funcName("finish");
auto re = runEscrowWasm(wasm, funcName, &nfs, 100000);
if (BEAST_EXPECT(!re))
std::cout << "bad case (more than MAX_PAGES) result "
<< re.error() << std::endl;
BEAST_EXPECT(!re);
// std::cout << "bad case (more than MAX_PAGES) result "
// << re.error() << std::endl;
}
{ // fail because recursion too deep
@@ -276,9 +293,31 @@ struct Wasm_test : public beast::unit_test::suite
TestHostFunctions nfs(&env);
std::string funcName("recursive");
auto re = runEscrowWasm(wasm, funcName, &nfs, 1000'000'000);
if (BEAST_EXPECT(re.error()))
std::cout << "bad case (deep recursion) result " << re.error()
<< std::endl;
BEAST_EXPECT(re.error());
// std::cout << "bad case (deep recursion) result " << re.error()
// << std::endl;
auto const& sink = nfs.getSink();
auto countSubstr = [](std::string const& str,
std::string const& substr) {
std::size_t pos = 0;
int occurrences = 0;
while ((pos = str.find(substr, pos)) != std::string::npos)
{
occurrences++;
pos += substr.length();
}
return occurrences;
};
BEAST_EXPECT(
countSubstr(
sink.messages().str(), "WAMR error: failed to call func") ==
1);
BEAST_EXPECT(
countSubstr(
sink.messages().str(),
"WAMR trap: Exception: wasm operand stack overflow") == 1);
}
}

107
src/xrpld/app/misc/WamrVM.cpp
View File

@@ -19,6 +19,8 @@
#include <xrpld/app/misc/WamrVM.h>
#include <xrpl/basics/Log.h>
#include <memory>
namespace ripple {
@@ -27,10 +29,91 @@ namespace ripple {
namespace {
static void
print_wasm_error(const char* message, wasm_trap_t* trap)
static log_level_t
getLogLevel(beast::severities::Severity severity)
{
fprintf(stderr, "WAMR error: %s\n", message);
using namespace beast::severities;
switch (severity)
{
case kTrace:
return WASM_LOG_LEVEL_VERBOSE;
case kDebug:
return WASM_LOG_LEVEL_DEBUG;
case kInfo:
case kWarning:
return WASM_LOG_LEVEL_WARNING;
case kError:
return WASM_LOG_LEVEL_ERROR;
default:
UNREACHABLE("invalid severity");
[[fallthrough]];
case kFatal:
case kNone:
break;
}
return WASM_LOG_LEVEL_FATAL;
}
static beast::severities::Severity
getLogLevel(uint32_t severity)
{
using namespace beast::severities;
switch (severity)
{
case WASM_LOG_LEVEL_VERBOSE:
return kTrace;
case WASM_LOG_LEVEL_DEBUG:
return kDebug;
case WASM_LOG_LEVEL_WARNING:
return kWarning;
case WASM_LOG_LEVEL_ERROR:
return kError;
default:
UNREACHABLE("invalid severity");
[[fallthrough]];
case WASM_LOG_LEVEL_FATAL:
break;
}
return kFatal;
}
// This function is called from WAMR to log messages.
extern "C" void
wamr_log_to_rippled(
uint32_t logLevel,
const char* file,
int line,
const char* fmt,
...)
{
beast::Journal j = debugLog();
// Format the variadic args
const char* safeFile = file ? file : "<null>";
std::ostringstream oss;
oss << "WAMR LOG (" << safeFile << ":" << line << "): ";
va_list args;
va_start(args, fmt);
char formatted[1024];
vsnprintf(formatted, sizeof(formatted), fmt, args);
formatted[sizeof(formatted) - 1] = '\0';
va_end(args);
oss << formatted;
j.stream(getLogLevel(logLevel)) << oss.str();
}
static void
print_wasm_error(const char* message, wasm_trap_t* trap, beast::Journal j)
{
j.debug() << "WAMR error: " << message;
if (trap)
{
@@ -38,11 +121,7 @@ print_wasm_error(const char* message, wasm_trap_t* trap)
wasm_trap_message(trap, &error_message);
wasm_trap_delete(trap);
fprintf(
stderr,
"WAMR trap: %.*s\n",
(int)error_message.size,
error_message.data);
j.debug() << "WAMR trap: " << error_message.data;
wasm_byte_vec_delete(&error_message);
}
}
@@ -69,7 +148,10 @@ InstanceWrapper::init(
if (!mi || trap)
{
print_wasm_error("can't create instance", trap);
print_wasm_error(
"can't create instance",
trap,
beast::Journal(beast::Journal::getNullSink()));
throw std::runtime_error("WAMR: can't create instance");
}
wasm_instance_exports(mi.get(), expt);
@@ -570,7 +652,7 @@ WamrEngine::call(wasm_func_t* func, std::vector<wasm_val_t>& in)
nullptr};
trap = wasm_func_call(func, &inv, &ret.r);
if (trap)
print_wasm_error("failed to call func", trap);
print_wasm_error("failed to call func", trap, j_);
// assert(results[0].kind == WASM_I32);
// if (NR) printf("Result P5: %d\n", ret[0].of.i32);
@@ -645,10 +727,13 @@ WamrEngine::run(
wbytes const& wasmCode,
std::string_view funcName,
std::vector<WasmImportFunc> const& imports,
std::vector<WasmParam> const& params)
std::vector<WasmParam> const& params,
beast::Journal j)
{
try
{
wasm_runtime_set_log_level(getLogLevel(j.sink().threshold()));
j_ = j;
return runHlp(wasmCode, funcName, imports, params);
}
catch (std::exception const&)

6
src/xrpld/app/misc/WamrVM.h
View File

@@ -20,6 +20,8 @@
#include <xrpld/app/misc/WasmVM.h>
#include <xrpl/beast/utility/Journal.h>
#include <iwasm/wasm_c_api.h>
#include <iwasm/wasm_export.h>
@@ -146,6 +148,7 @@ class WamrEngine
wasm_trap_t* trap = nullptr;
std::int64_t defGas = -1;
std::int32_t defMaxPages = -1;
beast::Journal j_ = beast::Journal(beast::Journal::getNullSink());
public:
WamrEngine();
@@ -155,7 +158,8 @@ public:
run(wbytes const& wasmCode,
std::string_view funcName,
std::vector<WasmImportFunc> const& imports,
std::vector<WasmParam> const& params);
std::vector<WasmParam> const& params,
beast::Journal j);
std::int64_t
initGas(std::int64_t def);

7
src/xrpld/app/misc/WasmHostFuncImpl.h
View File

@@ -23,6 +23,7 @@
#include <xrpld/app/tx/detail/ApplyContext.h>
#include <xrpl/basics/Expected.h>
#include <xrpl/beast/utility/Journal.h>
#include <xrpl/protocol/TER.h>
namespace ripple {
@@ -34,6 +35,12 @@ public:
{
}
beast::Journal
getJournal() override
{
return ctx.journal;
}
int32_t
getLedgerSqn() override;

7
src/xrpld/app/misc/WasmVM.cpp
View File

@@ -56,7 +56,7 @@ runEscrowWasm(
WASM_IMPORT_FUNC(imports, print, hfs)
std::int64_t const sgas = gasLimit; // vm.getGas();
auto ret = vm.run(wasmCode, funcName, imports);
auto ret = vm.run(wasmCode, funcName, imports, {}, hfs->getJournal());
// std::cout << "runEscrowWasm, mod size: " << wasmCode.size()
// << ", gasLimit: " << gasLimit << ", funcName: " << funcName;
@@ -92,9 +92,10 @@ WasmEngine::run(
wbytes const& wasmCode,
std::string_view funcName,
std::vector<WasmImportFunc> const& imports,
std::vector<WasmParam> const& params)
std::vector<WasmParam> const& params,
beast::Journal j)
{
return impl->run(wasmCode, funcName, imports, params);
return impl->run(wasmCode, funcName, imports, params, j);
}
std::int64_t

9
src/xrpld/app/misc/WasmVM.h
View File

@@ -68,6 +68,12 @@ typedef WasmResult<bool> EscrowResult;
struct HostFunctions
{
virtual beast::Journal
getJournal()
{
return beast::Journal{beast::Journal::getNullSink()};
}
virtual int32_t
getLedgerSqn()
{
@@ -331,7 +337,8 @@ public:
run(wbytes const& wasmCode,
std::string_view funcName = {},
std::vector<WasmImportFunc> const& imports = {},
std::vector<WasmParam> const& params = {});
std::vector<WasmParam> const& params = {},
beast::Journal j = beast::Journal{beast::Journal::getNullSink()});
std::int64_t
initGas(std::int64_t def = 1'000'000'000'000LL);