diff --git a/hn-node/src/lib.rs b/hn-node/src/lib.rs index 4201aed..cc57903 100644 --- a/hn-node/src/lib.rs +++ b/hn-node/src/lib.rs @@ -48,7 +48,14 @@ //! catches up to the network's real current height by observing //! ordinary gossiped vote/certificate/proposal traffic (ADR-0039, //! "Decided: Passive Height-Observation Catch-Up") — no dedicated sync -//! protocol. +//! protocol. Each such jump starts a fresh `ConsensusEngine` with no +//! cached proposal, so a quorum certificate for a block this node +//! never itself saw `Proposal` for cannot be applied; rather than exit +//! the whole process over that one missed height, [`node::run`] logs +//! and skips it (a `SKIPPED finalizing ...` line), leaving the engine +//! to be replaced wholesale by the next, self-healing catch-up jump — +//! found as a real crash via CI's own multi-node restart-recovery test +//! failing under load (never locally), not a hypothetical. //! //! Explicitly out of scope, named rather than guessed at: any RPC/CLI //! surface, real (non-devnet) validator onboarding and real custody for diff --git a/hn-node/src/node.rs b/hn-node/src/node.rs index bd28ad5..2f75c3e 100644 --- a/hn-node/src/node.rs +++ b/hn-node/src/node.rs @@ -6,7 +6,9 @@ use std::sync::mpsc::{self, Receiver, Sender}; use std::thread; use std::time::Duration; -use hn_consensus::{ConsensusAction, ConsensusEngine, ConsensusTarget, round_proposer}; +use hn_consensus::{ + ConsensusAction, ConsensusEngine, ConsensusError, ConsensusTarget, round_proposer, +}; use hn_core::{BlockHeight, Epoch, ProtocolEpoch, ProtocolVersion, Round, UnixTimeMillis}; use hn_crypto::{Digest, Ed25519KeyPair, KeyRole, SignatureEnvelope, hash_profile_0x0001}; use hn_network::{ @@ -685,19 +687,47 @@ fn act_on(ctx: &mut Ctx, action: ConsensusAction) -> NodeResult<()> { ConsensusAction::Finalized { block_hash, .. } => { let height = ctx.engine.state().height; let round = ctx.engine.state().round; - let result = - ctx.engine - .commit_finalized_block(block_hash, &mut ctx.store, &ctx.records)?; - log_line(&format!( - "FINALIZED height={} round={} block={} applied={}", - height.get(), - round.get(), - hex(&block_hash), - result.applied.len() - )); - ctx.last_block_hash = block_hash; - let action = ctx.engine.begin_new_height()?; - act_on(ctx, action)?; + match ctx + .engine + .commit_finalized_block(block_hash, &mut ctx.store, &ctx.records) + { + Ok(result) => { + log_line(&format!( + "FINALIZED height={} round={} block={} applied={}", + height.get(), + round.get(), + hex(&block_hash), + result.applied.len() + )); + ctx.last_block_hash = block_hash; + let action = ctx.engine.begin_new_height()?; + act_on(ctx, action)?; + } + // A real, already-named race in ADR-0039's own passive + // height-observation catch-up: a jump straight to + // `observed_height` (`maybe_sync_forward`) starts a + // fresh `ConsensusEngine` with no cached proposal, so a + // quorum certificate this node never itself saw + // `Proposal` for (only its votes/QC) cannot be applied + // here -- doing so would need real block/state sync + // (ADR-0016, unchanged), not this pass's scope. Rather + // than exit the whole process over one missed height, + // log and leave the engine at `Finalize` for this + // height/round; the next `maybe_sync_forward` jump + // (driven by the very QC/vote traffic that keeps + // arriving from peers already past this height) already + // replaces the engine wholesale, self-healing past the + // gap without any new mechanism. + Err(ConsensusError::UnknownProposedBlock { block_hash }) => { + log_line(&format!( + "SKIPPED finalizing height={} round={} block={} (no cached proposal -- passive catch-up gap, ADR-0016)", + height.get(), + round.get(), + hex(&block_hash), + )); + } + Err(error) => return Err(error.into()), + } } ConsensusAction::RoundAdvanced { .. } | ConsensusAction::NewHeight { .. } => { let action = ctx.engine.begin_round()?; diff --git a/hn-node/tests/support/mod.rs b/hn-node/tests/support/mod.rs index 0b86694..5ae2b25 100644 --- a/hn-node/tests/support/mod.rs +++ b/hn-node/tests/support/mod.rs @@ -199,13 +199,19 @@ pub fn spawn_node( guard.push(line); } }); - // Drained so the child never blocks on a full stderr pipe; its - // content is not part of any test's assertions. + // Merged into the same log (tagged) rather than discarded: a panic + // message -- the one thing most likely to explain a node that goes + // silent on stdout -- prints to stderr, and `wait_until_all_log`'s + // own timeout diagnostic needs to see it, not just the last stdout + // lines. + let stderr_log = Arc::clone(&log); std::thread::spawn(move || { for line in BufReader::new(stderr).lines() { - if line.is_err() { + let Ok(line) = line else { break }; + let Ok(mut guard) = stderr_log.lock() else { break; - } + }; + guard.push(format!("[stderr] {line}")); } }); @@ -234,7 +240,21 @@ pub fn wait_until_all_log( return Ok(matches); } if Instant::now() >= deadline { - return Err("timed out waiting for all nodes to log a matching line".into()); + let mut diagnostic = + String::from("timed out waiting for all nodes to log a matching line:\n"); + for (index, node) in nodes.iter().enumerate() { + let log = node.log_snapshot()?; + let tail_start = log.len().saturating_sub(10); + diagnostic.push_str(&format!( + " node[{index}] logged {} lines, last {}:\n", + log.len(), + log.len() - tail_start + )); + for line in &log[tail_start..] { + diagnostic.push_str(&format!(" {line}\n")); + } + } + return Err(diagnostic.into()); } std::thread::sleep(Duration::from_millis(50)); }