From 6f0545dd99788cd8f0f715db78afaeb7baf72b6c Mon Sep 17 00:00:00 2001 From: "Newscape Inc." Date: Sun, 27 Sep 2026 10:17:25 +0300 Subject: [PATCH 1/3] Add per-node log diagnostics to wait_until_all_log's timeout error Temporary debugging aid: restart_recovery's CI failure gives no signal about which stage timed out or what the restarted node last logged. This prints each node's last 10 log lines on timeout so the next CI failure is diagnosable instead of another blind guess. Co-Authored-By: Claude Sonnet 5 --- hn-node/tests/support/mod.rs | 16 +++++++++++++++- 1 file changed, 15 insertions(+), 1 deletion(-) diff --git a/hn-node/tests/support/mod.rs b/hn-node/tests/support/mod.rs index 0b86694..968c9ef 100644 --- a/hn-node/tests/support/mod.rs +++ b/hn-node/tests/support/mod.rs @@ -234,7 +234,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)); } From 6e559b841e031e02f7a6073c0dfd20d92d15b4de Mon Sep 17 00:00:00 2001 From: "Newscape Inc." Date: Sun, 27 Sep 2026 10:26:26 +0300 Subject: [PATCH 2/3] Capture stderr into the same diagnostic log, not discard it The prior diagnostic only showed stdout: one "SYNCED to height=16" line, then total silence for the remaining ~90s. That silence is itself suspicious for a process that should keep casting votes/timing out every ~150ms - and this test harness was throwing away exactly the stream (stderr) a Rust panic message would appear on. Merge stderr lines (tagged) into the same log so the next timeout's diagnostic dump can actually show a panic if that's what's happening. Co-Authored-By: Claude Sonnet 5 --- hn-node/tests/support/mod.rs | 14 ++++++++++---- 1 file changed, 10 insertions(+), 4 deletions(-) diff --git a/hn-node/tests/support/mod.rs b/hn-node/tests/support/mod.rs index 968c9ef..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}")); } }); From 05febab804a9b559ba7694c1b0428d6deba26a62 Mon Sep 17 00:00:00 2001 From: "Newscape Inc." Date: Sun, 27 Sep 2026 10:47:37 +0300 Subject: [PATCH 3/3] Do not exit the whole process on a passive-catchup finalize gap Root cause of both original CI failures (and the debug branch's own reproduction, with stderr now captured): maybe_sync_forward's height jump replaces ConsensusEngine wholesale, discarding any cached proposal. If a QuorumCertificate for the just-jumped-to (height, round) arrives right after, commit_finalized_block correctly rejects it with UnknownProposedBlock (this engine instance never itself saw that block's Proposal) -- but the old code propagated that as a fatal error all the way out of main(), exiting the whole node process (ADR-0038's own "no-panic, exit cleanly on error" discipline, applied to a condition that isn't actually unrecoverable). Real block/state sync (ADR-0016) is still out of scope, so this commit doesn't try to apply that block. Instead: log a SKIPPED line and leave the engine at Finalize for that one height/round. The very same ongoing vote/QC gossip that revealed this gap keeps arriving and triggers the next maybe_sync_forward jump, which replaces the engine wholesale anyway -- self-healing with no new mechanism, matching ADR-0039's own already-acknowledged "round at a time" fallback in spirit. Co-Authored-By: Claude Sonnet 5 --- hn-node/src/lib.rs | 9 ++++++- hn-node/src/node.rs | 58 ++++++++++++++++++++++++++++++++++----------- 2 files changed, 52 insertions(+), 15 deletions(-) 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()?;