diff --git a/.github/workflows/sri-integration-test.yml b/.github/workflows/sri-integration-test.yml index dd404241..66ddddc9 100644 --- a/.github/workflows/sri-integration-test.yml +++ b/.github/workflows/sri-integration-test.yml @@ -13,8 +13,8 @@ jobs: runs-on: ubuntu-24.04 timeout-minutes: 90 env: - BITCOIN_CORE_VERSION: 31.0rc4 - BITCOIN_CORE_PLATFORM: x86_64-linux-gnu + BITCOIN_CORE_REPO: https://github.com/Sjors/bitcoin.git + BITCOIN_CORE_REF: 2025/11/ipc-memusage RUSTC_WRAPPER: sccache SCCACHE_GHA_ENABLED: 'true' SCENARIO_ROOT: ${{ github.workspace }}/sri-integration-test diff --git a/.gitignore b/.gitignore index 055b83e8..ac7cdecc 100644 --- a/.gitignore +++ b/.gitignore @@ -30,3 +30,4 @@ target/ # Agents AGENTS.md .claude +plots diff --git a/ci/test/04_run_stratum_v2_scenario.sh b/ci/test/04_run_stratum_v2_scenario.sh index 87a64e5f..d4184c0a 100755 --- a/ci/test/04_run_stratum_v2_scenario.sh +++ b/ci/test/04_run_stratum_v2_scenario.sh @@ -95,6 +95,17 @@ show_logs() ) } +has_memory_load_log() +{ + local log_file + for log_file in "${LOG_DIR}/sv2-tp.log" "${DATADIR}/regtest/sv2-debug.log"; do + if [[ -f "${log_file}" ]] && grep -Eq "Template memory footprint [0-9.]+ MiB" "${log_file}"; then + return 0 + fi + done + return 1 +} + cleanup() { set +e @@ -306,6 +317,11 @@ run_phase() grep -q "Connected to bitcoin-node via IPC" "${LOG_DIR}/sv2-tp.log" + if ! has_memory_load_log; then + echo "SRI integration test did not observe a getMemoryLoad() memory footprint log entry" >&2 + exit 1 + fi + echo "SRI integration test completed successfully at regtest height ${count}" } diff --git a/ci/test/stratum_v2_sv2-tp.conf b/ci/test/stratum_v2_sv2-tp.conf index 68b4808c..e99ced37 100644 --- a/ci/test/stratum_v2_sv2-tp.conf +++ b/ci/test/stratum_v2_sv2-tp.conf @@ -3,3 +3,4 @@ ipcconnect=unix debug=sv2 loglevel=sv2:trace printtoconsole=1 +memoryinterval=1 diff --git a/contrib/devtools/plot_memory_load.py b/contrib/devtools/plot_memory_load.py new file mode 100755 index 00000000..dfb691d1 --- /dev/null +++ b/contrib/devtools/plot_memory_load.py @@ -0,0 +1,380 @@ +#!/usr/bin/env python3 +"""Plot GetTemplateMemoryUsage durations and template memory footprints over time.""" +from __future__ import annotations + +import argparse +import datetime as dt +import pickle +import re +from pathlib import Path +from typing import List, Tuple + +import matplotlib.dates as mdates # type: ignore[import, import-not-found] +import matplotlib.pyplot as plt # type: ignore[import, import-not-found] +from matplotlib import transforms # type: ignore[import, import-not-found] +from matplotlib.ticker import NullFormatter # type: ignore[import, import-not-found] + +MEMORY_LOAD_COMPLETED = re.compile( + r"^(?P\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d+Z).*GetTemplateMemoryUsage:.*completed \((?P\d+\.\d+)ms\)" +) +UPDATE_TIP = re.compile( + r"^(?P\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d+Z).*UpdateTip:.*height=(?P\d+) " +) +TP_LOG_ENTRY = re.compile( + r"^(?P\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}(?:\.\d+)?)Z.*Template memory footprint (?P\d+(?:\.\d+)?) MiB" +) + +TIP_LABEL_MIN_FRACTION = 0.02 +CLIPPED_LABEL_MIN_FRACTION = 0.01 +DEFAULT_DURATION_CAP_MS = 15.0 # Hard cap for GetTemplateMemoryUsage durations + + +def format_with_machine(base: str, machine: str | None) -> str: + return f"{base} ({machine})" if machine else base + + +def parse_args() -> argparse.Namespace: + parser = argparse.ArgumentParser(description=__doc__) + parser.add_argument( + "bitcoin_log", + type=Path, + help="Path to bitcoin debug log containing GetTemplateMemoryUsage entries", + ) + parser.add_argument( + "--output", + type=Path, + default=Path("getmemoryload-scatter.svg"), + help="Destination image path (default: ./getmemoryload-scatter.svg)", + ) + parser.add_argument( + "--show", + action="store_true", + help="Display the plot interactively instead of saving it", + ) + parser.add_argument( + "tp_log", + type=Path, + help="SV2 template provider log containing 'Template memory footprint' lines", + ) + parser.add_argument( + "--since", + type=str, + default=None, + help=( + "Ignore log events earlier than this ISO 8601 timestamp. Naive timestamps " + "are interpreted as UTC (e.g. '2025-12-02T14:50:00')." + ), + ) + parser.add_argument( + "--duration-cap", + type=float, + default=DEFAULT_DURATION_CAP_MS, + help=( + "Clip GetTemplateMemoryUsage durations above this value (ms) and annotate their " + f"true value at the top of the chart. Default: {DEFAULT_DURATION_CAP_MS:.0f} ms." + ), + ) + parser.add_argument( + "--figure-pickle", + type=Path, + default=None, + help=( + "Optional path to write a pickle of the Matplotlib Figure for further " + "inspection." + ), + ) + parser.add_argument( + "--dpi", + type=int, + default=300, + help="Raster output resolution (applies to PNG/JPEG/TIFF). Default: 300 dpi.", + ) + parser.add_argument( + "--machine", + type=str, + default=None, + help="Optional machine label to append to dataset names (e.g. 'M4').", + ) + return parser.parse_args() + + +def parse_timestamp(raw: str) -> dt.datetime: + """Return timezone-aware UTC timestamps from log entries.""" + parsed = dt.datetime.fromisoformat(raw.replace("Z", "+00:00")) + if parsed.tzinfo is None: + parsed = parsed.replace(tzinfo=dt.timezone.utc) + return parsed.astimezone(dt.timezone.utc) + + +def parse_since_timestamp(raw: str) -> dt.datetime: + sanitized = raw.strip() + if not sanitized: + raise SystemExit("--since timestamp must not be empty") + if sanitized.endswith("Z"): + sanitized = f"{sanitized[:-1]}+00:00" + try: + parsed = dt.datetime.fromisoformat(sanitized) + except ValueError as exc: + raise SystemExit(f"Invalid --since timestamp '{raw}': {exc}") from exc + if parsed.tzinfo is None: + parsed = parsed.replace(tzinfo=dt.timezone.utc) + return parsed.astimezone(dt.timezone.utc) + + +def load_events(log_path: Path, since: dt.datetime | None = None): + mem_points = [] + tip_events = [] + with log_path.open("r", encoding="utf-8") as handle: + for line in handle: + mem_match = MEMORY_LOAD_COMPLETED.search(line) + if mem_match: + timestamp = parse_timestamp(mem_match.group("ts")) + if since is not None and timestamp < since: + continue + mem_points.append((timestamp, float(mem_match.group("ms")))) + continue + tip_match = UPDATE_TIP.search(line) + if tip_match: + timestamp = parse_timestamp(tip_match.group("ts")) + if since is not None and timestamp < since: + continue + tip_events.append((timestamp, int(tip_match.group("height")))) + mem_points.sort(key=lambda item: item[0]) + tip_events.sort(key=lambda item: item[0]) + return mem_points, tip_events + + +def load_tp_points( + log_path: Path, since: dt.datetime | None = None +) -> List[Tuple[dt.datetime, float]]: + tp_points: List[Tuple[dt.datetime, float]] = [] + if not log_path.exists(): + raise SystemExit(f"Template provider log '{log_path}' not found") + + with log_path.open("r", encoding="utf-8") as handle: + for line in handle: + match = TP_LOG_ENTRY.search(line) + if match: + mib_val = float(match.group("mib")) + timestamp = parse_timestamp(match.group("ts")) + if since is not None and timestamp < since: + continue + tp_points.append((timestamp, mib_val)) + + tp_points.sort(key=lambda item: item[0]) + if not tp_points: + raise SystemExit( + f"No template provider entries were found in '{log_path}'. Does it contain " + "'Template memory footprint' lines?" + ) + return tp_points + +def plot_memory_load( + mem_points, + tip_events, + tp_points, + duration_cap, + figure_pickle: Path | None, + dpi: int, + machine_label: str | None, + output: Path, + show_plot: bool, +) -> None: + if not mem_points: + raise SystemExit("No GetTemplateMemoryUsage() completion records found in log") + + times, durations = zip(*mem_points) + fig, ax = plt.subplots(figsize=(15, 5)) + fig.patch.set_facecolor("white") + fig.patch.set_alpha(1.0) + ax.set_facecolor("white") + duration_label = format_with_machine("GetTemplateMemoryUsage() duration", machine_label) + ax.scatter( + times, + durations, + s=5, + color="tab:blue", + label=duration_label, + zorder=3, + ) + + ax.set_ylabel("Duration (ms)") + ax.set_xlabel("") + ax.set_title("") + ax.xaxis.set_major_formatter(NullFormatter()) + ax.margins(x=0) + + max_duration = max(durations) + effective_cap = duration_cap + clipped_points = [] + if effective_cap is not None and effective_cap < max_duration: + ax.set_ylim(bottom=0, top=effective_cap) + clipped_points = [(timestamp, value) for timestamp, value in mem_points if value > effective_cap] + else: + upper_pad = max_duration * 1.05 if max_duration > 0 else 1 + ax.set_ylim(bottom=0, top=upper_pad) + + twin_ax = None + if tp_points: + tp_times, tp_mib = zip(*tp_points) + twin_ax = ax.twinx() + twin_ax.margins(x=0) + twin_ax.vlines( + tp_times, + [0] * len(tp_times), + tp_mib, + color="#4fbf73", + alpha=0.5, + linewidth=1, + zorder=1, + label="Template provider memory", + ) + twin_ax.set_ylabel("Memory footprint (MiB)", color="#2b8a46") + twin_ax.tick_params(axis="y", colors="#2b8a46") + twin_ax.set_ylim(bottom=0) + + if clipped_points: + clip_trans = transforms.blended_transform_factory(ax.transData, ax.transAxes) + marker_y = 1.0 + clipped_times = [timestamp for timestamp, _ in clipped_points] + clipped_values = [value for _, value in clipped_points] + clipped_time_nums = mdates.date2num(clipped_times) + ax.scatter( + clipped_time_nums, + [marker_y] * len(clipped_points), + marker="o", + s=22, + facecolors="none", + edgecolors="tab:blue", + linewidths=1, + label=f"Clipped duration (> {effective_cap:.2f} ms)", + transform=clip_trans, + clip_on=False, + zorder=4, + ) + label_min_delta = (ax.get_xlim()[1] - ax.get_xlim()[0]) * CLIPPED_LABEL_MIN_FRACTION + last_clipped_label_num: float | None = None + for ts_num, value in zip(clipped_time_nums, clipped_values): + if last_clipped_label_num is not None and ts_num - last_clipped_label_num < label_min_delta: + continue + label = f"{value:.0f} ms" + ax.annotate( + label, + xy=(ts_num, marker_y), + xycoords=clip_trans, + xytext=(0, -8), + textcoords="offset points", + ha="center", + va="top", + fontsize=8, + color="tab:blue", + rotation=270, + clip_on=False, + ) + last_clipped_label_num = ts_num + + if tip_events: + tip_color = "tab:red" + tip_times, tip_heights = zip(*tip_events) + tip_time_nums = mdates.date2num(tip_times) + trans = transforms.blended_transform_factory(ax.transData, ax.transAxes) + marker_y = -0.01 + ax.scatter( + tip_time_nums, + [marker_y] * len(tip_events), + marker="^", + s=70, + color=tip_color, + edgecolors="none", + label="Tip update", + zorder=4, + transform=trans, + clip_on=False, + ) + label_trans = transforms.blended_transform_factory(ax.transData, ax.transAxes) + x_start, x_end = ax.get_xlim() + min_delta = (x_end - x_start) * TIP_LABEL_MIN_FRACTION + last_label_num: float | None = None + for ts_num, height in zip(tip_time_nums, tip_heights): + if last_label_num is not None and ts_num - last_label_num < min_delta: + continue + label = f"{height:,}" + ax.annotate( + label, + xy=(ts_num, 0), + xycoords=label_trans, + xytext=(1, -8), + textcoords="offset points", + rotation=45, + ha="right", + va="top", + color=tip_color, + fontsize=8, + clip_on=False, + ) + last_label_num = ts_num + + handles, labels = ax.get_legend_handles_labels() + if twin_ax is not None: + twin_handles, twin_labels = twin_ax.get_legend_handles_labels() + handles += twin_handles + labels += twin_labels + try: + tip_idx = labels.index("Tip update") + tip_handle = handles.pop(tip_idx) + tip_label = labels.pop(tip_idx) + handles.append(tip_handle) + labels.append(tip_label) + except ValueError: + pass + legend = fig.legend( + handles, + labels, + loc="upper left", + bbox_to_anchor=(0.12, 0.78), + ) + legend.set_zorder(10) + frame = legend.get_frame() + frame.set_alpha(0.75) + frame.set_zorder(legend.get_zorder()) + ax.grid(True, axis="y", linestyle="--", alpha=0.3) + + if figure_pickle is not None: + figure_pickle.parent.mkdir(parents=True, exist_ok=True) + with figure_pickle.open("wb") as handle: + pickle.dump(fig, handle) + + if show_plot: + plt.show() + else: + output.parent.mkdir(parents=True, exist_ok=True) + raster_exts = {".png", ".jpg", ".jpeg", ".tif", ".tiff", ".bmp", ".gif"} + if output.suffix.lower() in raster_exts: + fig.savefig(output, bbox_inches="tight", facecolor=fig.get_facecolor(), dpi=dpi) + else: + fig.savefig(output, bbox_inches="tight", facecolor=fig.get_facecolor()) + print(f"Wrote {output}") + + plt.close(fig) + + +def main() -> None: + args = parse_args() + since_ts = parse_since_timestamp(args.since) if args.since else None + mem_points, tip_events = load_events(args.bitcoin_log, since_ts) + tp_points = load_tp_points(args.tp_log, since_ts) + plot_memory_load( + mem_points, + tip_events, + tp_points, + args.duration_cap, + args.figure_pickle, + args.dpi, + args.machine, + args.output, + args.show, + ) + + +if __name__ == "__main__": + main() diff --git a/src/interfaces/mining.h b/src/interfaces/mining.h index 956effa0..3868e304 100644 --- a/src/interfaces/mining.h +++ b/src/interfaces/mining.h @@ -92,6 +92,12 @@ class BlockTemplate virtual void interruptWait() = 0; }; +//! Tracks memory usage for template-bound transactions. +struct MemoryLoad +{ + uint64_t usage{0}; +}; + //! Interface giving clients (RPC, Stratum v2 Template Provider in the future) //! ability to create block templates. class Mining @@ -155,6 +161,12 @@ class Mining */ virtual bool checkBlock(const CBlock& block, const node::BlockCheckOptions& options, std::string& reason, std::string& debug) = 0; + /** + * Returns the current memory load for template transactions outside the + * mempool. + */ + virtual MemoryLoad getMemoryLoad() = 0; + //! Get internal node context. Useful for RPC and testing, //! but not accessible across processes. virtual node::NodeContext* context() { return nullptr; } diff --git a/src/ipc/capnp/mining.capnp b/src/ipc/capnp/mining.capnp index 39ac1267..86048d94 100644 --- a/src/ipc/capnp/mining.capnp +++ b/src/ipc/capnp/mining.capnp @@ -25,6 +25,7 @@ interface Mining $Proxy.wrap("interfaces::Mining") { createNewBlock @4 (context :Proxy.Context, options: BlockCreateOptions, cooldown: Bool = true) -> (result: BlockTemplate); checkBlock @5 (context :Proxy.Context, block: Data, options: BlockCheckOptions) -> (reason: Text, debug: Text, result: Bool); interrupt @6 () -> (); + getMemoryLoad @7 (context :Proxy.Context) -> (result: MemoryLoad); } interface BlockTemplate $Proxy.wrap("interfaces::BlockTemplate") { @@ -46,6 +47,10 @@ struct BlockCreateOptions $Proxy.wrap("node::BlockCreateOptions") { coinbaseOutputMaxAdditionalSigops @2 :UInt64 = .defaultCoinbaseOutputMaxAdditionalSigops $Proxy.name("coinbase_output_max_additional_sigops"); } +struct MemoryLoad $Proxy.wrap("interfaces::MemoryLoad") { + usage @0 :UInt64; +} + struct BlockWaitOptions $Proxy.wrap("node::BlockWaitOptions") { timeout @0 : Float64 = .maxDouble $Proxy.name("timeout"); feeThreshold @1 : Int64 = .maxMoney $Proxy.name("fee_threshold"); diff --git a/src/sv2-tp.cpp b/src/sv2-tp.cpp index 419998f1..b3e2deee 100644 --- a/src/sv2-tp.cpp +++ b/src/sv2-tp.cpp @@ -120,6 +120,7 @@ static void AddArgs(ArgsManager& args) args.AddArg("-sv2bind=[:]", strprintf("Bind to given address and always listen on it (default: 127.0.0.1). Use [host]:port notation for IPv6."), ArgsManager::ALLOW_ANY | ArgsManager::NETWORK_ONLY, OptionsCategory::CONNECTION); args.AddArg("-sv2port=", strprintf("Listen for Stratum v2 connections on (default: %u, testnet3: %u, testnet4: %u, signet: %u, regtest: %u).", defaultBaseParams->Sv2Port(), testnetBaseParams->Sv2Port(), testnet4BaseParams->Sv2Port(), signetBaseParams->Sv2Port(), regtestBaseParams->Sv2Port()), ArgsManager::ALLOW_ANY | ArgsManager::NETWORK_ONLY, OptionsCategory::CONNECTION); args.AddArg("-templateinterval", strprintf("Minimum seconds between fee-based template updates. New blocks always propagate immediately. (default: %d)", Sv2TemplateProviderOptions().template_interval.count()), ArgsManager::ALLOW_ANY, OptionsCategory::BLOCK_CREATION); + args.AddArg("-memoryinterval", strprintf("Template Provider memory usage reporting interval (default: %d seconds)", Sv2TemplateProviderOptions().memory_check_interval.count()), ArgsManager::ALLOW_ANY, OptionsCategory::BLOCK_CREATION); args.AddArg("-sv2feedelta", strprintf("Minimum fee delta for Template Provider to send update upstream (default: %d sat)", uint64_t(Sv2TemplateProviderOptions().fee_delta)), ArgsManager::ALLOW_ANY, OptionsCategory::BLOCK_CREATION); init::AddLoggingArgs(args); } @@ -231,6 +232,14 @@ MAIN_FUNCTION options.template_interval = std::chrono::seconds(args.GetIntArg("-templateinterval", 0)); } + if (args.IsArgSet("-memoryinterval")) { + if (args.GetIntArg("-memoryinterval", 0) < 1) { + tfm::format(std::cerr, "-memoryinterval must be at least one second\n"); + return EXIT_FAILURE; + } + options.memory_check_interval = std::chrono::seconds(args.GetIntArg("-memoryinterval", 0)); + } + // Connect to bitcoin-node via IPC // // If the node is not available, keep retrying in a loop every 10 seconds. diff --git a/src/sv2/template_provider.cpp b/src/sv2/template_provider.cpp index a445bd46..bddc0a96 100644 --- a/src/sv2/template_provider.cpp +++ b/src/sv2/template_provider.cpp @@ -17,6 +17,8 @@ #include #include +using interfaces::MemoryLoad; + // Allow a few seconds for clients to submit a block or to request transactions constexpr size_t STALE_TEMPLATE_GRACE_PERIOD{10}; @@ -110,6 +112,8 @@ bool Sv2TemplateProvider::Start(const Sv2TemplateProviderOptions& options) } m_thread_sv2_handler = std::thread(&util::TraceThread, "sv2", [this] { ThreadSv2Handler(); }); + m_thread_memory_handler = std::thread(&util::TraceThread, "memory", [this] { ThreadMemoryHandler(); }); + return true; } @@ -147,6 +151,9 @@ void Sv2TemplateProvider::StopThreads() if (m_thread_sv2_handler.joinable()) { m_thread_sv2_handler.join(); } + if (m_thread_memory_handler.joinable()) { + m_thread_memory_handler.join(); + } } class Timer { @@ -242,6 +249,26 @@ void Sv2TemplateProvider::ThreadSv2Handler() } +void Sv2TemplateProvider::ThreadMemoryHandler() +{ + Timer timer{m_options.memory_check_interval}; + while (!m_flag_interrupt_sv2) { + std::this_thread::sleep_for(1000ms); + if (!timer.trigger()) continue; + if (m_mining.isInitialBlockDownload()) continue; + try { + MemoryLoad memory_load{m_mining.getMemoryLoad()}; + const double usage_mib{static_cast(memory_load.usage) / (1024.0 * 1024.0)}; + const std::string usage_mib_str{strprintf("%.3f", usage_mib)}; + LogTrace(BCLog::SV2, "Template memory footprint %s MiB", usage_mib_str); + } catch (const ipc::Exception& e) { + LogTrace(BCLog::SV2, "getMemoryLoad() not implemented on the node"); + // Nothing to do for this thread + break; + } + } +} + void Sv2TemplateProvider::ThreadSv2ClientHandler(size_t client_id) { try { diff --git a/src/sv2/template_provider.h b/src/sv2/template_provider.h index 5b53bcb6..c63bfde6 100644 --- a/src/sv2/template_provider.h +++ b/src/sv2/template_provider.h @@ -43,6 +43,11 @@ struct Sv2TemplateProviderOptions * New blocks always propagate immediately. */ std::chrono::seconds template_interval{5}; + + /** + * Memory usage reporting interval + */ + std::chrono::seconds memory_check_interval{60}; }; /** @@ -82,6 +87,11 @@ class Sv2TemplateProvider : public Sv2EventsInterface */ std::thread m_thread_sv2_handler; + /** + * Memory management thread + */ + std::thread m_thread_memory_handler; + /** * Signal for handling interrupts and stopping the template provider event loop. */ @@ -130,6 +140,11 @@ class Sv2TemplateProvider : public Sv2EventsInterface */ void ThreadSv2Handler() EXCLUSIVE_LOCKS_REQUIRED(!m_tp_mutex); + /** + * Template memory management thread. + */ + void ThreadMemoryHandler() EXCLUSIVE_LOCKS_REQUIRED(!m_tp_mutex); + /** * Give each client its own thread so they're treated equally * and so that newly connected clients don't have to wait. diff --git a/src/test/sv2_mock_mining.cpp b/src/test/sv2_mock_mining.cpp index a34feba3..0cbce693 100644 --- a/src/test/sv2_mock_mining.cpp +++ b/src/test/sv2_mock_mining.cpp @@ -123,6 +123,12 @@ std::unique_ptr MockMining::createNewBlock(const node void MockMining::interrupt() { LogPrintLevel(BCLog::SV2, BCLog::Level::Trace, "mock interrupt()"); } bool MockMining::checkBlock(const CBlock&, const node::BlockCheckOptions&, std::string&, std::string&) { return true; } +MemoryLoad MockMining::getMemoryLoad() +{ + LOCK(state->m); + return state->memory_load; +} + uint64_t MockMining::GetTemplateSeq() { LOCK(state->m); @@ -154,6 +160,11 @@ void MockMining::TriggerNewTip() state->events.push(MockEvent{MockEvent::Type::NewTip, {}}); state->cv.notify_all(); } +void MockMining::SetMemoryLoad(uint64_t usage) +{ + LOCK(state->m); + state->memory_load = {.usage = usage}; +} void MockMining::Shutdown() { LOCK(state->m); diff --git a/src/test/sv2_mock_mining.h b/src/test/sv2_mock_mining.h index 1014dd80..ee12895e 100644 --- a/src/test/sv2_mock_mining.h +++ b/src/test/sv2_mock_mining.h @@ -17,6 +17,8 @@ #include #include +using interfaces::MemoryLoad; + // Minimal mocks for the Mining IPC interface used by sv2 tests. struct MockEvent { @@ -44,6 +46,7 @@ struct MockState { std::vector txs; // non-coinbase transactions included in templates std::queue events; // queued events driving waitNext() std::condition_variable_any cv; + MemoryLoad memory_load; bool shutdown{false}; }; @@ -81,6 +84,7 @@ class MockMining : public interfaces::Mining { std::unique_ptr createNewBlock(const node::BlockCreateOptions&, bool cooldown) override; void interrupt() override; bool checkBlock(const CBlock&, const node::BlockCheckOptions&, std::string&, std::string&) override; + MemoryLoad getMemoryLoad() override; // Accessors for tests (thread-safe) uint64_t GetTemplateSeq(); @@ -89,6 +93,7 @@ class MockMining : public interfaces::Mining { // Test control helpers void TriggerFeeIncrease(std::vector txs); void TriggerNewTip(); + void SetMemoryLoad(uint64_t usage); void Shutdown(); // Wait until internal template sequence reaches at least target (returns false on timeout/shutdown) diff --git a/src/test/sv2_template_provider_tests.cpp b/src/test/sv2_template_provider_tests.cpp index 44cb9d87..11405d42 100644 --- a/src/test/sv2_template_provider_tests.cpp +++ b/src/test/sv2_template_provider_tests.cpp @@ -2,6 +2,7 @@ #include #include #include +#include #include #include #include @@ -16,9 +17,11 @@ #include #include -#include #include +#include +#include #include +#include #include #include @@ -38,6 +41,57 @@ BOOST_AUTO_TEST_CASE(block_reserved_weight_floor) BOOST_REQUIRE_EQUAL(options.block_reserved_weight, node::MIN_BLOCK_RESERVED_WEIGHT); } +BOOST_AUTO_TEST_CASE(memory_load_log) +{ + auto& logger{LogInstance()}; + logger.DisconnectTestLogger(); + logger.m_print_to_console = false; + logger.m_print_to_file = false; + logger.m_log_timestamps = false; + logger.EnableCategory(BCLog::SV2); + logger.SetCategoryLogLevel({{BCLog::SV2, BCLog::Level::Trace}}); + + std::mutex mutex; + std::condition_variable cv; + bool found{false}; + auto callback{logger.PushBackCallback([&](const std::string& line) { + if (line.find("Template memory footprint 2.000 MiB") == std::string::npos) return; + { + std::lock_guard lock{mutex}; + found = true; + } + cv.notify_one(); + })}; + struct LoggerCleanup { + BCLog::Logger& logger; + decltype(callback) callback_it; + ~LoggerCleanup() + { + logger.DeleteCallback(callback_it); + logger.DisableCategory(BCLog::SV2); + logger.SetCategoryLogLevel({}); + } + } logger_cleanup{logger, callback}; + BOOST_REQUIRE(logger.StartLogging()); + + bool saw_log{false}; + { + TPTester tester{}; + tester.m_mining_control->SetMemoryLoad(2 * 1024 * 1024); + + // Jump to the next 60 second reporting interval. Retry a few times to + // avoid depending on exactly when the memory thread started. + for (int attempt{0}; attempt < 3 && !saw_log; ++attempt) { + SetMockTime(GetMockTime() + std::chrono::seconds{60}); + std::unique_lock lock{mutex}; + saw_log = cv.wait_for(lock, std::chrono::milliseconds{1500}, [&] { return found; }); + } + tester.m_mining_control->Shutdown(); + } + + BOOST_REQUIRE(saw_log); +} + BOOST_AUTO_TEST_CASE(client_tests) { TPTester tester{};