pub(crate) mod op_ctx_task;
pub(crate) mod pending_broadcast;
pub(crate) mod propagation_stats;
use freenet_stdlib::prelude::*;
pub(crate) use self::messages::{BroadcastStreamingPayload, UpdateMsg, UpdateStreamingPayload};
use super::OpError;
use crate::contract::{ContractHandlerEvent, ExecutorError, StoreResponse};
use crate::message::{NodeEvent, Transaction};
use crate::node::OpManager;
use crate::ring::PeerKeyLocation;
use std::collections::VecDeque;
use std::net::SocketAddr;
use dashmap::DashMap;
use tokio::time::Instant;
pub(crate) struct BroadcastDedupCache {
entries: DashMap<ContractKey, VecDeque<DedupEntry>>,
}
struct DedupEntry {
delta_hash: u64,
inserted_at: Instant,
}
const DEDUP_MAX_ENTRIES_PER_CONTRACT: usize = 64;
const DEDUP_TTL: std::time::Duration = std::time::Duration::from_secs(60);
impl BroadcastDedupCache {
pub fn new() -> Self {
Self {
entries: DashMap::new(),
}
}
pub fn check_and_insert(
&self,
key: &ContractKey,
payload_bytes: &[u8],
is_delta: bool,
now: Instant,
) -> bool {
use ahash::AHasher;
use std::hash::Hasher;
let mut hasher = AHasher::default();
hasher.write_u8(if is_delta { 1 } else { 0 });
hasher.write(payload_bytes);
let delta_hash = hasher.finish();
let mut entry = self.entries.entry(*key).or_default();
let queue = entry.value_mut();
while let Some(front) = queue.front() {
if now.duration_since(front.inserted_at) > DEDUP_TTL {
queue.pop_front();
} else {
break;
}
}
if queue.iter().any(|e| e.delta_hash == delta_hash) {
return true; }
while queue.len() >= DEDUP_MAX_ENTRIES_PER_CONTRACT {
queue.pop_front();
}
queue.push_back(DedupEntry {
delta_hash,
inserted_at: now,
});
false }
}
pub(crate) struct BroadcastTargetResult {
pub targets: Vec<PeerKeyLocation>,
pub proximity_found: usize,
pub proximity_resolve_failed: usize,
pub interest_found: usize,
pub interest_resolve_failed: usize,
pub skipped_self: usize,
pub skipped_sender: usize,
}
pub(crate) struct UpdateExecution {
pub(crate) value: WrappedState,
pub(crate) changed: bool,
}
pub(crate) const CONTRACT_FETCH_COOLDOWN_MS: u64 = 300_000;
#[derive(Debug, Clone, Copy, PartialEq, Eq)]
pub(crate) enum AutoFetchReason {
Originator,
InboundRelay,
}
impl OpManager {
pub(crate) fn try_auto_fetch_contract(
&self,
key: &ContractKey,
sender_addr: SocketAddr,
reason: AutoFetchReason,
) {
use crate::config::GlobalSimulationTime;
let instance_id = *key.id();
if reason == AutoFetchReason::InboundRelay && !self.ring.contract_in_use(key) {
tracing::debug!(
contract = %key,
sender = %sender_addr,
"Skipping inbound-relay auto-fetch: no local client or downstream \
subscriber depends on this contract (phantom interest)"
);
return;
}
let now_ms = GlobalSimulationTime::read_time_ms();
{
use dashmap::mapref::entry::Entry;
match self.pending_contract_fetches.entry(instance_id) {
Entry::Occupied(mut existing) => {
let elapsed_ms = now_ms.saturating_sub(*existing.get());
if elapsed_ms < CONTRACT_FETCH_COOLDOWN_MS {
return; }
*existing.get_mut() = now_ms;
}
Entry::Vacant(slot) => {
slot.insert(now_ms);
}
}
}
let sender_pkl = match self.ring.connection_manager.get_peer_by_addr(sender_addr) {
Some(pkl) => pkl,
None => {
tracing::debug!(
contract = %key,
sender = %sender_addr,
"Cannot auto-fetch: UPDATE sender not found in connection manager"
);
self.pending_contract_fetches.remove(&instance_id);
return;
}
};
tracing::info!(
contract = %key,
sender = %sender_addr,
"Auto-fetching contract from UPDATE sender (missing parameters)"
);
let _tx = super::get::op_ctx_task::start_targeted_sub_op_get(self, instance_id, sender_pkl);
}
pub(crate) fn get_broadcast_targets_update(
&self,
key: &ContractKey,
sender: &SocketAddr,
) -> BroadcastTargetResult {
use std::collections::HashSet;
let self_addr = self.ring.connection_manager.get_own_addr();
let is_local_update_initiator = self_addr.as_ref().map(|me| me == sender).unwrap_or(false);
let mut targets: HashSet<PeerKeyLocation> = HashSet::new();
let mut proximity_resolve_failed: usize = 0;
let mut skipped_self: usize = 0;
let mut skipped_sender: usize = 0;
let proximity_pub_keys = self.neighbor_hosting.neighbors_with_contract(key);
let proximity_found = proximity_pub_keys.len();
for pub_key in proximity_pub_keys {
if let Some(pkl) = self.ring.connection_manager.get_peer_by_pub_key(&pub_key) {
if let Some(pkl_addr) = pkl.socket_addr() {
if &pkl_addr == sender && !is_local_update_initiator {
skipped_sender += 1;
continue;
}
if !is_local_update_initiator && self_addr.as_ref() == Some(&pkl_addr) {
skipped_self += 1;
continue;
}
}
targets.insert(pkl);
} else {
proximity_resolve_failed += 1;
self.neighbor_hosting.on_peer_disconnected(&pub_key);
tracing::debug!(
contract = %format!("{:.8}", key),
proximity_neighbor = %pub_key,
is_local = is_local_update_initiator,
phase = "target_lookup_failed",
"Proximity cache neighbor not found in connection manager; reaped stale entry"
);
}
}
let mut result: Vec<PeerKeyLocation> = targets.into_iter().collect();
result.sort();
if !result.is_empty() {
tracing::debug!(
contract = %format!("{:.8}", key),
peer_addr = %sender,
targets = %result
.iter()
.filter_map(|s| s.socket_addr())
.map(|addr| format!("{:.8}", addr))
.collect::<Vec<_>>()
.join(","),
count = result.len(),
proximity_sources = proximity_found,
phase = "broadcast",
"UPDATE_PROPAGATION"
);
} else {
tracing::debug!(
contract = %format!("{:.8}", key),
peer_addr = %sender,
self_addr = ?self_addr.map(|a| format!("{:.8}", a)),
proximity_sources = proximity_found,
proximity_resolve_failed,
phase = "warning",
"UPDATE_PROPAGATION: NO_TARGETS - update will not propagate further"
);
}
BroadcastTargetResult {
targets: result,
proximity_found,
proximity_resolve_failed,
interest_found: 0,
interest_resolve_failed: 0,
skipped_self,
skipped_sender,
}
}
}
fn log_update_contract_failure(key: &ContractKey, err: &ExecutorError) {
if err.is_invalid_update_rejection() {
tracing::info!(
contract = %key,
error = %err,
event = "merge_rejected_invalid_update",
"Update rejected by contract: incoming state invalid (likely stale rebroadcast), keeping local"
);
} else if err.is_contract_queue_full() {
tracing::debug!(
contract = %key,
error = %err,
event = "queue_full",
"Update skipped: per-contract queue saturated"
);
} else {
tracing::error!(
contract = %key,
error = %err,
phase = "error",
"Failed to update contract value"
);
}
}
pub(crate) fn log_broadcast_to_streaming_failure(
tx: &Transaction,
key: &ContractKey,
err: &OpError,
) -> bool {
if err.is_invalid_update_rejection() {
tracing::info!(
tx = %tx,
%key,
error = %err,
event = "merge_rejected_invalid_update",
"BroadcastToStreaming merge rejected: incoming state invalid (likely stale rebroadcast), keeping local"
);
} else if err.is_contract_queue_full() {
tracing::debug!(
tx = %tx,
%key,
error = %err,
event = "queue_full",
"BroadcastToStreaming update skipped: per-contract queue saturated"
);
} else if err.is_scheduler_timeout() {
tracing::debug!(
tx = %tx,
%key,
error = %err,
event = "scheduler_overloaded",
"BroadcastToStreaming update skipped: execution pool saturated, guest never ran (transient)"
);
} else {
tracing::warn!(
tx = %tx,
%key,
error = %err,
"BroadcastToStreaming update skipped: contract not ready locally"
);
}
!err.is_contract_exec_rejection() && !err.is_contract_queue_full()
}
async fn contract_summary_or_empty(
op_manager: &OpManager,
key: ContractKey,
priority: crate::contract::Priority,
) -> StateSummary<'static> {
match op_manager
.notify_contract_handler_prioritized(
ContractHandlerEvent::GetSummaryQuery { key },
priority,
)
.await
{
Ok(ContractHandlerEvent::GetSummaryResponse {
summary: Ok(summary),
..
}) => summary,
Ok(ContractHandlerEvent::GetSummaryResponse {
summary: Err(err), ..
}) => {
tracing::debug!(
contract = %key,
error = %err,
"client update: summarize failed; returning empty summary"
);
StateSummary::from(Vec::new())
}
other => {
tracing::debug!(
contract = %key,
response = ?other,
"client update: unexpected GetSummaryQuery response; returning empty summary"
);
StateSummary::from(Vec::new())
}
}
}
pub(crate) async fn update_contract(
op_manager: &OpManager,
key: ContractKey,
update_data: UpdateData<'static>,
related_contracts: RelatedContracts<'static>,
priority: crate::contract::Priority,
) -> Result<UpdateExecution, OpError> {
let previous_state = match op_manager
.notify_contract_handler_prioritized(
ContractHandlerEvent::GetQuery {
instance_id: *key.id(),
return_contract_code: false,
},
priority,
)
.await
{
Ok(ContractHandlerEvent::GetResponse {
response: Ok(StoreResponse { state, .. }),
..
}) => state,
Ok(other) => {
tracing::trace!(?other, %key, "Unexpected get response while preparing update summary");
None
}
Err(err) => {
tracing::debug!(%key, %err, "Failed to fetch existing contract state before update");
None
}
};
match op_manager
.notify_contract_handler_prioritized(
ContractHandlerEvent::UpdateQuery {
key,
data: update_data.clone(),
related_contracts,
},
priority,
)
.await
{
Ok(ContractHandlerEvent::UpdateResponse {
new_value: Ok(new_val),
state_changed,
}) => {
debug_assert!(
new_val.size() > 0,
"update_contract: state must be non-empty after successful UPDATE for contract {key}"
);
Ok(UpdateExecution {
value: new_val,
changed: state_changed,
})
}
Ok(ContractHandlerEvent::UpdateResponse {
new_value: Err(err),
..
}) => {
log_update_contract_failure(&key, &err);
Err(err.into())
}
Ok(ContractHandlerEvent::UpdateNoChange { .. }) => {
fn extract_state_from_update_data(
update_data: &UpdateData<'static>,
) -> Option<WrappedState> {
match update_data {
UpdateData::State(s) => Some(WrappedState::from(s.clone().into_bytes())),
UpdateData::StateAndDelta { state, .. }
| UpdateData::RelatedState { state, .. }
| UpdateData::RelatedStateAndDelta { state, .. } => {
Some(WrappedState::from(state.clone().into_bytes()))
}
UpdateData::Delta(_) | UpdateData::RelatedDelta { .. } => None,
_ => None,
}
}
let resolved_state = match previous_state {
Some(prev_state) => prev_state,
None => {
let fetched_state = op_manager
.notify_contract_handler_prioritized(
ContractHandlerEvent::GetQuery {
instance_id: *key.id(),
return_contract_code: false,
},
priority,
)
.await
.ok()
.and_then(|event| match event {
ContractHandlerEvent::GetResponse {
response: Ok(StoreResponse { state, .. }),
..
} => state,
ContractHandlerEvent::DelegateRequest { .. }
| ContractHandlerEvent::DelegateResponse(_)
| ContractHandlerEvent::ExportUserSecrets { .. }
| ContractHandlerEvent::ExportUserSecretsResponse(_)
| ContractHandlerEvent::ImportSecrets { .. }
| ContractHandlerEvent::ImportSecretsResponse(_)
| ContractHandlerEvent::PutQuery { .. }
| ContractHandlerEvent::PutResponse { .. }
| ContractHandlerEvent::GetQuery { .. }
| ContractHandlerEvent::GetResponse { .. }
| ContractHandlerEvent::UpdateQuery { .. }
| ContractHandlerEvent::UpdateResponse { .. }
| ContractHandlerEvent::UpdateNoChange { .. }
| ContractHandlerEvent::RegisterSubscriberListener { .. }
| ContractHandlerEvent::RegisterSubscriberListenerResponse { .. }
| ContractHandlerEvent::QuerySubscriptions { .. }
| ContractHandlerEvent::QuerySubscriptionsResponse
| ContractHandlerEvent::GetSummaryQuery { .. }
| ContractHandlerEvent::GetSummaryResponse { .. }
| ContractHandlerEvent::GetDeltaQuery { .. }
| ContractHandlerEvent::GetDeltaResponse { .. }
| ContractHandlerEvent::ClientDisconnect { .. }
| ContractHandlerEvent::EvictContract { .. } => None,
});
match fetched_state {
Some(state) => state,
None => {
tracing::debug!(
%key,
"Fallback fetch for UpdateNoChange returned no state; trying to extract from update_data"
);
match extract_state_from_update_data(&update_data) {
Some(state) => state,
None => {
tracing::error!(
%key,
"Cannot extract state from delta-only UpdateData in NoChange fallback"
);
return Err(OpError::UnexpectedOpState);
}
}
}
}
}
};
Ok(UpdateExecution {
value: resolved_state,
changed: false,
})
}
Err(err) => Err(err.into()),
Ok(other) => {
tracing::error!(event = ?other, contract = %key, phase = "error", "Unexpected event from contract handler during update");
Err(OpError::UnexpectedOpState)
}
}
}
pub(crate) async fn send_proactive_summary_notification(
op_manager: &OpManager,
key: &ContractKey,
sender_addr: SocketAddr,
) {
use crate::message::{InterestMessage, SummaryEntry};
use crate::ring::interest::contract_hash;
if !op_manager
.interest_manager
.should_send_summary_notification(key)
{
return;
}
let Some(summary) = op_manager
.interest_manager
.get_contract_summary(op_manager, key)
.await
else {
tracing::debug!(
contract = %key,
"Skipping proactive summary notification — no local summary available"
);
return;
};
let hash = contract_hash(key);
let message = InterestMessage::Summaries {
entries: vec![SummaryEntry::from_summary(hash, Some(&summary))],
};
let interested = op_manager.interest_manager.get_interested_peers(key);
let self_addr = op_manager.ring.connection_manager.get_own_addr();
for (peer_key, _interest) in &interested {
let peer_addr = match op_manager
.ring
.connection_manager
.get_peer_by_pub_key(&peer_key.0)
{
Some(pkl) => match pkl.socket_addr() {
Some(addr) => addr,
None => continue,
},
None => continue,
};
if peer_addr == sender_addr {
continue;
}
if self_addr.as_ref() == Some(&peer_addr) {
continue;
}
if let Err(e) = op_manager
.notify_node_event(NodeEvent::SendInterestMessage {
target: peer_addr,
message: message.clone(),
})
.await
{
tracing::debug!(
contract = %key,
peer = %peer_addr,
error = %e,
"Failed to send proactive summary notification"
);
}
}
tracing::debug!(
contract = %key,
peer_count = interested.len(),
"Sent proactive summary notifications after state change"
);
}
pub(crate) async fn send_summary_back_on_rejection(
op_manager: &OpManager,
key: &ContractKey,
target_addr: SocketAddr,
sender_summary_bytes: Vec<u8>,
) {
use crate::message::{InterestMessage, SummaryEntry};
use crate::ring::interest::contract_hash;
if !op_manager
.interest_manager
.should_send_summary_notification(key)
{
return;
}
let Some(our_summary) = op_manager
.interest_manager
.get_contract_summary(op_manager, key)
.await
else {
tracing::debug!(
contract = %key,
peer = %target_addr,
"Skipping summary-back on rejection — no local summary available"
);
return;
};
if our_summary.as_ref() != sender_summary_bytes.as_slice() {
tracing::debug!(
contract = %key,
peer = %target_addr,
"Skipping summary-back on rejection — sender's summary differs \
from ours (peer is genuinely out of sync; heartbeat will converge)"
);
return;
}
let hash = contract_hash(key);
let message = InterestMessage::Summaries {
entries: vec![SummaryEntry::from_summary(hash, Some(&our_summary))],
};
if let Err(e) = op_manager
.notify_node_event(NodeEvent::SendInterestMessage {
target: target_addr,
message,
})
.await
{
tracing::info!(
contract = %key,
peer = %target_addr,
error = %e,
"Failed to send summary-back after broadcast rejection"
);
}
}
mod messages {
use std::fmt::Display;
use freenet_stdlib::prelude::{ContractKey, RelatedContracts, WrappedState};
use serde::{Deserialize, Serialize};
use crate::{
message::{InnerMessage, Transaction},
ring::Location,
transport::peer_connection::StreamId,
};
#[derive(Debug, Serialize, Deserialize)]
pub(crate) struct UpdateStreamingPayload {
#[serde(deserialize_with = "RelatedContracts::deser_related_contracts")]
pub related_contracts: RelatedContracts<'static>,
pub value: WrappedState,
}
#[derive(Debug, Serialize, Deserialize)]
pub(crate) struct BroadcastStreamingPayload {
pub state_bytes: Vec<u8>,
pub sender_summary_bytes: Vec<u8>,
}
#[derive(Debug, Serialize, Deserialize, Clone)]
pub(crate) enum UpdateMsg {
RequestUpdate {
id: Transaction,
key: ContractKey,
#[serde(deserialize_with = "RelatedContracts::deser_related_contracts")]
related_contracts: RelatedContracts<'static>,
value: WrappedState,
},
BroadcastTo {
id: Transaction,
key: ContractKey,
payload: crate::message::DeltaOrFullState,
sender_summary_bytes: Vec<u8>,
},
RequestUpdateStreaming {
id: Transaction,
stream_id: StreamId,
key: ContractKey,
total_size: u64,
},
BroadcastToStreaming {
id: Transaction,
stream_id: StreamId,
key: ContractKey,
total_size: u64,
},
}
impl InnerMessage for UpdateMsg {
fn id(&self) -> &Transaction {
match self {
UpdateMsg::RequestUpdate { id, .. }
| UpdateMsg::BroadcastTo { id, .. }
| UpdateMsg::RequestUpdateStreaming { id, .. }
| UpdateMsg::BroadcastToStreaming { id, .. } => id,
}
}
fn requested_location(&self) -> Option<crate::ring::Location> {
match self {
UpdateMsg::RequestUpdate { key, .. }
| UpdateMsg::BroadcastTo { key, .. }
| UpdateMsg::RequestUpdateStreaming { key, .. }
| UpdateMsg::BroadcastToStreaming { key, .. } => Some(Location::from(key.id())),
}
}
}
impl Display for UpdateMsg {
fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
match self {
UpdateMsg::RequestUpdate { id, .. } => write!(f, "RequestUpdate(id: {id})"),
UpdateMsg::BroadcastTo { id, .. } => write!(f, "BroadcastTo(id: {id})"),
UpdateMsg::RequestUpdateStreaming { id, stream_id, .. } => {
write!(f, "RequestUpdateStreaming(id: {id}, stream: {stream_id})")
}
UpdateMsg::BroadcastToStreaming { id, stream_id, .. } => {
write!(f, "BroadcastToStreaming(id: {id}, stream: {stream_id})")
}
}
}
}
}
#[cfg(test)]
#[allow(clippy::wildcard_enum_match_arm)]
mod tests {
use super::*;
use crate::operations::test_utils::make_contract_key;
#[test]
fn no_targets_propagation_logs_at_debug_pin_test() {
let path =
std::path::Path::new(env!("CARGO_MANIFEST_DIR")).join("src/operations/update.rs");
let source = std::fs::read_to_string(&path)
.unwrap_or_else(|e| panic!("must read own source at {}: {e}", path.display()));
let needle = "UPDATE_PROPAGATION: NO_TARGETS - update will not propagate further";
let idx = source
.find(needle)
.expect("NO_TARGETS log message must still exist in source");
let preceding = &source[..idx];
let macro_idx = preceding
.rfind("tracing::")
.expect("a tracing macro must precede the NO_TARGETS log site");
let line_start = preceding[..macro_idx].rfind('\n').map_or(0, |n| n + 1);
let line_prefix = &preceding[line_start..macro_idx];
assert!(
line_prefix.chars().all(char::is_whitespace),
"rfind matched `tracing::` inside a string literal or comment, \
not a macro invocation. Prefix on its line: {line_prefix:?}"
);
let after_macro = &preceding[macro_idx + "tracing::".len()..];
let macro_name = after_macro.split('!').next().unwrap_or("");
let tail = &preceding[preceding.len().saturating_sub(200)..];
assert_eq!(
macro_name, "debug",
"NO_TARGETS log site must be DEBUG to avoid 4x amplification on retries \
(closest preceding macro is `tracing::{macro_name}!`). \
Re-promotion to WARN/INFO regresses #4251 review M2.\n\
Preceding source (last 200 bytes):\n{tail}"
);
}
#[test]
fn broadcast_propagation_logs_at_debug_pin_test() {
let path =
std::path::Path::new(env!("CARGO_MANIFEST_DIR")).join("src/operations/update.rs");
let source = std::fs::read_to_string(&path)
.unwrap_or_else(|e| panic!("must read own source at {}: {e}", path.display()));
let needle = "phase = \"broadcast\",";
let idx = source
.find(needle)
.expect("UPDATE_PROPAGATION broadcast log site must still exist in source");
let preceding = &source[..idx];
let macro_idx = preceding
.rfind("tracing::")
.expect("a tracing macro must precede the broadcast log site");
let line_start = preceding[..macro_idx].rfind('\n').map_or(0, |n| n + 1);
let line_prefix = &preceding[line_start..macro_idx];
assert!(
line_prefix.chars().all(char::is_whitespace),
"rfind matched `tracing::` inside a string literal or comment, \
not a macro invocation. Prefix on its line: {line_prefix:?}"
);
let after_macro = &preceding[macro_idx + "tracing::".len()..];
let macro_name = after_macro.split('!').next().unwrap_or("");
let tail = &preceding[preceding.len().saturating_sub(200)..];
assert_eq!(
macro_name, "debug",
"UPDATE_PROPAGATION broadcast log site must be DEBUG \
(closest preceding macro is `tracing::{macro_name}!`). \
Re-promotion to INFO/WARN restores the #4251 / #4272 log-volume regression.\n\
Preceding source (last 200 bytes):\n{tail}"
);
}
mod log_severity {
use super::*;
use crate::contract::ExecutorError;
use crate::test_utils::TestLogger;
use freenet_stdlib::client_api::{ContractError as StdContractError, RequestError};
fn invalid_update_rejection() -> ExecutorError {
let req: RequestError = StdContractError::update_exec_error(
make_contract_key(1),
"invalid contract update, reason: New state version 100 must be higher than current version 100",
)
.into();
req.into()
}
fn out_of_gas_failure() -> ExecutorError {
let req: RequestError = StdContractError::update_exec_error(
make_contract_key(1),
"The operation ran out of gas. This might be caused by an infinite loop or an inefficient computation.",
)
.into();
req.into()
}
fn missing_parameters_failure() -> ExecutorError {
let req: RequestError = StdContractError::Update {
key: make_contract_key(2),
cause: "missing contract parameters".into(),
}
.into();
req.into()
}
fn queue_full_failure() -> ExecutorError {
ExecutorError::other(crate::contract::ContractQueueFull)
}
fn scheduler_timeout_failure() -> ExecutorError {
ExecutorError::test_host_scheduler_timeout(make_contract_key(1))
}
#[test]
fn update_contract_failure_logs_info_for_invalid_update_rejection() {
let logger = TestLogger::new().capture_logs().with_level("info").init();
log_update_contract_failure(&make_contract_key(1), &invalid_update_rejection());
assert!(
logger.contains("merge_rejected_invalid_update"),
"expected event=merge_rejected_invalid_update in logs, got: {:?}",
logger.logs()
);
assert!(
logger.contains("INFO"),
"expected INFO-level log for invalid-update rejection, got: {:?}",
logger.logs()
);
assert!(
!logger.logs().iter().any(|l| l.contains("ERROR")),
"invalid-update rejection must not produce ERROR-level logs, got: {:?}",
logger.logs()
);
}
#[test]
fn update_contract_failure_logs_error_for_real_failure() {
let logger = TestLogger::new().capture_logs().with_level("info").init();
log_update_contract_failure(&make_contract_key(2), &missing_parameters_failure());
assert!(
logger.contains("ERROR"),
"real failures must remain ERROR-level, got: {:?}",
logger.logs()
);
assert!(
logger.contains("Failed to update contract value"),
"expected ERROR message text, got: {:?}",
logger.logs()
);
}
#[test]
fn update_contract_failure_logs_error_for_out_of_gas() {
let logger = TestLogger::new().capture_logs().with_level("info").init();
log_update_contract_failure(&make_contract_key(1), &out_of_gas_failure());
assert!(
logger.contains("ERROR"),
"out-of-gas must remain ERROR-level (real WASM fault), got: {:?}",
logger.logs()
);
assert!(
!logger
.logs()
.iter()
.any(|l| l.contains("merge_rejected_invalid_update")),
"out-of-gas must NOT be classified as a benign rejection, got: {:?}",
logger.logs()
);
}
#[test]
fn broadcast_to_streaming_failure_logs_info_and_skips_auto_fetch_for_invalid_update() {
let logger = TestLogger::new().capture_logs().with_level("info").init();
let tx = Transaction::new::<UpdateMsg>();
let err: OpError = invalid_update_rejection().into();
let needs_auto_fetch =
log_broadcast_to_streaming_failure(&tx, &make_contract_key(1), &err);
assert!(
!needs_auto_fetch,
"invalid-update rejection must NOT trigger self-heal auto-fetch (contract code is present)"
);
assert!(
logger.contains("merge_rejected_invalid_update"),
"expected event=merge_rejected_invalid_update in logs, got: {:?}",
logger.logs()
);
assert!(
!logger.logs().iter().any(|l| l.contains("WARN")),
"invalid-update rejection must not produce WARN-level logs (the old misleading 'contract not ready locally' line), got: {:?}",
logger.logs()
);
assert!(
!logger
.logs()
.iter()
.any(|l| l.contains("contract not ready locally")),
"the misleading 'contract not ready locally' message must not appear for invalid-update rejections, got: {:?}",
logger.logs()
);
}
#[test]
fn broadcast_to_streaming_failure_logs_warn_and_triggers_auto_fetch_for_real_failure() {
let logger = TestLogger::new().capture_logs().with_level("info").init();
let tx = Transaction::new::<UpdateMsg>();
let err: OpError = missing_parameters_failure().into();
let needs_auto_fetch =
log_broadcast_to_streaming_failure(&tx, &make_contract_key(2), &err);
assert!(
needs_auto_fetch,
"real failures must trigger self-heal auto-fetch"
);
assert!(
logger.contains("WARN"),
"real failures remain WARN-level for the streaming branch, got: {:?}",
logger.logs()
);
assert!(
logger.contains("contract not ready locally"),
"expected the WARN message text for real failure, got: {:?}",
logger.logs()
);
}
#[test]
fn update_contract_failure_logs_debug_for_queue_full() {
let logger = TestLogger::new().capture_logs().with_level("debug").init();
log_update_contract_failure(&make_contract_key(1), &queue_full_failure());
assert!(
logger.contains("queue_full"),
"queue-full must emit event=queue_full, got: {:?}",
logger.logs()
);
assert!(
!logger.logs().iter().any(|l| l.contains("ERROR")),
"queue-full must NOT log at ERROR (it's transient backpressure, not a fault), got: {:?}",
logger.logs()
);
assert!(
!logger
.logs()
.iter()
.any(|l| l.contains("Failed to update contract value")),
"queue-full must NOT emit the legacy ERROR message, got: {:?}",
logger.logs()
);
}
#[test]
fn broadcast_to_streaming_failure_skips_auto_fetch_and_uses_debug_for_queue_full() {
let logger = TestLogger::new().capture_logs().with_level("debug").init();
let tx = Transaction::new::<UpdateMsg>();
let err: OpError = queue_full_failure().into();
let needs_auto_fetch =
log_broadcast_to_streaming_failure(&tx, &make_contract_key(3), &err);
assert!(
!needs_auto_fetch,
"queue-full MUST NOT trigger self-heal auto-fetch — enqueuing a GET \
onto the saturated handler is exactly the amplification we're \
trying to break (issue #4251)"
);
assert!(
logger.contains("queue_full"),
"queue-full must emit event=queue_full in the streaming branch, got: {:?}",
logger.logs()
);
assert!(
!logger.logs().iter().any(|l| l.contains("WARN")),
"queue-full must NOT log at WARN — a saturated contract would otherwise \
fill operator dashboards with false-alarm WARNs, got: {:?}",
logger.logs()
);
assert!(
!logger
.logs()
.iter()
.any(|l| l.contains("contract not ready locally")),
"the misleading 'contract not ready locally' message must not appear \
for queue-full — the contract IS present, the queue is just busy, \
got: {:?}",
logger.logs()
);
}
#[test]
fn broadcast_to_streaming_failure_skips_auto_fetch_and_uses_debug_for_scheduler_timeout() {
let logger = TestLogger::new().capture_logs().with_level("debug").init();
let tx = Transaction::new::<UpdateMsg>();
let err: OpError = scheduler_timeout_failure().into();
assert!(
err.is_scheduler_timeout(),
"fixture must classify as a scheduler timeout"
);
let needs_auto_fetch =
log_broadcast_to_streaming_failure(&tx, &make_contract_key(1), &err);
assert!(
!needs_auto_fetch,
"scheduler timeout MUST NOT trigger self-heal auto-fetch — the contract \
IS present, the pool was just saturated; enqueuing a GET onto the \
saturated handler is the amplification we avoid"
);
assert!(
logger.contains("scheduler_overloaded"),
"scheduler timeout must emit event=scheduler_overloaded, got: {:?}",
logger.logs()
);
assert!(
!logger.logs().iter().any(|l| l.contains("WARN")),
"scheduler timeout must NOT log at WARN — it fires under exactly the \
saturation it represents, got: {:?}",
logger.logs()
);
assert!(
!logger
.logs()
.iter()
.any(|l| l.contains("contract not ready locally")),
"the misleading 'contract not ready locally' message must not appear \
for a scheduler timeout — the contract IS present, got: {:?}",
logger.logs()
);
}
#[test]
fn broadcast_to_streaming_failure_logs_warn_and_skips_auto_fetch_for_out_of_gas() {
let logger = TestLogger::new().capture_logs().with_level("info").init();
let tx = Transaction::new::<UpdateMsg>();
let err: OpError = out_of_gas_failure().into();
let needs_auto_fetch =
log_broadcast_to_streaming_failure(&tx, &make_contract_key(1), &err);
assert!(
logger.contains("WARN"),
"out-of-gas must remain WARN-level for the streaming branch, got: {:?}",
logger.logs()
);
assert!(
!logger
.logs()
.iter()
.any(|l| l.contains("merge_rejected_invalid_update")),
"out-of-gas must NOT be classified as a benign rejection, got: {:?}",
logger.logs()
);
assert!(
!needs_auto_fetch,
"out-of-gas must NOT trigger self-heal auto-fetch (contract code is present locally; the broader is_contract_exec_rejection predicate catches this case independently of log severity)"
);
}
}
#[test]
fn summary_back_helper_gates_on_summary_equality() {
let src = include_str!("update.rs");
let fn_start = src
.find("pub(crate) async fn send_summary_back_on_rejection(")
.expect("send_summary_back_on_rejection fn not found");
let fn_end_offset = src[fn_start..]
.find("\n}\n")
.expect("send_summary_back_on_rejection fn close not found");
let fn_body = &src[fn_start..fn_start + fn_end_offset];
assert!(
fn_body.contains("sender_summary_bytes"),
"send_summary_back_on_rejection must take sender_summary_bytes \
as a parameter"
);
let throttle_pos = fn_body
.find("should_send_summary_notification")
.expect("helper MUST call should_send_summary_notification (throttle)");
let wasm_call_pos = fn_body
.find("get_contract_summary")
.expect("helper must call get_contract_summary to compute our_summary");
assert!(
throttle_pos < wasm_call_pos,
"should_send_summary_notification MUST run before get_contract_summary \
— otherwise attacker-induced rejections force unbounded WASM amplification"
);
let inequality_check_pos = fn_body
.find("our_summary.as_ref() != sender_summary_bytes.as_slice()")
.expect(
"helper MUST use `our_summary.as_ref() != sender_summary_bytes.as_slice()` \
as the gate condition (reversed direction reintroduces the SyncStateToPeer \
loop — see node.rs:1791-1839)",
);
let after_check = &fn_body[inequality_check_pos..];
let return_pos = after_check.find("return;").expect(
"gate must early-return on inequality (reversed direction would bypass \
the SyncStateToPeer safeguard)",
);
let notify_pos = after_check
.find("notify_node_event")
.expect("helper must still call notify_node_event on the equality path");
assert!(
return_pos < notify_pos,
"early return on inequality MUST precede the notify_node_event \
send — otherwise mismatched summaries would still be transmitted"
);
}
#[test]
fn try_auto_fetch_contract_gates_on_contract_in_use_before_spawn() {
let src = include_str!("update.rs");
let fn_start = src
.find("pub(crate) fn try_auto_fetch_contract(")
.expect("try_auto_fetch_contract not found");
let fn_src = &src[fn_start..];
let gate_pos = fn_src.find("self.ring.contract_in_use(key)").expect(
"try_auto_fetch_contract MUST gate on self.ring.contract_in_use(key) \
so phantom-interest contracts are not auto-fetched (#4473)",
);
let reason_pos = fn_src.find("AutoFetchReason::InboundRelay").expect(
"the contract_in_use gate MUST be conditioned on \
AutoFetchReason::InboundRelay so Originator self-heal bypasses it (#4489)",
);
let return_pos = fn_src[gate_pos..]
.find("return;")
.map(|p| gate_pos + p)
.expect("the contract_in_use gate must early-return when not in use");
let spawn_pos = fn_src
.find("start_targeted_sub_op_get")
.expect("try_auto_fetch_contract must still spawn the sub-op GET on the in-use path");
assert!(
reason_pos < gate_pos,
"the AutoFetchReason::InboundRelay guard MUST precede the \
contract_in_use check, or the gate becomes unconditional and \
re-suppresses the Originator self-heal path (#4489)"
);
assert!(
gate_pos < return_pos && return_pos < spawn_pos,
"the contract_in_use gate + early return MUST precede the \
start_targeted_sub_op_get spawn, or phantom-interest contracts \
regress the #4473 fetch_contract churn"
);
}
#[test]
fn auto_fetch_call_sites_use_correct_reason() {
let driver_src = include_str!("update/op_ctx_task.rs");
let originator_anchor = driver_src
.find("phase = \"auto_fetch_originator\"")
.expect("originator auto-fetch site (auto_fetch_originator phase) not found");
let originator_call = driver_src[originator_anchor..]
.find("try_auto_fetch_contract(")
.map(|p| originator_anchor + p)
.expect("originator site must still call try_auto_fetch_contract");
let originator_reason = driver_src[originator_call..]
.find("AutoFetchReason::")
.map(|p| originator_call + p)
.expect("originator try_auto_fetch_contract call must pass an AutoFetchReason");
assert!(
driver_src[originator_reason..].starts_with("AutoFetchReason::Originator"),
"the auto_fetch_originator site MUST pass AutoFetchReason::Originator \
so a local client's UPDATE self-heal is never gated (#4489)"
);
assert!(
!driver_src.contains("sender_addr, AutoFetchReason::Originator"),
"inbound relay/broadcast auto-fetch sites (keyed on sender_addr) MUST \
use AutoFetchReason::InboundRelay, not Originator, or #4473 regresses"
);
}
const ROOM_STATE_BYTES: usize = 253_200;
const ROOM_SUMMARY_BYTES: usize = 33_800;
#[test]
fn honest_summary_passes_the_delta_gate_where_poisoned_refused() {
use crate::ring::interest::is_delta_efficient;
assert!(
is_delta_efficient(ROOM_SUMMARY_BYTES, ROOM_STATE_BYTES),
"the contract's real summary must pass the delta-efficiency gate"
);
assert!(
!is_delta_efficient(ROOM_STATE_BYTES, ROOM_STATE_BYTES),
"a state-sized 'summary' (the state relabeled) must be refused by \
the gate — this refusal is what forced every broadcast to a \
poisoned peer down the full-state fallback (#4923)"
);
}
async fn build_summary_test_node(
id: &str,
summary_ok: bool,
) -> (
std::sync::Arc<OpManager>,
WrappedState,
StateSummary<'static>,
Box<dyn std::any::Any>,
) {
let config_args = crate::config::ConfigArgs {
id: Some(id.to_string()),
mode: Some(crate::contract::OperationMode::Local),
..Default::default()
};
let node_config =
crate::node::NodeConfig::new(config_args.build().await.expect("build Config"))
.await
.expect("build NodeConfig");
let (notification_rx, notification_tx) = crate::node::event_loop_notification_channel();
let (ops_ch_channel, mut ch_channel, wait_for_event) =
crate::contract::contract_handler_channel();
let connection_manager = crate::ring::ConnectionManager::new(&node_config);
let (result_router_tx, result_router_rx) = tokio::sync::mpsc::channel(100);
let task_monitor = crate::node::background_task_monitor::BackgroundTaskMonitor::new();
let op_manager = std::sync::Arc::new(
OpManager::new(
notification_tx,
ops_ch_channel,
&node_config,
crate::tracing::DynamicRegister::new(vec![]),
connection_manager,
result_router_tx,
&task_monitor,
)
.expect("build OpManager"),
);
op_manager.ring.attach_op_manager(&op_manager);
let merged_state = WrappedState::from(vec![7u8; ROOM_STATE_BYTES]);
let contract_summary = StateSummary::from(vec![9u8; ROOM_SUMMARY_BYTES]);
let handler_state = merged_state.clone();
let handler_summary = contract_summary.clone();
let handler = tokio::spawn(async move {
while let Ok((id, ev, _priority)) = ch_channel.recv_from_sender().await {
let response = match ev {
ContractHandlerEvent::GetQuery { .. } => ContractHandlerEvent::GetResponse {
key: None,
response: Ok(StoreResponse {
state: Some(handler_state.clone()),
contract: None,
}),
},
ContractHandlerEvent::GetSummaryQuery { key } => {
ContractHandlerEvent::GetSummaryResponse {
key,
summary: if summary_ok {
Ok(handler_summary.clone())
} else {
Err(ExecutorError::other(crate::contract::ContractQueueFull))
},
}
}
ContractHandlerEvent::UpdateQuery { .. } => {
ContractHandlerEvent::UpdateResponse {
new_value: Ok(handler_state.clone()),
state_changed: true,
}
}
other => panic!("unexpected handler event: {other:?}"),
};
if ch_channel.send_to_sender(id, response).await.is_err() {
break;
}
}
});
let guard: Box<dyn std::any::Any> = Box::new((
handler,
notification_rx,
result_router_rx,
task_monitor,
wait_for_event,
));
(op_manager, merged_state, contract_summary, guard)
}
#[tokio::test]
async fn client_facing_summary_is_the_contract_summary_not_the_state() {
let (op_manager, merged_state, contract_summary, _guard) =
build_summary_test_node("update-summary-poison-4923", true).await;
let key = make_contract_key(1);
let execution = update_contract(
&op_manager,
key,
UpdateData::Delta(StateDelta::from(vec![1u8, 2, 3])),
RelatedContracts::default(),
crate::contract::Priority::ClientLocal,
)
.await
.expect("update must succeed");
assert!(execution.changed, "stand-in reports a changed state");
let summary =
contract_summary_or_empty(&op_manager, key, crate::contract::Priority::ClientLocal)
.await;
assert_eq!(
summary.as_ref(),
contract_summary.as_ref(),
"the client-facing summary must be the contract's `summarize_state` \
output ({ROOM_SUMMARY_BYTES} bytes), not the merged state \
({ROOM_STATE_BYTES} bytes) relabeled as a summary (#4923)"
);
assert_ne!(
summary.as_ref(),
merged_state.as_ref(),
"the client-facing summary must never equal the state bytes (#4923)"
);
assert!(
crate::ring::interest::is_delta_efficient(
summary.as_ref().len(),
execution.value.size()
),
"the client-facing summary must pass the receiver's \
delta-efficiency gate; got a {}-byte summary for a {}-byte state",
summary.as_ref().len(),
execution.value.size(),
);
}
#[tokio::test]
async fn contract_summary_or_empty_error_path_returns_empty_not_state() {
let (op_manager, merged_state, _contract_summary, _guard) =
build_summary_test_node("update-summary-poison-4923-errpath", false).await;
let key = make_contract_key(1);
let summary =
contract_summary_or_empty(&op_manager, key, crate::contract::Priority::ClientLocal)
.await;
assert!(
summary.as_ref().is_empty(),
"the summarize-failure fallback must be the EMPTY summary, got {} bytes",
summary.as_ref().len()
);
assert_ne!(
summary.as_ref(),
merged_state.as_ref(),
"the fallback must never be the state bytes (#4923)"
);
}
#[test]
fn update_contract_never_builds_a_summary_from_state_bytes() {
let src = include_str!("update.rs");
let uc_start = src
.find("pub(crate) async fn update_contract(")
.expect("update_contract must exist");
let uc_end = src[uc_start..]
.find("\n/// Send proactive summary notifications")
.map(|off| uc_start + off)
.expect("update_contract must be followed by send_proactive_summary_notification");
let uc_body: String = src[uc_start..uc_end].split_whitespace().collect();
assert!(
!uc_body.contains("StateSummary::from("),
"update_contract must not synthesize a StateSummary from bytes it \
has on hand — a state-sized summary poisons every peer's delta \
gate (#4923)"
);
assert!(
!uc_body.contains("contract_summary_or_empty("),
"update_contract must do NO summary work — it runs on the \
relay-broadcast and no-change hot paths; the client driver \
fetches the summary itself (#4923 MAJOR 4)"
);
let h_start = src
.find("async fn contract_summary_or_empty(")
.expect("contract_summary_or_empty must exist");
let h_end = src[h_start..]
.find("\n/// Apply an update to a contract.")
.map(|off| h_start + off)
.expect("contract_summary_or_empty must be followed by update_contract's doc");
let h_body: String = src[h_start..h_end].split_whitespace().collect();
let h_sans_fallback = h_body.replace("StateSummary::from(Vec::new())", "");
assert!(
!h_sans_fallback.contains("StateSummary::from("),
"contract_summary_or_empty may construct a StateSummary ONLY as \
the empty fallback StateSummary::from(Vec::new()) — any other \
construction risks re-introducing state-as-summary (#4923)"
);
let driver_src = include_str!("update/op_ctx_task.rs");
let d_start = driver_src
.find("async fn drive_client_update(")
.expect("drive_client_update must exist");
let d_after = &driver_src[d_start + 1..];
let d_end = d_after
.find("\nasync fn ")
.or_else(|| d_after.find("\nfn "))
.unwrap_or(d_after.len());
let d_body: String = driver_src[d_start..d_start + 1 + d_end]
.split_whitespace()
.collect();
assert!(
d_body.matches("contract_summary_or_empty(").count() >= 2,
"drive_client_update must fetch the client-facing summary via \
contract_summary_or_empty in BOTH arms (local-only and \
remote-forward) — hand-rolled summaries re-open #4923"
);
assert!(
!d_body.contains("StateSummary::from("),
"drive_client_update must never build a StateSummary from bytes \
(#4923)"
);
}
}