From a28eea9bfe4fe091500d4e0da22d9a33f61a446c Mon Sep 17 00:00:00 2001 From: Mehran Mazhar Date: Mon, 14 Sep 2026 17:12:15 +0400 Subject: [PATCH] fix(node): a stalled authoring loop said nothing at all Three stage nodes sat at the same height for hours and produced no log above debug to say so. The first sign of it was the block explorer looking empty, and finding the cause meant reading the authoring loop rather than any log it had written. The per-tick error is rightly debug: the loop ticks every second and fails on most of them by design, because an authority that does not own the current slot cannot author and an idle chain holding this slot's block should not. What was missing is the distinction between failing this tick and having failed every tick for hours. Each authority owns one slot in authorities.len(), so a healthy node authors about every step_duration * len seconds -- 60s for the three-node stage set. Five minutes of continuous failure is a stall, not a quiet period, and it now warns with the actual error: which of the several reasons authoring can fail is the entire question when this fires. Co-Authored-By: Claude Opus 5 --- src/node/node_services.rs | 31 ++++++++++++++++++++++++++++++- 1 file changed, 30 insertions(+), 1 deletion(-) diff --git a/src/node/node_services.rs b/src/node/node_services.rs index 7b4beaf..2bd5c6a 100644 --- a/src/node/node_services.rs +++ b/src/node/node_services.rs @@ -10,7 +10,7 @@ use std::sync::Arc; use std::time::Duration; use tokio::signal; use tokio::sync::{mpsc, oneshot, Mutex}; -use tracing::{debug, error, info}; +use tracing::{debug, error, info, warn}; pub struct NodeServices; @@ -128,11 +128,28 @@ impl NodeServices { ) { tokio::spawn(async move { let mut interval = tokio::time::interval(Duration::from_secs(interval_secs)); + // A stalled chain used to produce NO log at all. This loop ticks every second and + // fails on most of them by design -- an authority that does not own the current slot + // cannot author, and an idle chain already holding this slot's block should not -- + // so the per-tick error is rightly `debug`. The consequence was that three nodes sat + // at the same height for hours with nothing above `debug` to say so, and the first + // sign of it was the block explorer looking empty. + // + // Each authority owns one slot in `authorities.len()`, so on a healthy chain this + // node authors roughly every `step_duration * authorities.len()` seconds -- 60s for + // the three-node stage set. Five minutes of failing every single tick is therefore + // not a quiet period, it is a stall. + let stall_after = Duration::from_secs(300); + let repeat_every = Duration::from_secs(120); + let mut last_success = tokio::time::Instant::now(); + let mut last_warned: Option = None; loop { interval.tick().await; let blockchain = blockchain.lock().await; match blockchain.author_new_block() { Ok(block) => { + last_success = tokio::time::Instant::now(); + last_warned = None; let encoded_block = encode(&block); P2PServer::gossip_message_command( command_tx_p2p.clone(), @@ -143,6 +160,18 @@ impl NodeServices { } Err(e) => { debug!("Error authoring new block: {:?}", e); + let stalled_for = last_success.elapsed(); + let due = last_warned.map_or(true, |w| w.elapsed() >= repeat_every); + if stalled_for >= stall_after && due { + // The error itself, not a generic message: which of the several + // reasons authoring can fail is the whole question when this fires. + warn!( + "authored no block for {}s — last reason: {}", + stalled_for.as_secs(), + e + ); + last_warned = Some(tokio::time::Instant::now()); + } } } }