490 lines
18 KiB
Rust
490 lines
18 KiB
Rust
//! Test generating checkpoints using `zebra-checkpoints` directly connected to `zebrad`.
|
|
//!
|
|
//! This test requires a cached chain state that is synchronized close to the network chain tip
|
|
//! height. It will finish the sync and update the cached chain state.
|
|
|
|
use std::{
|
|
env, fs,
|
|
net::SocketAddr,
|
|
path::{Path, PathBuf},
|
|
sync::atomic::{AtomicBool, Ordering},
|
|
};
|
|
|
|
use color_eyre::eyre::Result;
|
|
use tempfile::TempDir;
|
|
|
|
use zebra_chain::{
|
|
block::{Height, HeightDiff, TryIntoHeight},
|
|
parameters::Network,
|
|
transparent::MIN_TRANSPARENT_COINBASE_MATURITY,
|
|
};
|
|
use zebra_consensus::MAX_CHECKPOINT_HEIGHT_GAP;
|
|
use zebra_node_services::rpc_client::RpcRequestClient;
|
|
use zebra_test::{
|
|
args,
|
|
command::{Arguments, TestDirExt, NO_MATCHES_REGEX_ITER},
|
|
prelude::TestChild,
|
|
};
|
|
|
|
use crate::common::{
|
|
launch::spawn_zebrad_for_rpc,
|
|
sync::{CHECKPOINT_VERIFIER_REGEX, SYNC_FINISHED_REGEX},
|
|
test_type::TestType::*,
|
|
};
|
|
|
|
use super::{
|
|
config::testdir,
|
|
failure_messages::{
|
|
PROCESS_FAILURE_MESSAGES, ZEBRA_CHECKPOINTS_FAILURE_MESSAGES, ZEBRA_FAILURE_MESSAGES,
|
|
},
|
|
launch::ZebradTestDirExt,
|
|
test_type::TestType,
|
|
};
|
|
|
|
/// The environmental variable used to activate zebrad logs in the checkpoint generation test.
|
|
///
|
|
/// We use a constant so the compiler detects typos.
|
|
pub const LOG_ZEBRAD_CHECKPOINTS: &str = "LOG_ZEBRAD_CHECKPOINTS";
|
|
|
|
/// The test entry point.
|
|
#[allow(clippy::print_stdout)]
|
|
pub async fn run(network: Network) -> Result<()> {
|
|
let _init_guard = zebra_test::init();
|
|
|
|
// We want a Zebra state dir, but we don't need `lightwalletd`.
|
|
let test_type = UpdateZebraCachedStateWithRpc;
|
|
let test_name = "zebra_checkpoints_test";
|
|
|
|
// Skip the test unless the user supplied the correct cached state env vars
|
|
let Some(zebrad_state_path) = test_type.zebrad_state_path(test_name) else {
|
|
return Ok(());
|
|
};
|
|
|
|
tracing::info!(
|
|
?network,
|
|
?test_type,
|
|
?zebrad_state_path,
|
|
"running zebra_checkpoints test, spawning zebrad...",
|
|
);
|
|
|
|
// Sync zebrad to the network chain tip
|
|
let (mut zebrad, zebra_rpc_address) = if let Some(zebrad_and_address) =
|
|
spawn_zebrad_for_rpc(network, test_name, test_type, true)?
|
|
{
|
|
zebrad_and_address
|
|
} else {
|
|
// Skip the test, we don't have the required cached state
|
|
return Ok(());
|
|
};
|
|
|
|
let zebra_rpc_address = zebra_rpc_address.expect("zebra_checkpoints test must have RPC port");
|
|
|
|
tracing::info!(
|
|
?network,
|
|
?zebra_rpc_address,
|
|
"spawned zebrad, waiting for it to load compiled-in checkpoints...",
|
|
);
|
|
|
|
let last_checkpoint = zebrad.expect_stdout_line_matches(CHECKPOINT_VERIFIER_REGEX)?;
|
|
// TODO: do this with a regex?
|
|
let (_prefix, last_checkpoint) = last_checkpoint
|
|
.split_once("max_checkpoint_height")
|
|
.expect("just checked log format");
|
|
let (_prefix, last_checkpoint) = last_checkpoint
|
|
.split_once('(')
|
|
.expect("unexpected log format");
|
|
let (last_checkpoint, _suffix) = last_checkpoint
|
|
.split_once(')')
|
|
.expect("unexpected log format");
|
|
|
|
tracing::info!(
|
|
?network,
|
|
?zebra_rpc_address,
|
|
?last_checkpoint,
|
|
"found zebrad's current last checkpoint",
|
|
);
|
|
|
|
tracing::info!(
|
|
?network,
|
|
?zebra_rpc_address,
|
|
"waiting for zebrad to open its RPC port...",
|
|
);
|
|
zebrad.expect_stdout_line_matches(&format!("Opened RPC endpoint at {zebra_rpc_address}"))?;
|
|
|
|
tracing::info!(
|
|
?network,
|
|
?zebra_rpc_address,
|
|
"zebrad opened its RPC port, waiting for it to sync...",
|
|
);
|
|
|
|
zebrad.expect_stdout_line_matches(SYNC_FINISHED_REGEX)?;
|
|
|
|
let zebra_tip_height = zebrad_tip_height(zebra_rpc_address).await?;
|
|
tracing::info!(
|
|
?network,
|
|
?zebra_rpc_address,
|
|
?zebra_tip_height,
|
|
?last_checkpoint,
|
|
"zebrad synced to the tip, launching zebra-checkpoints...",
|
|
);
|
|
|
|
let zebra_checkpoints =
|
|
spawn_zebra_checkpoints_direct(network, test_type, zebra_rpc_address, last_checkpoint)?;
|
|
|
|
let show_zebrad_logs = env::var(LOG_ZEBRAD_CHECKPOINTS).is_ok();
|
|
if !show_zebrad_logs {
|
|
tracing::info!(
|
|
"zebrad logs are hidden, show them using {LOG_ZEBRAD_CHECKPOINTS}=1 and RUST_LOG=debug"
|
|
);
|
|
}
|
|
|
|
tracing::info!(
|
|
?network,
|
|
?zebra_rpc_address,
|
|
?zebra_tip_height,
|
|
?last_checkpoint,
|
|
"spawned zebra-checkpoints connected to zebrad, checkpoints should appear here...",
|
|
);
|
|
println!("\n\n");
|
|
|
|
let (_zebra_checkpoints, _zebrad) = wait_for_zebra_checkpoints_generation(
|
|
zebra_checkpoints,
|
|
zebrad,
|
|
zebra_tip_height,
|
|
test_type,
|
|
show_zebrad_logs,
|
|
)?;
|
|
|
|
println!("\n\n");
|
|
tracing::info!(
|
|
?network,
|
|
?zebra_tip_height,
|
|
?last_checkpoint,
|
|
"finished generating Zebra checkpoints",
|
|
);
|
|
|
|
Ok(())
|
|
}
|
|
|
|
/// Spawns a `zebra-checkpoints` instance on `network`, connected to `zebrad_rpc_address`.
|
|
///
|
|
/// Returns:
|
|
/// - `Ok(zebra_checkpoints)` on success,
|
|
/// - `Err(_)` if spawning `zebra-checkpoints` fails.
|
|
#[tracing::instrument]
|
|
pub fn spawn_zebra_checkpoints_direct(
|
|
network: Network,
|
|
test_type: TestType,
|
|
zebrad_rpc_address: SocketAddr,
|
|
last_checkpoint: &str,
|
|
) -> Result<TestChild<TempDir>> {
|
|
let zebrad_rpc_address = zebrad_rpc_address.to_string();
|
|
|
|
let arguments = args![
|
|
"--addr": zebrad_rpc_address,
|
|
"--last-checkpoint": last_checkpoint,
|
|
];
|
|
|
|
// TODO: add logs for different kinds of zebra_checkpoints failures
|
|
let zebra_checkpoints_failure_messages = PROCESS_FAILURE_MESSAGES
|
|
.iter()
|
|
.chain(ZEBRA_FAILURE_MESSAGES)
|
|
.chain(ZEBRA_CHECKPOINTS_FAILURE_MESSAGES)
|
|
.cloned();
|
|
let zebra_checkpoints_ignore_messages = NO_MATCHES_REGEX_ITER.iter().cloned();
|
|
|
|
// Currently unused, but we might put a copy of the checkpoints file in it later
|
|
let zebra_checkpoints_dir = testdir()?;
|
|
|
|
let mut zebra_checkpoints = zebra_checkpoints_dir
|
|
.spawn_zebra_checkpoints_child(arguments)?
|
|
.with_timeout(test_type.zebrad_timeout())
|
|
.with_failure_regex_iter(
|
|
zebra_checkpoints_failure_messages,
|
|
zebra_checkpoints_ignore_messages,
|
|
);
|
|
|
|
// zebra-checkpoints logs to stderr when it launches.
|
|
//
|
|
// This log happens very quickly, so it is ok to block for a short while here.
|
|
zebra_checkpoints.expect_stderr_line_matches(regex::escape("calculating checkpoints"))?;
|
|
|
|
Ok(zebra_checkpoints)
|
|
}
|
|
|
|
/// Extension trait for methods on `tempfile::TempDir` for using it as a test
|
|
/// directory for `zebra-checkpoints`.
|
|
pub trait ZebraCheckpointsTestDirExt: ZebradTestDirExt
|
|
where
|
|
Self: AsRef<Path> + Sized,
|
|
{
|
|
/// Spawn `zebra-checkpoints` with `extra_args`, as a child process in this test directory,
|
|
/// potentially taking ownership of the tempdir for the duration of the child process.
|
|
///
|
|
/// By default, launch an instance that connects directly to `zebrad`.
|
|
fn spawn_zebra_checkpoints_child(self, extra_args: Arguments) -> Result<TestChild<Self>>;
|
|
}
|
|
|
|
impl ZebraCheckpointsTestDirExt for TempDir {
|
|
#[allow(clippy::unwrap_in_result)]
|
|
fn spawn_zebra_checkpoints_child(mut self, extra_args: Arguments) -> Result<TestChild<Self>> {
|
|
// By default, launch an instance that connects directly to `zebrad`.
|
|
let mut args = Arguments::new();
|
|
args.set_parameter("--transport", "direct");
|
|
|
|
// Apply user provided arguments
|
|
args.merge_with(extra_args);
|
|
|
|
// Create debugging info
|
|
let temp_dir = self.as_ref().display().to_string();
|
|
|
|
// Try searching the system $PATH first, that's what the test Docker image uses
|
|
let zebra_checkpoints_path = "zebra-checkpoints";
|
|
|
|
// Make sure we have the right zebra-checkpoints binary.
|
|
//
|
|
// When we were creating this test, we spent a lot of time debugging a build issue where
|
|
// `zebra-checkpoints` had an empty `main()` function. This check makes sure that doesn't
|
|
// happen again.
|
|
let debug_checkpoints = env::var(LOG_ZEBRAD_CHECKPOINTS).is_ok();
|
|
if debug_checkpoints {
|
|
let mut args = Arguments::new();
|
|
args.set_argument("--help");
|
|
|
|
let help_dir = testdir()?;
|
|
|
|
tracing::info!(
|
|
?zebra_checkpoints_path,
|
|
?args,
|
|
?help_dir,
|
|
system_path = ?env::var("PATH"),
|
|
// TODO: disable when the tests are working well
|
|
usr_local_zebra_checkpoints_info = ?fs::metadata("/usr/local/bin/zebra-checkpoints"),
|
|
"Trying to launch `zebra-checkpoints --help` by searching system $PATH...",
|
|
);
|
|
|
|
let zebra_checkpoints = help_dir.spawn_child_with_command(zebra_checkpoints_path, args);
|
|
|
|
if let Err(help_error) = zebra_checkpoints {
|
|
tracing::info!(?help_error, "Failed to launch `zebra-checkpoints --help`");
|
|
} else {
|
|
tracing::info!("Launched `zebra-checkpoints --help`, output is:");
|
|
|
|
let mut zebra_checkpoints = zebra_checkpoints.unwrap();
|
|
let mut output_is_empty = true;
|
|
|
|
// Get the help output
|
|
while zebra_checkpoints.wait_for_stdout_line(None) {
|
|
output_is_empty = false;
|
|
}
|
|
while zebra_checkpoints.wait_for_stderr_line(None) {
|
|
output_is_empty = false;
|
|
}
|
|
|
|
if output_is_empty {
|
|
tracing::info!(
|
|
"`zebra-checkpoints --help` did not log any output. \
|
|
Is the binary being built during tests? Are its required-features active?"
|
|
);
|
|
}
|
|
}
|
|
}
|
|
|
|
// Try the `zebra-checkpoints` binary the Docker image copied just after it built the tests.
|
|
tracing::info!(
|
|
?zebra_checkpoints_path,
|
|
?args,
|
|
?temp_dir,
|
|
system_path = ?env::var("PATH"),
|
|
// TODO: disable when the tests are working well
|
|
usr_local_zebra_checkpoints_info = ?fs::metadata("/usr/local/bin/zebra-checkpoints"),
|
|
"Trying to launch zebra-checkpoints by searching system $PATH...",
|
|
);
|
|
|
|
let zebra_checkpoints = self.spawn_child_with_command(zebra_checkpoints_path, args.clone());
|
|
|
|
let Err(system_path_error) = zebra_checkpoints else {
|
|
return zebra_checkpoints;
|
|
};
|
|
|
|
// Fall back to assuming zebra-checkpoints is in the same directory as zebrad.
|
|
let mut zebra_checkpoints_path: PathBuf = env!("CARGO_BIN_EXE_zebrad").into();
|
|
assert!(
|
|
zebra_checkpoints_path.pop(),
|
|
"must have at least one path component",
|
|
);
|
|
zebra_checkpoints_path.push("zebra-checkpoints");
|
|
|
|
if zebra_checkpoints_path.exists() {
|
|
// Create a new temporary directory, because the old one has been used up.
|
|
//
|
|
// TODO: instead, return the TempDir from spawn_child_with_command() on error.
|
|
self = testdir()?;
|
|
|
|
// Create debugging info
|
|
let temp_dir = self.as_ref().display().to_string();
|
|
|
|
tracing::info!(
|
|
?zebra_checkpoints_path,
|
|
?args,
|
|
?temp_dir,
|
|
?system_path_error,
|
|
// TODO: disable when the tests are working well
|
|
zebra_checkpoints_info = ?fs::metadata(&zebra_checkpoints_path),
|
|
"Launching from system $PATH failed, \
|
|
trying to launch zebra-checkpoints from cargo path...",
|
|
);
|
|
|
|
self.spawn_child_with_command(
|
|
zebra_checkpoints_path.to_str().expect(
|
|
"internal test harness error: path is not UTF-8 \
|
|
TODO: change spawn child methods to take &OsStr not &str",
|
|
),
|
|
args,
|
|
)
|
|
} else {
|
|
tracing::info!(
|
|
cargo_path = ?zebra_checkpoints_path,
|
|
?system_path_error,
|
|
// TODO: disable when the tests are working well
|
|
cargo_path_info = ?fs::metadata(&zebra_checkpoints_path),
|
|
"Launching from system $PATH failed, \
|
|
and zebra-checkpoints cargo path does not exist...",
|
|
);
|
|
|
|
// Return the original error
|
|
Err(system_path_error)
|
|
}
|
|
}
|
|
}
|
|
|
|
/// Wait for `zebra-checkpoints` to generate checkpoints, clearing Zebra's logs at the same time.
|
|
#[tracing::instrument]
|
|
pub fn wait_for_zebra_checkpoints_generation<
|
|
P: ZebradTestDirExt + std::fmt::Debug + std::marker::Send + 'static,
|
|
>(
|
|
mut zebra_checkpoints: TestChild<TempDir>,
|
|
mut zebrad: TestChild<P>,
|
|
zebra_tip_height: Height,
|
|
test_type: TestType,
|
|
show_zebrad_logs: bool,
|
|
) -> Result<(TestChild<TempDir>, TestChild<P>)> {
|
|
let last_checkpoint_gap = HeightDiff::try_from(MIN_TRANSPARENT_COINBASE_MATURITY)
|
|
.expect("constant fits in HeightDiff")
|
|
+ HeightDiff::try_from(MAX_CHECKPOINT_HEIGHT_GAP).expect("constant fits in HeightDiff");
|
|
let expected_final_checkpoint_height =
|
|
(zebra_tip_height - last_checkpoint_gap).expect("network tip is high enough");
|
|
|
|
let is_zebra_checkpoints_finished = AtomicBool::new(false);
|
|
let is_zebra_checkpoints_finished = &is_zebra_checkpoints_finished;
|
|
|
|
// Check Zebra's logs for errors.
|
|
//
|
|
// Checkpoint generation can take a long time, so we need to check `zebrad` for errors
|
|
// in parallel.
|
|
let zebrad_mut = &mut zebrad;
|
|
let zebrad_wait_fn = || -> Result<_> {
|
|
tracing::debug!(
|
|
?test_type,
|
|
"zebrad is waiting for zebra-checkpoints to generate checkpoints...",
|
|
);
|
|
while !is_zebra_checkpoints_finished.load(Ordering::SeqCst) {
|
|
// Just keep silently checking the Zebra logs for errors,
|
|
// so the checkpoint list can be copied from the output.
|
|
//
|
|
// Make sure the sync is still finished, this is logged every minute or so.
|
|
if env::var(LOG_ZEBRAD_CHECKPOINTS).is_ok() {
|
|
zebrad_mut.expect_stdout_line_matches(SYNC_FINISHED_REGEX)?;
|
|
} else {
|
|
zebrad_mut.expect_stdout_line_matches_silent(SYNC_FINISHED_REGEX)?;
|
|
}
|
|
}
|
|
|
|
Ok(zebrad_mut)
|
|
};
|
|
|
|
// Wait until `zebra-checkpoints` has generated a full set of checkpoints.
|
|
// Also checks `zebra-checkpoints` logs for errors.
|
|
//
|
|
// Checkpoints generation can take a long time, so we need to run it in parallel with `zebrad`.
|
|
let zebra_checkpoints_mut = &mut zebra_checkpoints;
|
|
let zebra_checkpoints_wait_fn = || -> Result<_> {
|
|
tracing::debug!(
|
|
?test_type,
|
|
"waiting for zebra_checkpoints to generate checkpoints...",
|
|
);
|
|
|
|
// zebra-checkpoints does not log anything when it finishes, it just prints checkpoints.
|
|
//
|
|
// We know that checkpoints are always less than 1000 blocks apart, but they can happen
|
|
// anywhere in that range due to block sizes. So we ignore the last 3 digits of the height.
|
|
let expected_final_checkpoint_prefix = expected_final_checkpoint_height.0 / 1000;
|
|
|
|
// Mainnet and testnet checkpoints always have at least one leading zero in their hash.
|
|
let expected_final_checkpoint =
|
|
format!("{expected_final_checkpoint_prefix}[0-9][0-9][0-9] 0");
|
|
zebra_checkpoints_mut.expect_stdout_line_matches(&expected_final_checkpoint)?;
|
|
|
|
// Write the rest of the checkpoints: there can be 0-2 more checkpoints.
|
|
while zebra_checkpoints_mut.wait_for_stdout_line(None) {}
|
|
|
|
// Tell the other thread that `zebra_checkpoints` has finished
|
|
is_zebra_checkpoints_finished.store(true, Ordering::SeqCst);
|
|
|
|
Ok(zebra_checkpoints_mut)
|
|
};
|
|
|
|
// Run both threads in parallel, automatically propagating any panics to this thread.
|
|
std::thread::scope(|s| {
|
|
// Launch the sync-waiting threads
|
|
let zebrad_thread = s.spawn(|| {
|
|
zebrad_wait_fn().expect("test failed while waiting for zebrad to sync");
|
|
});
|
|
|
|
let zebra_checkpoints_thread = s.spawn(|| {
|
|
let zebra_checkpoints_result = zebra_checkpoints_wait_fn();
|
|
|
|
is_zebra_checkpoints_finished.store(true, Ordering::SeqCst);
|
|
|
|
zebra_checkpoints_result
|
|
.expect("test failed while waiting for zebra_checkpoints to sync.");
|
|
});
|
|
|
|
// Mark the sync-waiting threads as finished if they fail or panic.
|
|
// This tells the other thread that it can exit.
|
|
//
|
|
// TODO: use `panic::catch_unwind()` instead,
|
|
// when `&mut zebra_test::command::TestChild<TempDir>` is unwind-safe
|
|
s.spawn(|| {
|
|
let zebrad_result = zebrad_thread.join();
|
|
zebrad_result.expect("test panicked or failed while waiting for zebrad to sync");
|
|
});
|
|
s.spawn(|| {
|
|
let zebra_checkpoints_result = zebra_checkpoints_thread.join();
|
|
is_zebra_checkpoints_finished.store(true, Ordering::SeqCst);
|
|
|
|
zebra_checkpoints_result
|
|
.expect("test panicked or failed while waiting for zebra_checkpoints to sync");
|
|
});
|
|
});
|
|
|
|
Ok((zebra_checkpoints, zebrad))
|
|
}
|
|
|
|
/// Returns an approximate `zebrad` tip height, using JSON-RPC.
|
|
#[tracing::instrument]
|
|
pub async fn zebrad_tip_height(zebra_rpc_address: SocketAddr) -> Result<Height> {
|
|
let client = RpcRequestClient::new(zebra_rpc_address);
|
|
|
|
let zebrad_blockchain_info = client
|
|
.text_from_call("getblockchaininfo", "[]".to_string())
|
|
.await?;
|
|
let zebrad_blockchain_info: serde_json::Value = serde_json::from_str(&zebrad_blockchain_info)?;
|
|
|
|
let zebrad_tip_height = zebrad_blockchain_info["result"]["blocks"]
|
|
.try_into_height()
|
|
.expect("unexpected block height: invalid Height value");
|
|
|
|
Ok(zebrad_tip_height)
|
|
}
|