From 3e478afa5dfb7168bce46a92e4b569137d55a948 Mon Sep 17 00:00:00 2001 From: Alexander Koptelov Date: Wed, 3 Apr 2024 12:24:27 +0300 Subject: [PATCH 1/7] feat(actions): split off logger_effects function --- Cargo.lock | 1 + core/src/log.rs | 65 + core/src/snark/snark_job_commitment.rs | 6 +- node/src/action_kind.rs | 2 +- .../block_producer/block_producer_actions.rs | 30 + .../block_producer_vrf_evaluator_actions.rs | 149 ++ .../external_snark_worker_actions.rs | 31 +- node/src/logger/logger_effects.rs | 1479 +---------------- .../transition_frontier_genesis_actions.rs | 18 + .../sync/transition_frontier_sync_actions.rs | 46 + .../transition_frontier_actions.rs | 22 + .../best_tip/p2p_channels_best_tip_actions.rs | 37 +- p2p/src/channels/p2p_channels_actions.rs | 9 + .../channels/rpc/p2p_channels_rpc_actions.rs | 63 + .../snark/p2p_channels_snark_actions.rs | 67 +- ...p_channels_snark_job_commitment_actions.rs | 50 + .../p2p_connection_incoming_actions.rs | 51 +- .../incoming/p2p_connection_incoming_state.rs | 5 +- p2p/src/connection/mod.rs | 4 +- .../p2p_connection_outgoing_actions.rs | 61 + .../outgoing/p2p_connection_outgoing_state.rs | 7 +- .../p2p_disconnection_actions.rs | 19 + p2p/src/discovery/p2p_discovery_actions.rs | 32 + p2p/src/listen/p2p_listen_actions.rs | 27 + .../p2p_network_kad_bootstrap_actions.rs | 23 + .../network/kad/p2p_network_kad_actions.rs | 55 +- .../p2p_network_kad_request_actions.rs | 55 + .../stream/p2p_network_kad_stream_actions.rs | 119 ++ .../noise/p2p_network_noise_actions.rs | 46 + .../network/pnet/p2p_network_pnet_actions.rs | 20 + .../network/rpc/p2p_network_rpc_actions.rs | 109 ++ .../p2p_network_scheduler_actions.rs | 77 + .../scheduler/p2p_network_scheduler_state.rs | 8 +- .../select/p2p_network_select_actions.rs | 47 + .../yamux/p2p_network_yamux_actions.rs | 45 + p2p/src/peer/p2p_peer_actions.rs | 24 +- snark/Cargo.toml | 1 + snark/src/work_verify/mod.rs | 4 +- .../work_verify/snark_work_verify_actions.rs | 31 +- 39 files changed, 1502 insertions(+), 1443 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 74157e1a73..0013de8bfa 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -5795,6 +5795,7 @@ dependencies = [ "serde_json", "sha2 0.10.8", "strum_macros", + "thiserror", "wasm-bindgen-test", ] diff --git a/core/src/log.rs b/core/src/log.rs index cb1db0d83c..eae4826409 100644 --- a/core/src/log.rs +++ b/core/src/log.rs @@ -73,4 +73,69 @@ macro_rules! error { }; } +pub const ACTION_TRACE_TARGET: &str = "openmina_core::log::action"; + +#[macro_export] +macro_rules! action_event { + ($level:expr, $context:expr, $($tts:tt)*) => { + $crate::log::inner::event!(target: { $crate::log::ACTION_TRACE_TARGET }, $level, time = $context.time(), kind = $context.kind(), node_id = $context.node_id(), $($tts)*) + }; + ($level:expr, $context:expr) => { + $crate::log::inner::event!(target: { $crate::log::ACTION_TRACE_TARGET }, $level, time = $context.time(), kind = $context.kind(), node_id = $context.node_id()) + }; + } + +#[macro_export] +macro_rules! action_warn { + ($context:expr, $($tts:tt)*) => { + $crate::action_event!($crate::log::inner::Level::WARN, $context, $($tts)*) + }; + ($context:expr) => { + $crate::action_event!($crate::log::inner::Level::WARN, $context) + }; +} + +#[macro_export] +macro_rules! action_info { + ($context:expr, $($tts:tt)*) => { + $crate::action_event!($crate::log::inner::Level::INFO, $context, $($tts)*) + }; + ($context:expr) => { + $crate::action_event!($crate::log::inner::Level::INFO, $context) + }; +} + +#[macro_export] +macro_rules! action_debug { + ($context:expr, $($tts:tt)*) => { + $crate::action_event!($crate::log::inner::Level::DEBUG, $context, $($tts)*) + }; + ($context:expr) => { + $crate::action_event!($crate::log::inner::Level::DEBUG, $context) + }; +} + +#[macro_export] +macro_rules! action_trace { + ($context:expr, $($tts:tt)*) => { + $crate::action_event!($crate::log::inner::Level::TRACE, $context, $($tts)*) + }; + ($context:expr) => { + $crate::action_event!($crate::log::inner::Level::TRACE, $context) + }; +} + +pub trait EventContext { + fn timestamp(&self) -> redux::Timestamp; + fn time(&self) -> String; + fn node_id(&self) -> String; + fn kind(&self) -> String; +} + +pub trait ActionEvent { + fn action_event(&self, context: &T) + where + T: EventContext; +} + pub use crate::{debug, error, info, trace, warn}; diff --git a/core/src/snark/snark_job_commitment.rs b/core/src/snark/snark_job_commitment.rs index b071e1d346..ab02ee1154 100644 --- a/core/src/snark/snark_job_commitment.rs +++ b/core/src/snark/snark_job_commitment.rs @@ -10,9 +10,7 @@ use super::SnarkJobId; #[derive(BinProtWrite, BinProtRead, Serialize, Deserialize, Debug, Clone)] pub struct SnarkJobCommitment { - /// Timestamp in milliseconds. - /// TODO(binier): have to use i64, because binprot doesn't support u64. - timestamp: i64, + timestamp: u64, pub job_id: SnarkJobId, pub fee: CurrencyFeeStableV1, pub snarker: NonZeroCurvePoint, @@ -27,7 +25,7 @@ impl SnarkJobCommitment { snarker: NonZeroCurvePoint, ) -> Self { Self { - timestamp: timestamp as i64, + timestamp, job_id, fee, snarker, diff --git a/node/src/action_kind.rs b/node/src/action_kind.rs index 4bad67b933..a9d8eeaf2a 100644 --- a/node/src/action_kind.rs +++ b/node/src/action_kind.rs @@ -1117,7 +1117,7 @@ impl ActionKindGet for P2pNetworkKademliaAction { ActionKind::P2pNetworkKademliaUpdateFindNodeRequest } Self::StartBootstrap { .. } => ActionKind::P2pNetworkKademliaStartBootstrap, - Self::BootstrapFinished { .. } => ActionKind::P2pNetworkKademliaBootstrapFinished, + Self::BootstrapFinished => ActionKind::P2pNetworkKademliaBootstrapFinished, } } } diff --git a/node/src/block_producer/block_producer_actions.rs b/node/src/block_producer/block_producer_actions.rs index 9a04133b04..3c5a1c53a9 100644 --- a/node/src/block_producer/block_producer_actions.rs +++ b/node/src/block_producer/block_producer_actions.rs @@ -1,5 +1,7 @@ use mina_p2p_messages::v2::MinaBaseProofStableV2; use openmina_core::block::ArcBlockWithHash; +use openmina_core::log::ActionEvent; +use openmina_core::{action_info, action_trace}; use serde::{Deserialize, Serialize}; use super::vrf_evaluator::BlockProducerVrfEvaluatorAction; @@ -146,3 +148,31 @@ impl redux::EnablingCondition for BlockProducerAction { } } } + +impl ActionEvent for BlockProducerAction { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + match self { + BlockProducerAction::VrfEvaluator(action) => action.action_event(context), + BlockProducerAction::WonSlot { + won_slot: + BlockProducerWonSlot { + slot_time, + global_slot, + .. + }, + } => action_info!( + context, + summary = "Won slot", + slot = global_slot.slot_number.as_u32(), + slot_time = openmina_core::log::to_rfc_3339(*slot_time) + .unwrap_or_else(|_| "".to_owned()), + current_time = openmina_core::log::to_rfc_3339(context.timestamp()) + .unwrap_or_else(|_| "".to_owned()), + ), + _ => action_trace!(context), + } + } +} diff --git a/node/src/block_producer/vrf_evaluator/block_producer_vrf_evaluator_actions.rs b/node/src/block_producer/vrf_evaluator/block_producer_vrf_evaluator_actions.rs index 58c48e77dd..649d04a09a 100644 --- a/node/src/block_producer/vrf_evaluator/block_producer_vrf_evaluator_actions.rs +++ b/node/src/block_producer/vrf_evaluator/block_producer_vrf_evaluator_actions.rs @@ -5,9 +5,13 @@ use mina_p2p_messages::v2::{ ConsensusProofOfStakeDataEpochDataNextValueVersionedValueStableV1, ConsensusProofOfStakeDataEpochDataStakingValueVersionedValueStableV1, LedgerHash, }; +use openmina_core::action_info; +use openmina_core::action_trace; use openmina_core::block::ArcBlockWithHash; +use openmina_core::log::ActionEvent; use serde::{Deserialize, Serialize}; use vrf::VrfEvaluationOutput; +use vrf::VrfWonSlot; use super::{EpochData, VrfEvaluatorInput}; @@ -217,3 +221,148 @@ impl From for crate::Action { Self::BlockProducer(crate::BlockProducerAction::VrfEvaluator(value)) } } + +impl ActionEvent for BlockProducerVrfEvaluatorAction { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + match self { + BlockProducerVrfEvaluatorAction::EvaluateSlot { vrf_input } => action_info!( + context, + summary = "Vrf Evaluation requested", + input = debug(vrf_input) + ), + BlockProducerVrfEvaluatorAction::ProcessSlotEvaluationSuccess { + vrf_output, .. + } => match vrf_output { + VrfEvaluationOutput::SlotWon(VrfWonSlot { + global_slot, + vrf_output, + .. + }) => action_info!( + context, + summary = "Slot evaluation result - won slot", + global_slot, + vrf_output = display(vrf_output) + ), + VrfEvaluationOutput::SlotLost(_) => { + action_info!(context, summary = "Slot evaluation result - lost slot") + } + }, + BlockProducerVrfEvaluatorAction::InitializeEvaluator { .. } => { + action_trace!(context) + } + BlockProducerVrfEvaluatorAction::FinalizeEvaluatorInitialization { .. } => { + action_info!(context, summary = "Vrf evaluator initilaized") + } + BlockProducerVrfEvaluatorAction::CheckEpochEvaluability { + current_epoch_number, + current_best_tip_slot, + current_best_tip_global_slot, + .. + } => action_info!( + context, + summary = "Checking possible Vrf evaluations", + current_epoch_number, + current_best_tip_slot, + current_best_tip_global_slot + ), + BlockProducerVrfEvaluatorAction::InitializeEpochEvaluation { + current_epoch_number, + current_best_tip_slot, + current_best_tip_global_slot, + .. + } => action_info!( + context, + summary = "Constructing delegator table", /* TODO: check the name*/ + current_epoch_number, + current_best_tip_slot, + current_best_tip_global_slot + ), + BlockProducerVrfEvaluatorAction::BeginDelegatorTableConstruction { + current_epoch_number, + current_best_tip_slot, + current_best_tip_global_slot, + .. + } => action_info!( + context, + summary = "Constructing delegator table", + current_epoch_number, + current_best_tip_slot, + current_best_tip_global_slot + ), + BlockProducerVrfEvaluatorAction::FinalizeDelegatorTableConstruction { + current_epoch_number, + current_best_tip_slot, + current_best_tip_global_slot, + .. + } => action_info!( + context, + summary = "Delegator table constructed", + current_epoch_number, + current_best_tip_slot, + current_best_tip_global_slot + ), + BlockProducerVrfEvaluatorAction::SelectInitialSlot { + current_global_slot, + current_best_tip_height, + .. + } => action_info!( + context, + summary = "Selecting starting slot", + current_global_slot, + current_best_tip_height + ), + BlockProducerVrfEvaluatorAction::BeginEpochEvaluation { + current_epoch_number, + current_best_tip_slot, + current_best_tip_global_slot, + .. + } => action_info!( + context, + summary = "Starting epoch evaluation", + current_epoch_number, + current_best_tip_slot, + current_best_tip_global_slot + ), + BlockProducerVrfEvaluatorAction::RecordLastBlockHeightInEpoch { + epoch_number, + last_block_height, + } => action_info!( + context, + summary = "Saving last block height in epoch", + epoch_number, + last_block_height + ), + BlockProducerVrfEvaluatorAction::ContinueEpochEvaluation { .. } => { + action_trace!(context) + } + BlockProducerVrfEvaluatorAction::FinishEpochEvaluation { + epoch_number, + latest_evaluated_global_slot, + } => action_info!( + context, + summary = "Epoch evaluation finished", + epoch_number, + latest_evaluated_global_slot + ), + BlockProducerVrfEvaluatorAction::WaitForNextEvaluation { + current_epoch_number, + current_best_tip_height, + .. + } => action_info!( + context, + summary = "Waiting for epoch to evaluate", + current_epoch_number, + current_best_tip_height + ), + BlockProducerVrfEvaluatorAction::CheckEpochBounds { .. } => { + action_trace!(context, summary = "Checking epoch bounds") + } + BlockProducerVrfEvaluatorAction::CleanupOldSlots { .. } => { + action_trace!(context, summary = "Cleaning up old won slots") + } + } + } +} diff --git a/node/src/external_snark_worker/external_snark_worker_actions.rs b/node/src/external_snark_worker/external_snark_worker_actions.rs index cca543aa5a..cd27d962ce 100644 --- a/node/src/external_snark_worker/external_snark_worker_actions.rs +++ b/node/src/external_snark_worker/external_snark_worker_actions.rs @@ -1,6 +1,6 @@ use std::time::Duration; -use openmina_core::snark::SnarkJobId; +use openmina_core::{action_debug, log::ActionEvent, snark::SnarkJobId}; use redux::{EnablingCondition, Timestamp}; use serde::{Deserialize, Serialize}; @@ -134,3 +134,32 @@ impl EnablingCondition for ExternalSnarkWorkerAction { } } } + +impl ActionEvent for ExternalSnarkWorkerAction { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + match self { + ExternalSnarkWorkerAction::Start + | ExternalSnarkWorkerAction::Started + | ExternalSnarkWorkerAction::Kill + | ExternalSnarkWorkerAction::Killed + | ExternalSnarkWorkerAction::WorkCancelled + | ExternalSnarkWorkerAction::PruneWork => action_debug!(context), + ExternalSnarkWorkerAction::SubmitWork { job_id, .. } => { + action_debug!(context, job_id = display(job_id)) + } + ExternalSnarkWorkerAction::WorkResult { .. } => action_debug!(context), + ExternalSnarkWorkerAction::CancelWork => todo!(), + ExternalSnarkWorkerAction::WorkError { error } => { + action_debug!(context, error = display(error)) + } + ExternalSnarkWorkerAction::Error { error, .. } => { + action_debug!(context, error = display(error)) + } + ExternalSnarkWorkerAction::StartTimeout { .. } => action_debug!(context), + ExternalSnarkWorkerAction::WorkTimeout { .. } => action_debug!(context), + } + } +} diff --git a/node/src/logger/logger_effects.rs b/node/src/logger/logger_effects.rs index 15d93b5109..8c4cdc7d46 100644 --- a/node/src/logger/logger_effects.rs +++ b/node/src/logger/logger_effects.rs @@ -1,1448 +1,79 @@ -use p2p::P2pNetworkConnectionCloseReason; +use openmina_core::log::{time_to_str, ActionEvent, EventContext}; +use p2p::PeerId; -use crate::block_producer::vrf_evaluator::BlockProducerVrfEvaluatorAction; -use crate::p2p::channels::best_tip::P2pChannelsBestTipAction; -use crate::p2p::channels::rpc::P2pChannelsRpcAction; -use crate::p2p::channels::snark::P2pChannelsSnarkAction; -use crate::p2p::channels::snark_job_commitment::P2pChannelsSnarkJobCommitmentAction; use crate::p2p::channels::P2pChannelsAction; -use crate::p2p::connection::incoming::P2pConnectionIncomingAction; -use crate::p2p::connection::outgoing::P2pConnectionOutgoingAction; use crate::p2p::connection::P2pConnectionAction; -use crate::p2p::disconnection::P2pDisconnectionAction; -use crate::p2p::discovery::P2pDiscoveryAction; -use crate::p2p::network::{ - noise::P2pNetworkNoiseAction, pnet::P2pNetworkPnetAction, rpc::P2pNetworkRpcAction, - scheduler::P2pNetworkSchedulerAction, select::P2pNetworkSelectAction, - yamux::P2pNetworkYamuxAction, P2pNetworkAction, SelectKind, -}; +use crate::p2p::network::P2pNetworkAction; use crate::p2p::P2pAction; -use crate::snark::work_verify::SnarkWorkVerifyAction; use crate::snark::SnarkAction; -use crate::transition_frontier::genesis::TransitionFrontierGenesisAction; -use crate::transition_frontier::sync::TransitionFrontierSyncAction; -use crate::transition_frontier::TransitionFrontierAction; -use crate::{Action, ActionWithMetaRef, BlockProducerAction, Service, Store}; +use crate::{Action, ActionKind, ActionWithMetaRef, Service, Store}; + +struct ActionLoggerContext { + time: redux::Timestamp, + node_id: PeerId, + kind: ActionKind, +} + +impl EventContext for ActionLoggerContext { + fn timestamp(&self) -> redux::Timestamp { + self.time + } + + fn time(&self) -> String { + time_to_str(self.time) + } + + fn node_id(&self) -> String { + self.node_id.to_string() + } + + fn kind(&self) -> String { + self.kind.to_string() + } +} pub fn logger_effects(store: &Store, action: ActionWithMetaRef<'_>) { let (action, meta) = action.split(); - let kind = action.kind(); - - let node_id = store.state().p2p.my_id().to_string(); - // let _guard = openmina_core::log::create_span(&peer_id).entered(); + let context = ActionLoggerContext { + time: meta.time(), + node_id: store.state().p2p.my_id(), + kind: action.kind(), + }; match action { Action::P2p(action) => match action { - P2pAction::Listen(action) => match action { - p2p::listen::P2pListenAction::New { listener_id, addr } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("addr: {addr}"), - addr = addr.to_string(), - listener_id = listener_id.to_string(), - ); - } - p2p::listen::P2pListenAction::Expired { listener_id, addr } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("addr: {addr}"), - addr = addr.to_string(), - listener_id = listener_id.to_string(), - ); - } - p2p::listen::P2pListenAction::Error { listener_id, error } => { - openmina_core::log::warn!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("id: {listener_id}, error: {error}"), - error = error, - listener_id = listener_id.to_string(), - ); - } - p2p::listen::P2pListenAction::Closed { listener_id, error } => { - if let Some(error) = error { - openmina_core::log::warn!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("id: {listener_id}, error: {error}"), - error = error, - listener_id = listener_id.to_string(), - ); - } else { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("id: {listener_id},"), - listener_id = listener_id.to_string(), - ); - } - } - }, + P2pAction::Listen(action) => action.action_event(&context), P2pAction::Connection(action) => match action { - P2pConnectionAction::Outgoing(action) => match action { - P2pConnectionOutgoingAction::RandomInit => {} - P2pConnectionOutgoingAction::Init { opts, .. } => { - let peer_id = opts.peer_id(); - openmina_core::log::info!( - meta.time(); - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string(), - transport = opts.kind(), - ); - } - P2pConnectionOutgoingAction::Reconnect { opts, .. } => { - let peer_id = opts.peer_id(); - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string(), - transport = opts.kind(), - ); - } - P2pConnectionOutgoingAction::OfferSdpCreatePending { .. } => {} - P2pConnectionOutgoingAction::OfferSdpCreateError { peer_id, error } => { - openmina_core::log::warn!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string(), - error = error.clone(), - ); - } - P2pConnectionOutgoingAction::OfferSdpCreateSuccess { peer_id, sdp } => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string(), - sdp = sdp.clone(), - ); - } - P2pConnectionOutgoingAction::OfferReady { peer_id, offer } => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string(), - offer = serde_json::to_string(offer).ok() - ); - } - P2pConnectionOutgoingAction::OfferSendSuccess { peer_id } => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string(), - ); - } - P2pConnectionOutgoingAction::AnswerRecvPending { .. } => {} - P2pConnectionOutgoingAction::AnswerRecvError { peer_id, error } => { - openmina_core::log::warn!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string(), - error = format!("{:?}", error), - ); - } - P2pConnectionOutgoingAction::AnswerRecvSuccess { peer_id, answer } => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string(), - trace_answer = serde_json::to_string(answer).ok() - ); - } - P2pConnectionOutgoingAction::FinalizePending { .. } => {} - P2pConnectionOutgoingAction::FinalizeError { peer_id, error } => { - openmina_core::log::warn!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string(), - error = error.clone(), - ); - } - P2pConnectionOutgoingAction::FinalizeSuccess { peer_id } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string() - ); - } - P2pConnectionOutgoingAction::Timeout { peer_id } => { - openmina_core::log::warn!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string() - ); - } - P2pConnectionOutgoingAction::Error { peer_id, error } => { - openmina_core::log::warn!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string(), - error = format!("{:?}", error), - ); - } - P2pConnectionOutgoingAction::Success { peer_id } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string() - ); - } - }, - P2pConnectionAction::Incoming(action) => match action { - P2pConnectionIncomingAction::Init { opts, .. } => { - let peer_id = opts.peer_id; - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string(), - trace_signaling = format!("{:?}", opts.signaling), - ); - } - P2pConnectionIncomingAction::AnswerSdpCreatePending { .. } => {} - P2pConnectionIncomingAction::AnswerSdpCreateError { peer_id, error } => { - openmina_core::log::warn!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string(), - error = format!("{:?}", error), - ); - } - P2pConnectionIncomingAction::AnswerSdpCreateSuccess { peer_id, sdp } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string(), - trace_sdp = sdp.clone(), - ); - } - P2pConnectionIncomingAction::AnswerReady { peer_id, answer } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string(), - trace_answer = serde_json::to_string(answer).ok() - ); - } - P2pConnectionIncomingAction::AnswerSendSuccess { peer_id } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string(), - ); - } - P2pConnectionIncomingAction::FinalizePending { .. } => {} - P2pConnectionIncomingAction::FinalizeError { peer_id, error } => { - openmina_core::log::warn!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string(), - error = format!("{:?}", error), - ); - } - P2pConnectionIncomingAction::FinalizeSuccess { peer_id } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string(), - ); - } - P2pConnectionIncomingAction::Timeout { peer_id } => { - openmina_core::log::warn!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string(), - ); - } - P2pConnectionIncomingAction::Error { peer_id, error } => { - openmina_core::log::warn!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string(), - error = format!("{:?}", error), - ); - } - P2pConnectionIncomingAction::Success { peer_id } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string(), - ); - } - P2pConnectionIncomingAction::Libp2pReceived { peer_id } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string(), - ); - } - }, - }, - P2pAction::Disconnection(action) => match action { - P2pDisconnectionAction::Init { peer_id, reason } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string(), - reason = format!("{:?}", reason) - ); - } - P2pDisconnectionAction::Finish { peer_id } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string() - ); - } - }, - P2pAction::Discovery(action) => match action { - P2pDiscoveryAction::Init { peer_id } => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string() - ); - } - P2pDiscoveryAction::Success { peer_id, .. } => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string() - ); - } - P2pDiscoveryAction::KademliaBootstrap => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("bootstrap kademlia"), - ); - } - P2pDiscoveryAction::KademliaInit => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("find node"), - ); - } - P2pDiscoveryAction::KademliaAddRoute { peer_id, addresses } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("add route {peer_id} {:?}", addresses.first()), - ); - } - P2pDiscoveryAction::KademliaSuccess { peers } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peers: {:?}", peers), - ); - } - P2pDiscoveryAction::KademliaFailure { description } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("{:?}", description), - ); - } + P2pConnectionAction::Outgoing(action) => action.action_event(&context), + P2pConnectionAction::Incoming(action) => action.action_event(&context), }, + P2pAction::Disconnection(action) => action.action_event(&context), + P2pAction::Discovery(action) => action.action_event(&context), P2pAction::Channels(action) => match action { - P2pChannelsAction::MessageReceived(_) => {} - P2pChannelsAction::BestTip(action) => match action { - P2pChannelsBestTipAction::Init { peer_id } => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string() - ); - } - P2pChannelsBestTipAction::Ready { peer_id } => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string() - ); - } - _ => {} - }, - P2pChannelsAction::Snark(action) => match action { - P2pChannelsSnarkAction::Init { peer_id } => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string() - ); - } - P2pChannelsSnarkAction::Ready { peer_id } => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string() - ); - } - _ => {} - }, - P2pChannelsAction::SnarkJobCommitment(action) => match action { - P2pChannelsSnarkJobCommitmentAction::Init { peer_id } => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {}", peer_id), - peer_id = peer_id.to_string() - ); - } - P2pChannelsSnarkJobCommitmentAction::Ready { peer_id } => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {}", peer_id), - peer_id = peer_id.to_string() - ); - } - _ => {} - }, - P2pChannelsAction::Rpc(action) => match action { - P2pChannelsRpcAction::Init { peer_id } => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string() - ); - } - P2pChannelsRpcAction::Ready { peer_id } => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}"), - peer_id = peer_id.to_string() - ); - } - P2pChannelsRpcAction::RequestSend { - peer_id, - id, - request, - } => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}, rpc_id: {id}, kind: {:?}", request.kind()), - peer_id = peer_id.to_string(), - rpc_id = id.to_string(), - trace_request = serde_json::to_string(request).ok() - ); - } - P2pChannelsRpcAction::ResponseReceived { - peer_id, - id, - response, - } => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("peer_id: {peer_id}, rpc_id: {id}"), - peer_id = peer_id.to_string(), - rpc_id = id.to_string(), - trace_response = serde_json::to_string(response).ok() - ); - } - _ => {} - }, + P2pChannelsAction::MessageReceived(action) => action.action_event(&context), + P2pChannelsAction::BestTip(action) => action.action_event(&context), + P2pChannelsAction::Snark(action) => action.action_event(&context), + P2pChannelsAction::SnarkJobCommitment(action) => action.action_event(&context), + P2pChannelsAction::Rpc(action) => action.action_event(&context), }, - P2pAction::Peer(_) => {} - // TODO: + P2pAction::Peer(action) => action.action_event(&context), P2pAction::Network(action) => match action { - P2pNetworkAction::Scheduler(action) => match action { - P2pNetworkSchedulerAction::InterfaceDetected { ip } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("ip: {}", ip), - ); - } - P2pNetworkSchedulerAction::InterfaceExpired { ip } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("ip: {}", ip), - ); - } - P2pNetworkSchedulerAction::IncomingDidAccept { addr, result } => match result { - Ok(()) => openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - addr = addr.as_ref().unwrap().to_string(), - ), - Err(err) => openmina_core::log::error!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - err = err, - ), - }, - P2pNetworkSchedulerAction::OutgoingDidConnect { addr, result } => { - match result { - Ok(()) => openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - addr = addr.to_string(), - ), - Err(err) => openmina_core::log::warn!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - err = err, - ), - } - } - P2pNetworkSchedulerAction::SelectDone { - addr, - kind: select_kind, - protocol, - incoming, - } if protocol.is_some() => match select_kind { - SelectKind::Authentication => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("authentication on addr: {}", addr), - negotiated = format!("{:?}", protocol), - incoming = incoming, - ) - } - SelectKind::MultiplexingNoPeerId => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("multiplexing on addr: {}", addr), - negotiated = format!("{:?}", protocol), - incoming = incoming, - ) - } - SelectKind::Multiplexing(peer_id) => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("multiplexing on addr: {}", addr), - peer_id = peer_id.to_string(), - negotiated = format!("{:?}", protocol), - incoming = incoming, - ) - } - SelectKind::Stream(peer_id, stream_id) => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("stream on addr: {}", addr), - peer_id = peer_id.to_string(), - stream_id = stream_id, - negotiated = format!("{:?}", protocol), - incoming = incoming, - ) - } - }, - P2pNetworkSchedulerAction::SelectError { - addr, - kind: select_kind, - error, - } => match select_kind { - SelectKind::Authentication => { - openmina_core::log::warn!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - error = error, - summary = format!("failed select authentication on addr {}: {}", addr, error), - ) - } - SelectKind::MultiplexingNoPeerId => { - openmina_core::log::warn!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - error = error, - summary = format!("failed select multiplexing on addr {}: {}", addr, error), - ) - } - SelectKind::Multiplexing(peer_id) => { - openmina_core::log::warn!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - error = error, - summary = format!("failed select multiplexing on addr {}: {}", addr, error), - peer_id = peer_id.to_string(), - ) - } - SelectKind::Stream(peer_id, stream_id) => { - openmina_core::log::warn!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - error = error, - summary = format!("failed select stream on addr {}: {}", addr, error), - peer_id = peer_id.to_string(), - stream_id = stream_id, - ) - } - }, - P2pNetworkSchedulerAction::Disconnect { addr, reason } => { - openmina_core::log::warn!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("disconnecting peer {addr}: {reason}"), - addr = openmina_core::log::inner::field::display(addr), - reason = openmina_core::log::inner::field::display(reason), - ) - } - P2pNetworkSchedulerAction::Error { addr, error } => { - openmina_core::log::warn!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("disconnecting peer {addr}: {error}"), - addr = openmina_core::log::inner::field::display(addr), - error = openmina_core::log::inner::field::display(error), - ) - } - P2pNetworkSchedulerAction::Disconnected { addr, reason } => match reason { - P2pNetworkConnectionCloseReason::Disconnect(reason) => { - openmina_core::log::warn!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("disconnected peer {addr}: {reason}"), - addr = openmina_core::log::inner::field::display(addr), - reason = openmina_core::log::inner::field::display(reason), - ) - } - P2pNetworkConnectionCloseReason::Error(error) => { - openmina_core::log::warn!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("disconnected peer {addr}: {error}"), - addr = openmina_core::log::inner::field::display(addr), - error = openmina_core::log::inner::field::display(error), - ) - } - }, - _ => {} - }, - P2pNetworkAction::Pnet(action) => match action { - P2pNetworkPnetAction::SetupNonce { addr, incoming, .. } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - addr = addr.to_string(), - incoming = incoming, - ) - } - _ => {} - }, - P2pNetworkAction::Select(action) => match action { - P2pNetworkSelectAction::Init { - addr, - kind: select_kind, - incoming, - .. - } => match select_kind { - SelectKind::Authentication => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("authentication on addr: {}", addr), - incoming = incoming, - ) - } - SelectKind::MultiplexingNoPeerId => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("multiplexing on addr: {}", addr), - incoming = incoming, - ) - } - SelectKind::Multiplexing(peer_id) => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("multiplexing on addr: {}", addr), - peer_id = peer_id.to_string(), - incoming = incoming, - ) - } - SelectKind::Stream(peer_id, stream_id) => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("stream on addr: {}", addr), - peer_id = peer_id.to_string(), - stream_id = stream_id, - incoming = incoming, - ) - } - }, - P2pNetworkSelectAction::IncomingToken { - addr, - kind: stream_kind, - token, - } => match stream_kind { - SelectKind::Authentication => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("authentication on addr: {}", addr), - token = format!("{:?}", token), - ) - } - SelectKind::MultiplexingNoPeerId => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("multiplexing on addr: {}", addr), - token = format!("{:?}", token), - ) - } - SelectKind::Multiplexing(peer_id) => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("multiplexing on addr: {}", addr), - peer_id = peer_id.to_string(), - token = format!("{:?}", token), - ) - } - SelectKind::Stream(peer_id, stream_id) => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("stream on addr: {}", addr), - peer_id = peer_id.to_string(), - stream_id = stream_id, - token = format!("{:?}", token), - ) - } - }, - P2pNetworkSelectAction::OutgoingTokens { - addr, - kind: select_kind, - tokens, - } => match select_kind { - SelectKind::Authentication => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("authentication on addr: {}", addr), - tokens = format!("{:?}", tokens), - ) - } - SelectKind::MultiplexingNoPeerId => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("multiplexing on addr: {}", addr), - tokens = format!("{:?}", tokens), - ) - } - SelectKind::Multiplexing(peer_id) => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("multiplexing on addr: {}", addr), - peer_id = peer_id.to_string(), - tokens = format!("{:?}", tokens), - ) - } - SelectKind::Stream(peer_id, stream_id) => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("stream on addr: {}", addr), - peer_id = peer_id.to_string(), - stream_id = stream_id, - tokens = format!("{:?}", tokens), - ) - } - }, - _ => {} - }, - P2pNetworkAction::Noise(action) => match action { - P2pNetworkNoiseAction::Init { addr, incoming, .. } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - addr = addr.to_string(), - incoming = incoming, - ) - } - P2pNetworkNoiseAction::HandshakeDone { - addr, - peer_id, - incoming, - } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - addr = addr.to_string(), - incoming = incoming, - peer_id = peer_id.to_string(), - ) - } - P2pNetworkNoiseAction::IncomingChunk { addr, data } => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - addr = addr.to_string(), - data = format!("{:?}", data), - ) - } - P2pNetworkNoiseAction::OutgoingChunk { addr, data } => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - addr = addr.to_string(), - data = format!("{:?}", data), - ) - } - P2pNetworkNoiseAction::DecryptedData { addr, data, .. } => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - addr = addr.to_string(), - data = format!("{:?}", data), - ) - } - _ => {} - }, - P2pNetworkAction::Yamux(action) => match action { - P2pNetworkYamuxAction::IncomingData { addr, data } => { - openmina_core::log::debug!( - meta.time(); - kind = kind.to_string(), - addr = addr.to_string(), - data = format!("{:?}", data), - ) - } - P2pNetworkYamuxAction::IncomingFrame { addr, frame } => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - addr = addr.to_string(), - frame = format!("{:?}", frame), - ) - } - P2pNetworkYamuxAction::OutgoingFrame { addr, frame } => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - addr = addr.to_string(), - frame = format!("{:?}", frame), - ) - } - _ => {} - }, - P2pNetworkAction::Rpc(action) => match action { - P2pNetworkRpcAction::Init { - addr, - peer_id, - stream_id, - incoming, - } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - addr = addr.to_string(), - peer_id = peer_id.to_string(), - stream_id = stream_id, - incoming = incoming, - ) - } - P2pNetworkRpcAction::IncomingMessage { - addr, - peer_id, - stream_id, - message, - } => { - let msg = match &message { - p2p::RpcMessage::Handshake => "handshake".to_owned(), - p2p::RpcMessage::Heartbeat => "heartbeat".to_owned(), - p2p::RpcMessage::Query { header, .. } => format!("{header:?}"), - p2p::RpcMessage::Response { header, .. } => format!("{header:?}"), - }; - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - addr = addr.to_string(), - peer_id = peer_id.to_string(), - stream_id = stream_id, - msg = msg, - ) - } - _ => {} - }, - P2pNetworkAction::Kad(_) => {} + P2pNetworkAction::Scheduler(action) => action.action_event(&context), + P2pNetworkAction::Pnet(action) => action.action_event(&context), + P2pNetworkAction::Select(action) => action.action_event(&context), + P2pNetworkAction::Noise(action) => action.action_event(&context), + P2pNetworkAction::Yamux(action) => action.action_event(&context), + P2pNetworkAction::Rpc(action) => action.action_event(&context), + P2pNetworkAction::Kad(action) => action.action_event(&context), }, }, - Action::ExternalSnarkWorker(a) => { - use crate::external_snark_worker::ExternalSnarkWorkerAction; - match a { - ExternalSnarkWorkerAction::Start - | ExternalSnarkWorkerAction::Started - | ExternalSnarkWorkerAction::Kill - | ExternalSnarkWorkerAction::Killed - | ExternalSnarkWorkerAction::WorkCancelled - | ExternalSnarkWorkerAction::PruneWork => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - trace_action = serde_json::to_string(&a).ok() - ) - } - ExternalSnarkWorkerAction::SubmitWork { job_id, .. } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - work_id = job_id.to_string(), - ) - } - ExternalSnarkWorkerAction::WorkResult { .. } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - ) - } - ExternalSnarkWorkerAction::CancelWork => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - ) - } - ExternalSnarkWorkerAction::WorkError { error, .. } => { - openmina_core::log::warn!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - error = error.to_string(), - ) - } - ExternalSnarkWorkerAction::Error { error, .. } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - error = error.to_string(), - ) - } - ExternalSnarkWorkerAction::StartTimeout { .. } => { - openmina_core::log::warn!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - ) - } - ExternalSnarkWorkerAction::WorkTimeout { .. } => { - openmina_core::log::warn!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - ) - } - } - } + Action::ExternalSnarkWorker(action) => action.action_event(&context), Action::Snark(a) => match a { - SnarkAction::WorkVerify(a) => match a { - SnarkWorkVerifyAction::Init { - req_id, - batch, - sender, - } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("id: {}, batch size: {}", req_id, batch.len()), - peer_id = sender, - rpc_id = req_id.to_string(), - trace_batch = serde_json::to_string(&batch.iter().map(|v| v.job_id()).collect::>()).ok() - ); - } - SnarkWorkVerifyAction::Error { req_id, .. } => { - let Some(req) = store.state().snark.work_verify.jobs.get(*req_id) else { - return; - }; - openmina_core::log::warn!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("id: {}, batch size: {}", req_id, req.batch().len()), - peer_id = req.sender(), - rpc_id = req_id.to_string(), - trace_batch = serde_json::to_string(&req.batch().iter().map(|v| v.job_id()).collect::>()).ok() - ); - } - SnarkWorkVerifyAction::Success { req_id } => { - let Some(req) = store.state().snark.work_verify.jobs.get(*req_id) else { - return; - }; - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("id: {}, batch size: {}", req_id, req.batch().len()), - peer_id = req.sender(), - rpc_id = req_id.to_string(), - trace_batch = serde_json::to_string(&req.batch().iter().map(|v| v.job_id()).collect::>()).ok() - ); - } - _ => {} - }, - _ => {} - }, - Action::TransitionFrontier(a) => match a { - TransitionFrontierAction::Genesis(a) => match a { - TransitionFrontierGenesisAction::ProvePending => { - openmina_core::log::info!( - meta.time(); - kind = kind.to_string(), - summary = format!("Proving genesis block"), - ); - } - TransitionFrontierGenesisAction::ProveSuccess { .. } => { - openmina_core::log::info!( - meta.time(); - kind = kind.to_string(), - summary = format!("Genesis block proved"), - ); - } - _ => {} - }, - TransitionFrontierAction::GenesisInject => { - let Some(genesis) = store - .state() - .transition_frontier - .genesis - .block_with_real_or_dummy_proof() - else { - return; - }; - openmina_core::log::info!( - meta.time(); - kind = kind.to_string(), - summary = format!("Transition frontier reconstructed genesis ledger({}) and block({})", genesis.snarked_ledger_hash(), genesis.hash()), - genesis_block_hash = genesis.hash().to_string(), - genesis_ledger_hash = genesis.snarked_ledger_hash().to_string(), - ); - } - TransitionFrontierAction::Sync(action) => match action { - TransitionFrontierSyncAction::Init { - best_tip, - root_block, - .. - } => openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = "Transition frontier sync init".to_string(), - block_hash = best_tip.hash.to_string(), - root_block_hash = root_block.hash.to_string(), - ), - TransitionFrontierSyncAction::BestTipUpdate { - best_tip, - root_block, - .. - } => openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = "New best tip received".to_string(), - block_hash = best_tip.hash.to_string(), - root_block_hash = root_block.hash.to_string(), - ), - TransitionFrontierSyncAction::LedgerStakingPending => openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = "Staking ledger sync pending".to_string(), - ), - TransitionFrontierSyncAction::LedgerStakingSuccess => openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = "Staking ledger sync success".to_string(), - ), - TransitionFrontierSyncAction::LedgerNextEpochPending => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = "Next epoch ledger sync pending".to_string(), - ) - } - TransitionFrontierSyncAction::LedgerNextEpochSuccess => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = "Next epoch ledger sync pending".to_string(), - ) - } - TransitionFrontierSyncAction::LedgerRootPending => openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = "Transition frontier root ledger sync pending".to_string(), - ), - TransitionFrontierSyncAction::LedgerRootSuccess => openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = "Transition frontier root ledger sync success".to_string(), - ), - _other => openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - ), - }, - TransitionFrontierAction::Synced { .. } => openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = "Transition frontier synced".to_string(), - ), - }, - Action::BlockProducer(a) => match a { - BlockProducerAction::VrfEvaluator(a) => match a { - BlockProducerVrfEvaluatorAction::ProcessSlotEvaluationSuccess { - vrf_output, - .. - } => match vrf_output { - vrf::VrfEvaluationOutput::SlotWon(won_slot) => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("Slot evaluation result - won slot"), - global_slot = won_slot.global_slot, - vrf_output = won_slot.vrf_output.to_string(), - ) - } - vrf::VrfEvaluationOutput::SlotLost(_) => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("Slot evaluation result - lost slot: {:?}", vrf_output), - ) - } - }, - BlockProducerVrfEvaluatorAction::EvaluateSlot { vrf_input } => { - openmina_core::log::debug!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("Vrf Evaluation requested: {:?}", vrf_input), - ) - } - BlockProducerVrfEvaluatorAction::CheckEpochEvaluability { - current_epoch_number, - current_best_tip_global_slot, - current_best_tip_slot, - .. - } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("Checking possible Vrf evaluations"), - status = store.state().block_producer.vrf_evaluator().unwrap().status.to_string(), // TODO: keep? if yes, no unwrap - status_details = format!("{:?}", store.state().block_producer.vrf_evaluator().unwrap().status), - current_epoch = current_epoch_number, - current_best_tip_global_slot = current_best_tip_global_slot, - current_best_tip_slot = current_best_tip_slot, - ) - } - BlockProducerVrfEvaluatorAction::InitializeEpochEvaluation { - current_epoch_number, - current_best_tip_global_slot, - current_best_tip_slot, - .. - } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("Constructing delegator table"), - status = store.state().block_producer.vrf_evaluator().unwrap().status.to_string(), // TODO: keep? if yes, no unwrap - current_epoch = current_epoch_number, - current_best_tip_global_slot = current_best_tip_global_slot, - current_best_tip_slot = current_best_tip_slot, - ) - } - BlockProducerVrfEvaluatorAction::BeginDelegatorTableConstruction { - current_epoch_number, - current_best_tip_global_slot, - current_best_tip_slot, - .. - } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("Constructing delegator table"), - status = store.state().block_producer.vrf_evaluator().unwrap().status.to_string(), // TODO: keep? if yes, no unwrap - current_epoch = current_epoch_number, - current_best_tip_global_slot = current_best_tip_global_slot, - current_best_tip_slot = current_best_tip_slot, - ) - } - BlockProducerVrfEvaluatorAction::BeginEpochEvaluation { - current_epoch_number, - current_best_tip_global_slot, - current_best_tip_slot, - .. - } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("Starting epoch evaluation"), - status = store.state().block_producer.vrf_evaluator().unwrap().status.to_string(), // TODO: keep? if yes, no unwrap - current_epoch = current_epoch_number, - current_best_tip_global_slot = current_best_tip_global_slot, - current_best_tip_slot = current_best_tip_slot, - ) - } - BlockProducerVrfEvaluatorAction::FinalizeDelegatorTableConstruction { - current_epoch_number, - current_best_tip_global_slot, - current_best_tip_slot, - .. - } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("Delegator table constructed"), - status = store.state().block_producer.vrf_evaluator().unwrap().status.to_string(), // TODO: keep? if yes, no unwrap - current_epoch = current_epoch_number, - current_best_tip_global_slot = current_best_tip_global_slot, - current_best_tip_slot = current_best_tip_slot, - ) - } - BlockProducerVrfEvaluatorAction::RecordLastBlockHeightInEpoch { - epoch_number, - last_block_height, - .. - } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("Saving last block height in epoch"), - status = store.state().block_producer.vrf_evaluator().unwrap().status.to_string(), // TODO: keep? if yes, no unwrap - epoch = epoch_number, - last_block_height = last_block_height, - ) - } - BlockProducerVrfEvaluatorAction::InitializeEvaluator { .. } => {} - BlockProducerVrfEvaluatorAction::FinalizeEvaluatorInitialization { .. } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("Vrf evaluator initilaized"), - ) - } - BlockProducerVrfEvaluatorAction::FinishEpochEvaluation { - epoch_number, - latest_evaluated_global_slot, - } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("Epoch evaluation finished"), - epoch_number = epoch_number, - latest_evaluated_global_slot = latest_evaluated_global_slot, - ) - } - BlockProducerVrfEvaluatorAction::WaitForNextEvaluation { - current_epoch_number, - current_best_tip_height, - .. - } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("Waiting for epoch to evaluate"), - epoch_number = current_epoch_number, - current_best_tip_height = current_best_tip_height, - ) - } - BlockProducerVrfEvaluatorAction::SelectInitialSlot { - current_epoch_number, - current_best_tip_height, - .. - } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("Selecting starting slot"), - epoch_number = current_epoch_number, - current_best_tip_height = current_best_tip_height, - ) - } - BlockProducerVrfEvaluatorAction::CheckEpochBounds { .. } => { - openmina_core::log::trace!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("Checking epoch bounds"), - status = format!("{:?}", store.state().block_producer.vrf_evaluator().unwrap().status), - ) - } - BlockProducerVrfEvaluatorAction::CleanupOldSlots { .. } => { - openmina_core::log::trace!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("Cleaning up old won slots"), - ) - } - _ => {} - }, - BlockProducerAction::BestTipUpdate { .. } => {} - BlockProducerAction::WonSlot { won_slot } => { - openmina_core::log::info!( - meta.time(); - node_id = node_id, - kind = kind.to_string(), - summary = format!("Won slot"), - slot = won_slot.global_slot.slot_number.as_u32(), - slot_time = openmina_core::log::to_rfc_3339(won_slot.slot_time).unwrap(), - current_time = openmina_core::log::to_rfc_3339(meta.time()).unwrap(), - ) - } + SnarkAction::WorkVerify(a) => a.action_event(&context), _ => {} }, + Action::TransitionFrontier(a) => a.action_event(&context), + Action::BlockProducer(a) => a.action_event(&context), _ => {} } } diff --git a/node/src/transition_frontier/genesis/transition_frontier_genesis_actions.rs b/node/src/transition_frontier/genesis/transition_frontier_genesis_actions.rs index dedba3702e..a3a1bb1f59 100644 --- a/node/src/transition_frontier/genesis/transition_frontier_genesis_actions.rs +++ b/node/src/transition_frontier/genesis/transition_frontier_genesis_actions.rs @@ -1,4 +1,5 @@ use mina_p2p_messages::v2; +use openmina_core::{action_info, action_trace, log::ActionEvent}; use serde::{Deserialize, Serialize}; use super::{GenesisConfigLoaded, TransitionFrontierGenesisState}; @@ -67,3 +68,20 @@ impl From for crate::Action { crate::transition_frontier::TransitionFrontierAction::Genesis(value).into() } } + +impl ActionEvent for TransitionFrontierGenesisAction { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + match self { + TransitionFrontierGenesisAction::ProvePending => { + action_info!(context, summary = "Genesis block proved") + } + TransitionFrontierGenesisAction::ProveSuccess { .. } => { + action_info!(context, summary = "Genesis block proved") + } + _ => action_trace!(context), + } + } +} diff --git a/node/src/transition_frontier/sync/transition_frontier_sync_actions.rs b/node/src/transition_frontier/sync/transition_frontier_sync_actions.rs index 6e8764dfc2..dcbae30ad3 100644 --- a/node/src/transition_frontier/sync/transition_frontier_sync_actions.rs +++ b/node/src/transition_frontier/sync/transition_frontier_sync_actions.rs @@ -1,6 +1,8 @@ use mina_p2p_messages::v2::StateHash; use openmina_core::block::ArcBlockWithHash; use openmina_core::consensus::consensus_take; +use openmina_core::log::ActionEvent; +use openmina_core::{action_debug, action_info}; use serde::{Deserialize, Serialize}; use crate::p2p::channels::rpc::P2pRpcId; @@ -312,3 +314,47 @@ impl From for crate::Action { Self::TransitionFrontier(TransitionFrontierAction::Sync(value)) } } + +impl ActionEvent for TransitionFrontierSyncAction { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + match self { + TransitionFrontierSyncAction::Init { + best_tip, + root_block, + .. + } => action_info!( + context, + block_hash = display(&best_tip.hash), + root_block_hash = display(&root_block.hash), + summary = "Transition frontier sync init" + ), + TransitionFrontierSyncAction::BestTipUpdate { .. } => { + action_info!(context, summary = "New best tip received") + } + TransitionFrontierSyncAction::LedgerStakingPending => { + action_info!(context, summary = "Staking ledger sync pending") + } + TransitionFrontierSyncAction::LedgerStakingSuccess => { + action_info!(context, summary = "Staking ledger sync success") + } + TransitionFrontierSyncAction::LedgerNextEpochPending => { + action_info!(context, summary = "Next epoch ledger sync pending") + } + TransitionFrontierSyncAction::LedgerNextEpochSuccess => { + action_info!(context, summary = "Next epoch ledger sync success") + } + TransitionFrontierSyncAction::LedgerRootPending => action_info!( + context, + summary = "Transition frontier root ledger sync pending" + ), + TransitionFrontierSyncAction::LedgerRootSuccess => action_info!( + context, + summary = "Transition frontier root ledger sync success" + ), + _ => action_debug!(context), + } + } +} diff --git a/node/src/transition_frontier/transition_frontier_actions.rs b/node/src/transition_frontier/transition_frontier_actions.rs index 34bb81634b..7ba22d82dd 100644 --- a/node/src/transition_frontier/transition_frontier_actions.rs +++ b/node/src/transition_frontier/transition_frontier_actions.rs @@ -1,6 +1,8 @@ use std::collections::BTreeSet; use mina_p2p_messages::v2::StateHash; +use openmina_core::action_info; +use openmina_core::log::ActionEvent; use serde::{Deserialize, Serialize}; use super::genesis::TransitionFrontierGenesisAction; @@ -50,3 +52,23 @@ impl redux::EnablingCondition for TransitionFrontierAction { } } } + +impl ActionEvent for TransitionFrontierAction { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + match self { + TransitionFrontierAction::Genesis(action) => action.action_event(context), + TransitionFrontierAction::GenesisInject => action_info!( + context, + summary = "Transition frontier reconstructed genesis ledger and block", + // TODO: fetch more fields from the state + ), + TransitionFrontierAction::Sync(action) => action.action_event(context), + TransitionFrontierAction::Synced { .. } => { + action_info!(context, summary = "Transition frontier synced") + } + } + } +} diff --git a/p2p/src/channels/best_tip/p2p_channels_best_tip_actions.rs b/p2p/src/channels/best_tip/p2p_channels_best_tip_actions.rs index a6fa853a5a..a67d756fe1 100644 --- a/p2p/src/channels/best_tip/p2p_channels_best_tip_actions.rs +++ b/p2p/src/channels/best_tip/p2p_channels_best_tip_actions.rs @@ -1,4 +1,4 @@ -use openmina_core::block::ArcBlockWithHash; +use openmina_core::{action_debug, block::ArcBlockWithHash, log::ActionEvent}; use serde::{Deserialize, Serialize}; use crate::{ @@ -130,3 +130,38 @@ impl From for crate::P2pAction { Self::Channels(P2pChannelsAction::BestTip(action)) } } + +impl ActionEvent for P2pChannelsBestTipAction { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + match self { + P2pChannelsBestTipAction::Init { peer_id } => { + action_debug!(context, peer_id = display(peer_id)) + } + P2pChannelsBestTipAction::Pending { peer_id } => { + action_debug!(context, peer_id = display(peer_id)) + } + P2pChannelsBestTipAction::Ready { peer_id } => { + action_debug!(context, peer_id = display(peer_id)) + } + P2pChannelsBestTipAction::RequestSend { peer_id } => { + action_debug!(context, peer_id = display(peer_id)) + } + P2pChannelsBestTipAction::Received { peer_id, best_tip } => action_debug!( + context, + peer_id = display(peer_id), + best_tip = display(&best_tip.hash) + ), + P2pChannelsBestTipAction::RequestReceived { peer_id } => { + action_debug!(context, peer_id = display(peer_id)) + } + P2pChannelsBestTipAction::ResponseSend { peer_id, best_tip } => action_debug!( + context, + peer_id = display(peer_id), + best_tip = display(&best_tip.hash) + ), + } + } +} diff --git a/p2p/src/channels/p2p_channels_actions.rs b/p2p/src/channels/p2p_channels_actions.rs index 7f436a7135..3f5fa5b206 100644 --- a/p2p/src/channels/p2p_channels_actions.rs +++ b/p2p/src/channels/p2p_channels_actions.rs @@ -1,3 +1,4 @@ +use openmina_core::log::ActionEvent; use serde::{Deserialize, Serialize}; use crate::{P2pState, PeerId}; @@ -50,3 +51,11 @@ impl From for crate::P2pAction { Self::Channels(P2pChannelsAction::MessageReceived(a)) } } + +impl ActionEvent for P2pChannelsMessageReceivedAction { + fn action_event(&self, _context: &T) + where + T: openmina_core::log::EventContext, + { + } +} diff --git a/p2p/src/channels/rpc/p2p_channels_rpc_actions.rs b/p2p/src/channels/rpc/p2p_channels_rpc_actions.rs index e3767aba1b..8dbd1c83d1 100644 --- a/p2p/src/channels/rpc/p2p_channels_rpc_actions.rs +++ b/p2p/src/channels/rpc/p2p_channels_rpc_actions.rs @@ -1,3 +1,4 @@ +use openmina_core::{action_debug, action_trace, log::ActionEvent}; use redux::Timestamp; use serde::{Deserialize, Serialize}; @@ -170,3 +171,65 @@ impl From for crate::P2pAction { Self::Channels(P2pChannelsAction::Rpc(a)) } } + +impl ActionEvent for P2pChannelsRpcAction { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + match self { + P2pChannelsRpcAction::Init { peer_id } => { + action_debug!(context, peer_id = display(peer_id)) + } + P2pChannelsRpcAction::Pending { peer_id } => { + action_trace!(context, peer_id = display(peer_id)) + } + P2pChannelsRpcAction::Ready { peer_id } => { + action_debug!(context, peer_id = display(peer_id)) + } + P2pChannelsRpcAction::RequestSend { + peer_id, + id, + request, + } => action_debug!( + context, + peer_id = display(peer_id), + id, + request = debug(request) + ), + P2pChannelsRpcAction::Timeout { peer_id, id } => { + action_debug!(context, peer_id = display(peer_id), id) + } + P2pChannelsRpcAction::ResponseReceived { + peer_id, + id, + response, + } => action_debug!( + context, + peer_id = display(peer_id), + id, + response = debug(response) + ), + P2pChannelsRpcAction::RequestReceived { + peer_id, + id, + request, + } => action_debug!( + context, + peer_id = display(peer_id), + id, + request = debug(request) + ), + P2pChannelsRpcAction::ResponseSend { + peer_id, + id, + response, + } => action_debug!( + context, + peer_id = display(peer_id), + id, + response = debug(response) + ), + } + } +} diff --git a/p2p/src/channels/snark/p2p_channels_snark_actions.rs b/p2p/src/channels/snark/p2p_channels_snark_actions.rs index 641f49de67..0963a31048 100644 --- a/p2p/src/channels/snark/p2p_channels_snark_actions.rs +++ b/p2p/src/channels/snark/p2p_channels_snark_actions.rs @@ -1,5 +1,5 @@ use crate::{channels::P2pChannelsAction, P2pState, PeerId}; -use openmina_core::snark::Snark; +use openmina_core::{action_debug, action_trace, log::ActionEvent, snark::Snark}; use serde::{Deserialize, Serialize}; use super::{P2pChannelsSnarkState, SnarkInfo, SnarkPropagationState}; @@ -179,3 +179,68 @@ impl From for crate::P2pAction { Self::Channels(P2pChannelsAction::Snark(action)) } } + +impl ActionEvent for P2pChannelsSnarkAction { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + match self { + P2pChannelsSnarkAction::Init { peer_id } => { + action_debug!(context, peer_id = display(peer_id)) + } + P2pChannelsSnarkAction::Pending { peer_id } => { + action_trace!(context, peer_id = display(peer_id)) + } + P2pChannelsSnarkAction::Ready { peer_id } => { + action_debug!(context, peer_id = display(peer_id)) + } + P2pChannelsSnarkAction::RequestSend { peer_id, limit } => { + action_trace!(context, peer_id = display(peer_id), limit) + } + P2pChannelsSnarkAction::PromiseReceived { + peer_id, + promised_count, + } => action_trace!(context, peer_id = display(peer_id), promised_count), + P2pChannelsSnarkAction::Received { peer_id, snark } => action_trace!( + context, + peer_id = display(peer_id), + snark.job_id = display(&snark.job_id), + snark.fee = debug(&snark.fee), + snark.prover = display(&snark.prover), + ), + P2pChannelsSnarkAction::RequestReceived { peer_id, limit } => { + action_trace!(context, peer_id = display(peer_id), limit) + } + P2pChannelsSnarkAction::ResponseSend { + peer_id, + snarks, + first_index, + last_index, + } => action_trace!( + context, + peer_id = display(peer_id), + snarks = debug(snarks), + first_index, + last_index + ), + P2pChannelsSnarkAction::Libp2pReceived { + peer_id, + snark, + nonce, + } => action_trace!( + context, + peer_id = display(peer_id), + snark.snarker = display(&snark.snarker), + snark.fee = debug(&snark.fee), + nonce + ), + P2pChannelsSnarkAction::Libp2pBroadcast { snark, nonce } => action_trace!( + context, + snark.snarker = display(&snark.snarker), + snark.fee = debug(&snark.fee), + nonce + ), + } + } +} diff --git a/p2p/src/channels/snark_job_commitment/p2p_channels_snark_job_commitment_actions.rs b/p2p/src/channels/snark_job_commitment/p2p_channels_snark_job_commitment_actions.rs index ad51f894c5..b211ffb78d 100644 --- a/p2p/src/channels/snark_job_commitment/p2p_channels_snark_job_commitment_actions.rs +++ b/p2p/src/channels/snark_job_commitment/p2p_channels_snark_job_commitment_actions.rs @@ -1,3 +1,4 @@ +use openmina_core::{action_debug, action_trace, log::ActionEvent}; use serde::{Deserialize, Serialize}; use crate::{P2pState, PeerId}; @@ -177,3 +178,52 @@ impl From for crate::P2pAction { Self::Channels(P2pChannelsAction::SnarkJobCommitment(action)) } } + +impl ActionEvent for P2pChannelsSnarkJobCommitmentAction { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + match self { + P2pChannelsSnarkJobCommitmentAction::Init { peer_id } => { + action_debug!(context, peer_id = display(peer_id)) + } + P2pChannelsSnarkJobCommitmentAction::Pending { peer_id } => { + action_trace!(context, peer_id = display(peer_id)) + } + P2pChannelsSnarkJobCommitmentAction::Ready { peer_id } => { + action_debug!(context, peer_id = display(peer_id)) + } + P2pChannelsSnarkJobCommitmentAction::RequestSend { peer_id, limit } => { + action_trace!(context, peer_id = display(peer_id), limit) + } + P2pChannelsSnarkJobCommitmentAction::PromiseReceived { + peer_id, + promised_count, + } => action_trace!(context, peer_id = display(peer_id), promised_count), + P2pChannelsSnarkJobCommitmentAction::Received { + peer_id, + commitment, + } => action_trace!( + context, + peer_id = display(peer_id), + commitment = debug(commitment) + ), + P2pChannelsSnarkJobCommitmentAction::RequestReceived { peer_id, limit } => { + action_trace!(context, peer_id = display(peer_id), limit) + } + P2pChannelsSnarkJobCommitmentAction::ResponseSend { + peer_id, + commitments, + first_index, + last_index, + } => action_trace!( + context, + peer_id = display(peer_id), + commitments = debug(commitments), + first_index, + last_index + ), + } + } +} diff --git a/p2p/src/connection/incoming/p2p_connection_incoming_actions.rs b/p2p/src/connection/incoming/p2p_connection_incoming_actions.rs index 198380a360..d76b79edef 100644 --- a/p2p/src/connection/incoming/p2p_connection_incoming_actions.rs +++ b/p2p/src/connection/incoming/p2p_connection_incoming_actions.rs @@ -1,6 +1,6 @@ use serde::{Deserialize, Serialize}; -use openmina_core::requests::RpcId; +use openmina_core::{action_debug, action_info, action_warn, log::ActionEvent, requests::RpcId}; use crate::{webrtc, P2pAction, P2pState, PeerId}; @@ -209,3 +209,52 @@ impl From for P2pAction { Self::Connection(P2pConnectionAction::Incoming(a)) } } + +impl ActionEvent for P2pConnectionIncomingAction { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + match self { + P2pConnectionIncomingAction::Init { opts, .. } => { + action_debug!(context, opts = debug(opts)) + } + P2pConnectionIncomingAction::AnswerSdpCreatePending { peer_id } => { + action_debug!(context, peer_id = display(peer_id)) + } + P2pConnectionIncomingAction::AnswerSdpCreateError { peer_id, error } => { + action_debug!(context, peer_id = display(peer_id), error) + } + P2pConnectionIncomingAction::AnswerSdpCreateSuccess { peer_id, sdp } => { + action_debug!(context, peer_id = display(peer_id), sdp) + } + P2pConnectionIncomingAction::AnswerReady { peer_id, answer } => { + action_debug!(context, peer_id = display(peer_id), answer = debug(answer)) + } + P2pConnectionIncomingAction::AnswerSendSuccess { peer_id } => { + action_debug!(context, peer_id = display(peer_id)) + } + P2pConnectionIncomingAction::FinalizePending { peer_id } => { + action_debug!(context, peer_id = display(peer_id)) + } + P2pConnectionIncomingAction::FinalizeError { peer_id, error } => { + action_debug!(context, peer_id = display(peer_id), error) + } + P2pConnectionIncomingAction::FinalizeSuccess { peer_id } => { + action_debug!(context, peer_id = display(peer_id)) + } + P2pConnectionIncomingAction::Timeout { peer_id } => { + action_debug!(context, peer_id = display(peer_id)) + } + P2pConnectionIncomingAction::Error { peer_id, error } => { + action_warn!(context, peer_id = display(peer_id), error = display(error)) + } + P2pConnectionIncomingAction::Success { peer_id } => { + action_info!(context, peer_id = display(peer_id)) + } + P2pConnectionIncomingAction::Libp2pReceived { peer_id } => { + action_debug!(context, peer_id = display(peer_id)) + } + } + } +} diff --git a/p2p/src/connection/incoming/p2p_connection_incoming_state.rs b/p2p/src/connection/incoming/p2p_connection_incoming_state.rs index 14ae5c3454..52dac1f982 100644 --- a/p2p/src/connection/incoming/p2p_connection_incoming_state.rs +++ b/p2p/src/connection/incoming/p2p_connection_incoming_state.rs @@ -113,9 +113,12 @@ impl P2pConnectionIncomingState { } } -#[derive(Serialize, Deserialize, Debug, Clone)] +#[derive(Serialize, Deserialize, Debug, Clone, thiserror::Error)] pub enum P2pConnectionIncomingError { + #[error("error creating SDP: {0}")] SdpCreateError(String), + #[error("finalization error: {0}")] FinalizeError(String), + #[error("timeout error")] Timeout, } diff --git a/p2p/src/connection/mod.rs b/p2p/src/connection/mod.rs index 939ceef05a..c94c2f5462 100644 --- a/p2p/src/connection/mod.rs +++ b/p2p/src/connection/mod.rs @@ -43,9 +43,11 @@ impl RejectionReason { } } -#[derive(Serialize, Deserialize, Debug, Clone)] +#[derive(Serialize, Deserialize, Debug, Clone, thiserror::Error)] pub enum P2pConnectionErrorResponse { + #[error("connection rejected: {0}")] Rejected(RejectionReason), + #[error("internal error")] InternalError, } diff --git a/p2p/src/connection/outgoing/p2p_connection_outgoing_actions.rs b/p2p/src/connection/outgoing/p2p_connection_outgoing_actions.rs index 0525c567ba..17330e8268 100644 --- a/p2p/src/connection/outgoing/p2p_connection_outgoing_actions.rs +++ b/p2p/src/connection/outgoing/p2p_connection_outgoing_actions.rs @@ -1,3 +1,5 @@ +use openmina_core::log::ActionEvent; +use openmina_core::{action_debug, action_info, action_warn}; use serde::{Deserialize, Serialize}; use openmina_core::requests::RpcId; @@ -282,3 +284,62 @@ impl From for crate::P2pAction { Self::Connection(P2pConnectionAction::Outgoing(a)) } } + +impl ActionEvent for P2pConnectionOutgoingAction { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + match self { + P2pConnectionOutgoingAction::RandomInit => action_debug!(context), + P2pConnectionOutgoingAction::Init { opts, rpc_id: _ } => { + action_debug!(context, opts = display(opts)) + } + P2pConnectionOutgoingAction::Reconnect { opts, rpc_id: _ } => { + action_debug!(context, opts = display(opts)) + } + P2pConnectionOutgoingAction::OfferSdpCreatePending { peer_id } => { + action_debug!(context, peer_id = display(peer_id)) + } + P2pConnectionOutgoingAction::OfferSdpCreateError { peer_id, error } => { + action_warn!(context, peer_id = display(peer_id), error) + } + P2pConnectionOutgoingAction::OfferSdpCreateSuccess { peer_id, sdp } => { + action_debug!(context, peer_id = display(peer_id), sdp) + } + P2pConnectionOutgoingAction::OfferReady { peer_id, offer } => { + action_debug!(context, peer_id = display(peer_id), offer = debug(offer)) + } + P2pConnectionOutgoingAction::OfferSendSuccess { peer_id } => { + action_debug!(context, peer_id = display(peer_id)) + } + P2pConnectionOutgoingAction::AnswerRecvPending { peer_id } => { + action_debug!(context, peer_id = display(peer_id)) + } + P2pConnectionOutgoingAction::AnswerRecvError { peer_id, error } => { + action_warn!(context, peer_id = display(peer_id), error = display(error)) + } + P2pConnectionOutgoingAction::AnswerRecvSuccess { peer_id, answer } => { + action_debug!(context, peer_id = display(peer_id), answer = debug(answer)) + } + P2pConnectionOutgoingAction::FinalizePending { peer_id } => { + action_debug!(context, peer_id = display(peer_id)) + } + P2pConnectionOutgoingAction::FinalizeError { peer_id, error } => { + action_warn!(context, peer_id = display(peer_id), error) + } + P2pConnectionOutgoingAction::FinalizeSuccess { peer_id } => { + action_debug!(context, peer_id = display(peer_id)) + } + P2pConnectionOutgoingAction::Timeout { peer_id } => { + action_debug!(context, peer_id = display(peer_id)) + } + P2pConnectionOutgoingAction::Error { peer_id, error } => { + action_debug!(context, peer_id = display(peer_id), error = display(error)) + } + P2pConnectionOutgoingAction::Success { peer_id } => { + action_info!(context, peer_id = display(peer_id)) + } + } + } +} diff --git a/p2p/src/connection/outgoing/p2p_connection_outgoing_state.rs b/p2p/src/connection/outgoing/p2p_connection_outgoing_state.rs index 670551b5f8..a89e840e8a 100644 --- a/p2p/src/connection/outgoing/p2p_connection_outgoing_state.rs +++ b/p2p/src/connection/outgoing/p2p_connection_outgoing_state.rs @@ -119,11 +119,16 @@ impl P2pConnectionOutgoingState { } } -#[derive(Serialize, Deserialize, Debug, Clone)] +#[derive(Serialize, Deserialize, Debug, Clone, thiserror::Error)] pub enum P2pConnectionOutgoingError { + #[error("error creating SDP: {0}")] SdpCreateError(String), + #[error("rejected: {0}")] Rejected(RejectionReason), + #[error("remote internal error")] RemoteInternalError, + #[error("finalization error: {0}")] FinalizeError(String), + #[error("timeout error")] Timeout, } diff --git a/p2p/src/disconnection/p2p_disconnection_actions.rs b/p2p/src/disconnection/p2p_disconnection_actions.rs index 36f03cfe57..f223adbf2d 100644 --- a/p2p/src/disconnection/p2p_disconnection_actions.rs +++ b/p2p/src/disconnection/p2p_disconnection_actions.rs @@ -1,3 +1,4 @@ +use openmina_core::{action_info, log::ActionEvent}; use serde::{Deserialize, Serialize}; use super::P2pDisconnectionReason; @@ -28,3 +29,21 @@ impl redux::EnablingCondition for P2pDisconnectionAction { } } } + +impl ActionEvent for P2pDisconnectionAction { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + match self { + P2pDisconnectionAction::Init { peer_id, reason } => action_info!( + context, + peer_id = display(peer_id), + reason = display(reason) + ), + P2pDisconnectionAction::Finish { peer_id } => { + action_info!(context, peer_id = display(peer_id)) + } + } + } +} diff --git a/p2p/src/discovery/p2p_discovery_actions.rs b/p2p/src/discovery/p2p_discovery_actions.rs index d1841630e3..a55c400aff 100644 --- a/p2p/src/discovery/p2p_discovery_actions.rs +++ b/p2p/src/discovery/p2p_discovery_actions.rs @@ -1,3 +1,4 @@ +use openmina_core::{action_debug, action_info, action_warn, log::ActionEvent}; use serde::{Deserialize, Serialize}; use crate::{connection::outgoing::P2pConnectionOutgoingInitOpts, P2pState, PeerId}; @@ -46,3 +47,34 @@ impl redux::EnablingCondition for P2pDiscoveryAction { } } } + +impl ActionEvent for P2pDiscoveryAction { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + match self { + P2pDiscoveryAction::Init { peer_id } => { + action_debug!(context, peer_id = display(peer_id)) + } + P2pDiscoveryAction::Success { peer_id, peers } => { + action_debug!(context, peer_id = display(peer_id), peers = debug(peers)) + } + P2pDiscoveryAction::KademliaBootstrap => action_debug!(context), + P2pDiscoveryAction::KademliaInit => action_debug!(context), + P2pDiscoveryAction::KademliaAddRoute { peer_id, addresses } => { + action_debug!( + context, + peer_id = display(peer_id), + addresses = debug(addresses) + ) + } + P2pDiscoveryAction::KademliaSuccess { peers } => { + action_info!(context, peers = debug(peers)) + } + P2pDiscoveryAction::KademliaFailure { description } => { + action_warn!(context, description) + } + } + } +} diff --git a/p2p/src/listen/p2p_listen_actions.rs b/p2p/src/listen/p2p_listen_actions.rs index 43aac301d5..c76e8b6319 100644 --- a/p2p/src/listen/p2p_listen_actions.rs +++ b/p2p/src/listen/p2p_listen_actions.rs @@ -1,3 +1,4 @@ +use openmina_core::{action_debug, action_warn, log::ActionEvent}; use redux::EnablingCondition; use serde::{Deserialize, Serialize}; @@ -26,3 +27,29 @@ pub enum P2pListenAction { } impl EnablingCondition for P2pListenAction {} + +impl ActionEvent for P2pListenAction { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + match self { + P2pListenAction::New { listener_id, addr } => action_debug!( + context, + listener_id = debug(listener_id), + addr = display(addr) + ), + P2pListenAction::Expired { listener_id, addr } => action_debug!( + context, + listener_id = debug(listener_id), + addr = display(addr) + ), + P2pListenAction::Error { listener_id, error } => { + action_warn!(context, listener_id = debug(listener_id), error) + } + P2pListenAction::Closed { listener_id, error } => { + action_debug!(context, listener_id = debug(listener_id), error) + } + } + } +} diff --git a/p2p/src/network/kad/bootstrap/p2p_network_kad_bootstrap_actions.rs b/p2p/src/network/kad/bootstrap/p2p_network_kad_bootstrap_actions.rs index b8191b015a..d721f68841 100644 --- a/p2p/src/network/kad/bootstrap/p2p_network_kad_bootstrap_actions.rs +++ b/p2p/src/network/kad/bootstrap/p2p_network_kad_bootstrap_actions.rs @@ -1,3 +1,4 @@ +use openmina_core::{action_debug, log::ActionEvent}; use redux::EnablingCondition; use serde::{Deserialize, Serialize}; @@ -45,3 +46,25 @@ impl From for P2pAction { P2pNetworkKadAction::Bootstrap(value).into() } } + +impl ActionEvent for P2pNetworkKadBootstrapAction { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + match self { + P2pNetworkKadBootstrapAction::CreateRequests => action_debug!(context), + P2pNetworkKadBootstrapAction::RequestDone { + peer_id, + closest_peers, + } => action_debug!( + context, + peer_id = display(peer_id), + closest_peers = debug(closest_peers) + ), + P2pNetworkKadBootstrapAction::RequestError { peer_id, error } => { + action_debug!(context, peer_id = display(peer_id), error = display(error)) + } + } + } +} diff --git a/p2p/src/network/kad/p2p_network_kad_actions.rs b/p2p/src/network/kad/p2p_network_kad_actions.rs index cf14af9ddf..33984e3266 100644 --- a/p2p/src/network/kad/p2p_network_kad_actions.rs +++ b/p2p/src/network/kad/p2p_network_kad_actions.rs @@ -1,5 +1,6 @@ use std::net::SocketAddr; +use openmina_core::{action_debug, action_info, log::ActionEvent}; use redux::EnablingCondition; use serde::{Deserialize, Serialize}; @@ -56,7 +57,7 @@ pub enum P2pNetworkKademliaAction { /// Performs local node's Kademlia bootstrap. StartBootstrap { key: PeerId }, /// Bootstrap is finished. - BootstrapFinished {}, + BootstrapFinished, } impl EnablingCondition for P2pNetworkKademliaAction { @@ -94,3 +95,55 @@ impl From for P2pAction { P2pAction::Network(P2pNetworkKadAction::System(value).into()) } } + +impl ActionEvent for P2pNetworkKadAction { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + match self { + P2pNetworkKadAction::System(action) => action.action_event(context), + P2pNetworkKadAction::Bootstrap(action) => action.action_event(context), + P2pNetworkKadAction::Request(action) => action.action_event(context), + P2pNetworkKadAction::Stream(action) => action.action_event(context), + } + } +} + +impl ActionEvent for P2pNetworkKademliaAction { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + match self { + P2pNetworkKademliaAction::AnswerFindNodeRequest { + addr, + peer_id, + stream_id, + key, + } => action_debug!( + context, + addr = display(addr), + peer_id = display(peer_id), + stream_id, + key = display(key) + ), + P2pNetworkKademliaAction::UpdateFindNodeRequest { + addr, + peer_id, + stream_id, + closest_peers, + } => action_debug!( + context, + addr = display(addr), + peer_id = display(peer_id), + stream_id, + closest_peers = debug(closest_peers) + ), + P2pNetworkKademliaAction::StartBootstrap { key } => { + action_info!(context, key = display(key)) + } + P2pNetworkKademliaAction::BootstrapFinished => action_debug!(context), + } + } +} diff --git a/p2p/src/network/kad/request/p2p_network_kad_request_actions.rs b/p2p/src/network/kad/request/p2p_network_kad_request_actions.rs index c2dc6ccd82..b035323d36 100644 --- a/p2p/src/network/kad/request/p2p_network_kad_request_actions.rs +++ b/p2p/src/network/kad/request/p2p_network_kad_request_actions.rs @@ -1,5 +1,6 @@ use std::net::SocketAddr; +use openmina_core::{action_debug, action_trace, log::ActionEvent}; use redux::EnablingCondition; use serde::{Deserialize, Serialize}; @@ -80,3 +81,57 @@ impl From for P2pAction { P2pAction::Network(super::super::P2pNetworkKadAction::Request(value).into()) } } + +impl ActionEvent for P2pNetworkKadRequestAction { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + match self { + P2pNetworkKadRequestAction::New { peer_id, addr, key } => action_debug!( + context, + peer_id = display(peer_id), + addr = display(addr), + key = display(key) + ), + P2pNetworkKadRequestAction::PeerIsConnecting { peer_id } => { + action_debug!(context, peer_id = display(peer_id)) + } + P2pNetworkKadRequestAction::MuxReady { peer_id, addr } => { + action_debug!(context, peer_id = display(peer_id), addr = display(addr)) + } + P2pNetworkKadRequestAction::StreamIsCreating { peer_id, stream_id } => { + action_debug!(context, peer_id = display(peer_id), stream_id) + } + P2pNetworkKadRequestAction::StreamReady { + peer_id, + stream_id, + addr, + } => action_debug!( + context, + peer_id = display(peer_id), + stream_id, + addr = display(addr) + ), + P2pNetworkKadRequestAction::RequestSent { peer_id } => { + action_debug!(context, peer_id = display(peer_id)) + } + P2pNetworkKadRequestAction::ReplyReceived { + peer_id, + stream_id, + data, + } => action_debug!( + context, + peer_id = display(peer_id), + stream_id, + data = debug(data) + ), + P2pNetworkKadRequestAction::Prune { peer_id } => { + action_trace!(context, peer_id = display(peer_id)) + } + P2pNetworkKadRequestAction::Error { peer_id, error } => { + action_debug!(context, peer_id = display(peer_id), error = display(error)) + } + } + } +} diff --git a/p2p/src/network/kad/stream/p2p_network_kad_stream_actions.rs b/p2p/src/network/kad/stream/p2p_network_kad_stream_actions.rs index 7a2b310828..fceaa781fb 100644 --- a/p2p/src/network/kad/stream/p2p_network_kad_stream_actions.rs +++ b/p2p/src/network/kad/stream/p2p_network_kad_stream_actions.rs @@ -1,5 +1,6 @@ use std::net::SocketAddr; +use openmina_core::{action_debug, action_trace, log::ActionEvent}; use redux::EnablingCondition; use serde::{Deserialize, Serialize}; @@ -119,3 +120,121 @@ impl From for P2pAction { P2pAction::Network(super::super::P2pNetworkKadAction::Stream(value).into()) } } + +impl ActionEvent for P2pNetworkKademliaStreamAction { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + match self { + P2pNetworkKademliaStreamAction::New { + addr, + peer_id, + stream_id, + incoming, + } => action_debug!( + context, + addr = display(addr), + peer_id = display(peer_id), + stream_id, + incoming + ), + P2pNetworkKademliaStreamAction::IncomingData { + addr, + peer_id, + stream_id, + data, + } => action_debug!( + context, + addr = display(addr), + peer_id = display(peer_id), + stream_id, + data = debug(data) + ), + P2pNetworkKademliaStreamAction::RemoteClose { + addr, + peer_id, + stream_id, + } => action_debug!( + context, + addr = display(addr), + peer_id = display(peer_id), + stream_id + ), + P2pNetworkKademliaStreamAction::WaitIncoming { + addr, + peer_id, + stream_id, + } => action_debug!( + context, + addr = display(addr), + peer_id = display(peer_id), + stream_id + ), + P2pNetworkKademliaStreamAction::WaitOutgoing { + addr, + peer_id, + stream_id, + } => action_debug!( + context, + addr = display(addr), + peer_id = display(peer_id), + stream_id + ), + P2pNetworkKademliaStreamAction::SendRequest { + addr, + peer_id, + stream_id, + data, + } => action_debug!( + context, + addr = display(addr), + peer_id = display(peer_id), + stream_id, + data = debug(data) + ), + P2pNetworkKademliaStreamAction::SendResponse { + addr, + peer_id, + stream_id, + data, + } => action_debug!( + context, + addr = display(addr), + peer_id = display(peer_id), + stream_id, + data = debug(data) + ), + P2pNetworkKademliaStreamAction::OutgoingDataReady { + addr, + peer_id, + stream_id, + } => action_debug!( + context, + addr = display(addr), + peer_id = display(peer_id), + stream_id + ), + P2pNetworkKademliaStreamAction::Close { + addr, + peer_id, + stream_id, + } => action_debug!( + context, + addr = display(addr), + peer_id = display(peer_id), + stream_id + ), + P2pNetworkKademliaStreamAction::Prune { + addr, + peer_id, + stream_id, + } => action_trace!( + context, + addr = display(addr), + peer_id = display(peer_id), + stream_id + ), + } + } +} diff --git a/p2p/src/network/noise/p2p_network_noise_actions.rs b/p2p/src/network/noise/p2p_network_noise_actions.rs index 284a67d9a7..5862d4d403 100644 --- a/p2p/src/network/noise/p2p_network_noise_actions.rs +++ b/p2p/src/network/noise/p2p_network_noise_actions.rs @@ -1,5 +1,6 @@ use std::net::SocketAddr; +use openmina_core::{action_trace, log::ActionEvent}; use serde::{Deserialize, Serialize}; use crate::{Data, P2pNetworkAction, P2pState, PeerId}; @@ -81,3 +82,48 @@ impl redux::EnablingCondition for P2pNetworkNoiseAction { } } } + +impl ActionEvent for P2pNetworkNoiseAction { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + match self { + P2pNetworkNoiseAction::Init { addr, incoming, .. } => { + action_trace!(context, addr = display(addr), incoming) + } + P2pNetworkNoiseAction::IncomingData { addr, data } => { + action_trace!(context, addr = display(addr), data = debug(data)) + } + P2pNetworkNoiseAction::IncomingChunk { addr, data } => { + action_trace!(context, addr = display(addr), data = debug(data)) + } + P2pNetworkNoiseAction::OutgoingChunk { addr, data } => { + action_trace!(context, addr = display(addr), data = debug(data)) + } + P2pNetworkNoiseAction::OutgoingData { addr, data } => { + action_trace!(context, addr = display(addr), data = debug(data)) + } + P2pNetworkNoiseAction::DecryptedData { + addr, + peer_id, + data, + } => action_trace!( + context, + addr = display(addr), + peer_id = debug(peer_id), + data = debug(data) + ), + P2pNetworkNoiseAction::HandshakeDone { + addr, + peer_id, + incoming, + } => action_trace!( + context, + addr = display(addr), + peer_id = display(peer_id), + incoming + ), + } + } +} diff --git a/p2p/src/network/pnet/p2p_network_pnet_actions.rs b/p2p/src/network/pnet/p2p_network_pnet_actions.rs index f2b80f0c77..881932a079 100644 --- a/p2p/src/network/pnet/p2p_network_pnet_actions.rs +++ b/p2p/src/network/pnet/p2p_network_pnet_actions.rs @@ -1,5 +1,6 @@ use std::net::SocketAddr; +use openmina_core::{action_debug, action_trace, log::ActionEvent}; use serde::{Deserialize, Serialize}; use crate::{Data, P2pState}; @@ -42,3 +43,22 @@ impl redux::EnablingCondition for P2pNetworkPnetAction { true } } + +impl ActionEvent for P2pNetworkPnetAction { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + match self { + P2pNetworkPnetAction::IncomingData { addr, data } => { + action_trace!(context, addr = display(addr), data = debug(data)) + } + P2pNetworkPnetAction::OutgoingData { addr, data } => { + action_trace!(context, addr = display(addr), data = debug(data)) + } + P2pNetworkPnetAction::SetupNonce { addr, incoming, .. } => { + action_debug!(context, addr = display(addr), incoming) + } + } + } +} diff --git a/p2p/src/network/rpc/p2p_network_rpc_actions.rs b/p2p/src/network/rpc/p2p_network_rpc_actions.rs index 9392462f87..16d1037460 100644 --- a/p2p/src/network/rpc/p2p_network_rpc_actions.rs +++ b/p2p/src/network/rpc/p2p_network_rpc_actions.rs @@ -1,6 +1,7 @@ use std::net::SocketAddr; use mina_p2p_messages::rpc_kernel::{QueryHeader, ResponseHeader}; +use openmina_core::{action_debug, action_trace, log::ActionEvent}; use serde::{Deserialize, Serialize}; use super::{super::*, *}; @@ -129,3 +130,111 @@ impl redux::EnablingCondition for P2pNetworkRpcAction { } } } + +impl ActionEvent for P2pNetworkRpcAction { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + match self { + P2pNetworkRpcAction::Init { + addr, + peer_id, + stream_id, + incoming, + } => action_debug!( + context, + addr = display(addr), + peer_id = display(peer_id), + stream_id, + incoming + ), + P2pNetworkRpcAction::IncomingData { + addr, + peer_id, + stream_id, + data, + } => action_trace!( + context, + addr = display(addr), + peer_id = display(peer_id), + stream_id, + data = debug(data) + ), + P2pNetworkRpcAction::IncomingMessage { + addr, + peer_id, + stream_id, + message, + } => match message { + RpcMessage::Handshake => action_trace!( + context, + addr = display(addr), + peer_id = display(peer_id), + stream_id, + message_kind = "handshake" + ), + RpcMessage::Heartbeat => action_trace!( + context, + addr = display(addr), + peer_id = display(peer_id), + stream_id, + message_kind = "heartbeat" + ), + RpcMessage::Query { header, .. } => action_debug!( + context, + addr = display(addr), + peer_id = display(peer_id), + stream_id, + message_kind = "query", + message_header = debug(header) + ), + RpcMessage::Response { header, .. } => action_debug!( + context, + addr = display(addr), + peer_id = display(peer_id), + stream_id, + message_kind = "response", + message_header = debug(header) + ), + }, + P2pNetworkRpcAction::PrunePending { peer_id, stream_id } => { + action_trace!(context, peer_id = display(peer_id), stream_id) + } + P2pNetworkRpcAction::OutgoingQuery { + peer_id, + query, + data, + } => action_debug!( + context, + peer_id = display(peer_id), + query = debug(query), + data = debug(data) + ), + P2pNetworkRpcAction::OutgoingResponse { + peer_id, + response, + data, + } => action_debug!( + context, + peer_id = display(peer_id), + response = debug(response), + data = debug(data) + ), + P2pNetworkRpcAction::OutgoingData { + addr, + peer_id, + stream_id, + data, + fin, + } => action_debug!( + context, + addr = display(addr), + peer_id = display(peer_id), + stream_id, + data = debug(data), + fin + ), + } + } +} diff --git a/p2p/src/network/scheduler/p2p_network_scheduler_actions.rs b/p2p/src/network/scheduler/p2p_network_scheduler_actions.rs index c3fd79f828..f315432e75 100644 --- a/p2p/src/network/scheduler/p2p_network_scheduler_actions.rs +++ b/p2p/src/network/scheduler/p2p_network_scheduler_actions.rs @@ -1,5 +1,6 @@ use std::net::{IpAddr, SocketAddr}; +use openmina_core::{action_debug, action_info, action_warn, log::ActionEvent}; use serde::{Deserialize, Serialize}; use super::{ @@ -122,3 +123,79 @@ impl redux::EnablingCondition for P2pNetworkSchedulerAction { } } } + +impl ActionEvent for P2pNetworkSchedulerAction { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + match self { + P2pNetworkSchedulerAction::InterfaceDetected { ip } => { + action_debug!(context, ip = display(ip)) + } + P2pNetworkSchedulerAction::InterfaceExpired { ip } => { + action_debug!(context, ip = display(ip)) + } + P2pNetworkSchedulerAction::IncomingConnectionIsReady { listener } => { + action_debug!(context, listener = display(listener)) + } + P2pNetworkSchedulerAction::IncomingDidAccept { + addr, + result: Ok(_), + } => action_debug!(context, addr = debug(addr)), + P2pNetworkSchedulerAction::IncomingDidAccept { + addr, + result: Err(error), + } => action_debug!(context, addr = debug(addr), error = display(error)), + P2pNetworkSchedulerAction::OutgoingDidConnect { + addr, + result: Ok(_), + } => action_debug!(context, addr = display(addr)), + P2pNetworkSchedulerAction::OutgoingDidConnect { + addr, + result: Err(error), + } => action_debug!(context, addr = display(addr), error = display(error)), + P2pNetworkSchedulerAction::IncomingDataIsReady { addr } => { + action_debug!(context, addr = display(addr)) + } + P2pNetworkSchedulerAction::IncomingDataDidReceive { + addr, + result: Ok(data), + } => action_debug!(context, addr = display(addr), data = debug(data)), + P2pNetworkSchedulerAction::IncomingDataDidReceive { + addr, + result: Err(error), + } => action_debug!(context, addr = display(addr), error = display(error)), + P2pNetworkSchedulerAction::SelectDone { + addr, + kind, + protocol, + incoming, + } => action_debug!( + context, + addr = display(addr), + select_kind = debug(kind), + protocol = debug(protocol), + incoming = incoming + ), + P2pNetworkSchedulerAction::SelectError { addr, kind, error } => action_warn!( + context, + addr = display(addr), + select_kind = debug(kind), + error = display(error) + ), + P2pNetworkSchedulerAction::YamuxDidInit { addr, peer_id } => { + action_debug!(context, addr = display(addr), peer_id = display(peer_id)) + } + P2pNetworkSchedulerAction::Disconnect { addr, reason } => { + action_info!(context, addr = display(addr), reason = display(reason)) + } + P2pNetworkSchedulerAction::Error { addr, error } => { + action_warn!(context, addr = display(addr), error = display(error)) + } + P2pNetworkSchedulerAction::Disconnected { addr, reason } => { + action_info!(context, addr = display(addr), reason = display(reason)) + } + } + } +} diff --git a/p2p/src/network/scheduler/p2p_network_scheduler_state.rs b/p2p/src/network/scheduler/p2p_network_scheduler_state.rs index 7506615209..cdaa4ebadb 100644 --- a/p2p/src/network/scheduler/p2p_network_scheduler_state.rs +++ b/p2p/src/network/scheduler/p2p_network_scheduler_state.rs @@ -55,10 +55,12 @@ impl P2pNetworkConnectionState { } } -#[derive(Serialize, Deserialize, Debug, Clone, PartialEq, Eq, derive_more::From)] +#[derive(Serialize, Deserialize, Debug, Clone, PartialEq, Eq, thiserror::Error)] pub enum P2pNetworkConnectionCloseReason { - Disconnect(P2pDisconnectionReason), - Error(P2pNetworkConnectionError), + #[error("peer is disconnected: {0}")] + Disconnect(#[from] P2pDisconnectionReason), + #[error("connection error: {0}")] + Error(#[from] P2pNetworkConnectionError), } /// P2p connection error. diff --git a/p2p/src/network/select/p2p_network_select_actions.rs b/p2p/src/network/select/p2p_network_select_actions.rs index c8cb524e2a..61eec36f0b 100644 --- a/p2p/src/network/select/p2p_network_select_actions.rs +++ b/p2p/src/network/select/p2p_network_select_actions.rs @@ -1,5 +1,6 @@ use std::net::SocketAddr; +use openmina_core::{action_debug, action_trace, log::ActionEvent}; use serde::{Deserialize, Serialize}; use crate::{Data, P2pState, PeerId}; @@ -100,3 +101,49 @@ impl redux::EnablingCondition for P2pNetworkSelectAction { } } } + +impl ActionEvent for P2pNetworkSelectAction { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + match self { + P2pNetworkSelectAction::Init { + addr, + kind, + incoming, + send_handshake, + } => action_debug!( + context, + addr = display(addr), + select_kind = debug(kind), + incoming, + send_handshake + ), + P2pNetworkSelectAction::IncomingData { + addr, + kind, + data, + fin, + } => action_trace!( + context, + addr = display(addr), + select_kind = debug(kind), + data = debug(data), + fin + ), + P2pNetworkSelectAction::IncomingToken { addr, kind, token } => action_debug!( + context, + addr = display(addr), + select_kind = debug(kind), + token = debug(token) + ), + P2pNetworkSelectAction::OutgoingTokens { addr, kind, tokens } => action_debug!( + context, + addr = display(addr), + select_kind = debug(kind), + tokens = debug(tokens) + ), + } + } +} diff --git a/p2p/src/network/yamux/p2p_network_yamux_actions.rs b/p2p/src/network/yamux/p2p_network_yamux_actions.rs index 1ed9027489..60015e9526 100644 --- a/p2p/src/network/yamux/p2p_network_yamux_actions.rs +++ b/p2p/src/network/yamux/p2p_network_yamux_actions.rs @@ -1,5 +1,6 @@ use std::net::SocketAddr; +use openmina_core::{action_debug, action_trace, log::ActionEvent}; use serde::{Deserialize, Serialize}; use super::p2p_network_yamux_state::{StreamId, YamuxFrame, YamuxPing}; @@ -77,3 +78,47 @@ impl redux::EnablingCondition for P2pNetworkYamuxAction { } } } + +impl ActionEvent for P2pNetworkYamuxAction { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + match self { + P2pNetworkYamuxAction::IncomingData { addr, data } => { + action_debug!(context, addr = debug(addr), data = debug(data)) + } + P2pNetworkYamuxAction::OutgoingData { + addr, + stream_id, + data, + fin, + } => action_debug!( + context, + addr = display(addr), + stream_id, + data = debug(data), + fin + ), + P2pNetworkYamuxAction::IncomingFrame { addr, frame } => { + action_trace!(context, addr = display(addr), frame = debug(frame)) + } + P2pNetworkYamuxAction::OutgoingFrame { addr, frame } => { + action_trace!(context, addr = display(addr), frame = debug(frame)) + } + P2pNetworkYamuxAction::PingStream { addr, ping } => { + action_debug!(context, addr = display(addr), ping = debug(ping)) + } + P2pNetworkYamuxAction::OpenStream { + addr, + stream_id, + stream_kind, + } => action_debug!( + context, + addr = display(addr), + stream_id, + stream_kind = debug(stream_kind) + ), + } + } +} diff --git a/p2p/src/peer/p2p_peer_actions.rs b/p2p/src/peer/p2p_peer_actions.rs index f27d7fbb82..9f2274f821 100644 --- a/p2p/src/peer/p2p_peer_actions.rs +++ b/p2p/src/peer/p2p_peer_actions.rs @@ -1,4 +1,4 @@ -use openmina_core::block::ArcBlockWithHash; +use openmina_core::{action_info, block::ArcBlockWithHash, log::ActionEvent}; use serde::{Deserialize, Serialize}; use crate::{P2pState, PeerId}; @@ -42,3 +42,25 @@ impl redux::EnablingCondition for P2pPeerAction { } } } + +impl ActionEvent for P2pPeerAction { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + match self { + P2pPeerAction::Ready { peer_id, incoming } => action_info!( + context, + summary = "Peer is ready", + peer_id = display(peer_id), + incoming, + ), + P2pPeerAction::BestTipUpdate { peer_id, best_tip } => action_info!( + context, + summary = "Best tip updated", + peer_id = display(peer_id), + best_tip = display(&best_tip.hash), + ), + } + } +} diff --git a/snark/Cargo.toml b/snark/Cargo.toml index 82794f3478..67a6a154ce 100644 --- a/snark/Cargo.toml +++ b/snark/Cargo.toml @@ -28,6 +28,7 @@ mina-p2p-messages = { workspace = true } sha2 = "0.10" num-bigint = "0.4" bincode = "1.3.3" +thiserror = "1.0.50" rand = "0.8" rayon = "1.5" diff --git a/snark/src/work_verify/mod.rs b/snark/src/work_verify/mod.rs index 0401b123b7..158106534d 100644 --- a/snark/src/work_verify/mod.rs +++ b/snark/src/work_verify/mod.rs @@ -22,8 +22,10 @@ impl openmina_core::requests::RequestIdType for SnarkWorkVerifyIdType { pub type SnarkWorkVerifyId = openmina_core::requests::RequestId; -#[derive(Serialize, Deserialize, Debug, Clone)] +#[derive(Serialize, Deserialize, Debug, Clone, thiserror::Error)] pub enum SnarkWorkVerifyError { + #[error("verification failed")] VerificationFailed, + #[error("validator thread crashed")] ValidatorThreadCrashed, } diff --git a/snark/src/work_verify/snark_work_verify_actions.rs b/snark/src/work_verify/snark_work_verify_actions.rs index f204bfebeb..3bbc08fb2e 100644 --- a/snark/src/work_verify/snark_work_verify_actions.rs +++ b/snark/src/work_verify/snark_work_verify_actions.rs @@ -1,6 +1,6 @@ use serde::{Deserialize, Serialize}; -use openmina_core::snark::Snark; +use openmina_core::{action_info, action_trace, action_warn, log::ActionEvent, snark::Snark}; use super::{SnarkWorkVerifyError, SnarkWorkVerifyId}; @@ -58,3 +58,32 @@ impl redux::EnablingCondition for SnarkWorkVerifyAction { } } } + +impl ActionEvent for SnarkWorkVerifyAction { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + match self { + SnarkWorkVerifyAction::Init { req_id, batch, .. } => action_info!( + context, + req_id = display(req_id), + trace_batch = + serde_json::to_string(&batch.iter().map(|v| v.job_id()).collect::>()) + .ok() + ), + SnarkWorkVerifyAction::Pending { req_id } => { + action_trace!(context, req_id = display(req_id)) + } + SnarkWorkVerifyAction::Error { req_id, error } => { + action_warn!(context, req_id = display(req_id), error = display(error)) + } + SnarkWorkVerifyAction::Success { req_id } => { + action_info!(context, req_id = display(req_id)) + } + SnarkWorkVerifyAction::Finish { req_id } => { + action_trace!(context, req_id = display(req_id)) + } + } + } +} From 0de3f04f5aa774d0e5c54d98eb6432825d5cd36c Mon Sep 17 00:00:00 2001 From: Alexander Koptelov Date: Wed, 3 Apr 2024 12:37:46 +0300 Subject: [PATCH 2/7] feat(actions): generalize context trait --- core/src/log.rs | 8 ++++--- node/src/logger/logger_effects.rs | 36 ++++++++++++++++++++----------- 2 files changed, 28 insertions(+), 16 deletions(-) diff --git a/core/src/log.rs b/core/src/log.rs index eae4826409..15ec293491 100644 --- a/core/src/log.rs +++ b/core/src/log.rs @@ -127,9 +127,9 @@ macro_rules! action_trace { pub trait EventContext { fn timestamp(&self) -> redux::Timestamp; - fn time(&self) -> String; - fn node_id(&self) -> String; - fn kind(&self) -> String; + fn time(&self) -> &'_ dyn Value; + fn node_id(&self) -> &'_ dyn Value; + fn kind(&self) -> &'_ dyn Value; } pub trait ActionEvent { @@ -138,4 +138,6 @@ pub trait ActionEvent { T: EventContext; } +use tracing::Value; + pub use crate::{debug, error, info, trace, warn}; diff --git a/node/src/logger/logger_effects.rs b/node/src/logger/logger_effects.rs index 8c4cdc7d46..03a158c9ce 100644 --- a/node/src/logger/logger_effects.rs +++ b/node/src/logger/logger_effects.rs @@ -1,3 +1,5 @@ +use openmina_core::log::inner::field::{display, DisplayValue}; +use openmina_core::log::inner::Value; use openmina_core::log::{time_to_str, ActionEvent, EventContext}; use p2p::PeerId; @@ -10,8 +12,20 @@ use crate::{Action, ActionKind, ActionWithMetaRef, Service, Store}; struct ActionLoggerContext { time: redux::Timestamp, - node_id: PeerId, - kind: ActionKind, + time_str: String, + node_id: DisplayValue, + kind: DisplayValue, +} + +impl ActionLoggerContext { + fn new(time: redux::Timestamp, node_id: PeerId, kind: ActionKind) -> Self { + ActionLoggerContext { + time, + time_str: time_to_str(time), + node_id: display(node_id), + kind: display(kind), + } + } } impl EventContext for ActionLoggerContext { @@ -19,26 +33,22 @@ impl EventContext for ActionLoggerContext { self.time } - fn time(&self) -> String { - time_to_str(self.time) + fn time(&self) -> &'_ dyn Value { + &self.time_str } - fn node_id(&self) -> String { - self.node_id.to_string() + fn node_id(&self) -> &'_ dyn Value { + &self.node_id } - fn kind(&self) -> String { - self.kind.to_string() + fn kind(&self) -> &'_ dyn Value { + &self.kind } } pub fn logger_effects(store: &Store, action: ActionWithMetaRef<'_>) { let (action, meta) = action.split(); - let context = ActionLoggerContext { - time: meta.time(), - node_id: store.state().p2p.my_id(), - kind: action.kind(), - }; + let context = ActionLoggerContext::new(meta.time(), store.state().p2p.my_id(), action.kind()); match action { Action::P2p(action) => match action { From 5de895c2d758fb759a4c58e201e5bce0a13944bf Mon Sep 17 00:00:00 2001 From: Alexander Koptelov Date: Thu, 4 Apr 2024 16:49:49 +0300 Subject: [PATCH 3/7] feat(actions): use derive macro for action tracing --- Cargo.lock | 86 ++-- Cargo.toml | 1 + core/Cargo.toml | 1 + core/src/lib.rs | 3 + macros/Cargo.toml | 20 + macros/src/action_event.md | 153 +++++++ macros/src/action_event.rs | 401 ++++++++++++++++++ macros/src/lib.rs | 11 + p2p/Cargo.toml | 1 + .../p2p_network_kad_bootstrap_actions.rs | 55 +-- .../network/kad/p2p_network_kad_actions.rs | 109 +++-- .../p2p_network_kad_request_actions.rs | 112 ++--- .../p2p_network_kad_request_effects.rs | 4 +- .../stream/p2p_network_kad_stream_actions.rs | 240 +++++------ 14 files changed, 904 insertions(+), 293 deletions(-) create mode 100644 macros/Cargo.toml create mode 100644 macros/src/action_event.md create mode 100644 macros/src/action_event.rs create mode 100644 macros/src/lib.rs diff --git a/Cargo.lock b/Cargo.lock index 0013de8bfa..8cf7b74bb2 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -270,9 +270,9 @@ dependencies = [ [[package]] name = "anyhow" -version = "1.0.75" +version = "1.0.81" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "a4668cab20f66d8d020e1fbc0ebe47217433c1b6c8f2040faf858554e394ace6" +checksum = "0952808a6c2afd1aa8947271f3a60f1a6763c7b912d210184c5149b5cf147247" [[package]] name = "arc-swap" @@ -481,7 +481,7 @@ checksum = "a66537f1bb974b254c98ed142ff995236e81b9d0fe4db0575f46612cb15eb0f9" dependencies = [ "proc-macro2", "quote", - "syn 2.0.38", + "syn 2.0.58", ] [[package]] @@ -1000,7 +1000,7 @@ dependencies = [ "heck 0.4.1", "proc-macro2", "quote", - "syn 2.0.38", + "syn 2.0.58", ] [[package]] @@ -1325,7 +1325,7 @@ checksum = "83fdaf97f4804dcebfa5862639bc9ce4121e82140bec2a987ac5140294865b5b" dependencies = [ "proc-macro2", "quote", - "syn 2.0.38", + "syn 2.0.58", ] [[package]] @@ -1397,7 +1397,7 @@ dependencies = [ "proc-macro2", "quote", "strsim 0.10.0", - "syn 2.0.38", + "syn 2.0.58", ] [[package]] @@ -1430,7 +1430,7 @@ checksum = "c5a91391accf613803c2a9bf9abccdbaa07c54b4244a5b64883f9c3c137c86be" dependencies = [ "darling_core 0.20.6", "quote", - "syn 2.0.38", + "syn 2.0.58", ] [[package]] @@ -1628,7 +1628,7 @@ checksum = "487585f4d0c6655fe74905e2504d8ad6908e4db67f744eb140876906c2f3175d" dependencies = [ "proc-macro2", "quote", - "syn 2.0.38", + "syn 2.0.58", ] [[package]] @@ -1647,7 +1647,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "f87ab5c4c35c1d2fc7928e96d1cee3786a9bc9571ebaf4bf8f4207e6271165fa" dependencies = [ "quote", - "syn 2.0.38", + "syn 2.0.58", ] [[package]] @@ -1763,7 +1763,7 @@ dependencies = [ "heck 0.4.1", "proc-macro2", "quote", - "syn 2.0.38", + "syn 2.0.58", ] [[package]] @@ -1775,7 +1775,7 @@ dependencies = [ "once_cell", "proc-macro2", "quote", - "syn 2.0.38", + "syn 2.0.58", ] [[package]] @@ -2008,7 +2008,7 @@ checksum = "89ca545a94061b6365f2c7355b4b32bd20df3ff95f02da9329b34ccc3bd6ee72" dependencies = [ "proc-macro2", "quote", - "syn 2.0.38", + "syn 2.0.58", ] [[package]] @@ -3197,7 +3197,7 @@ dependencies = [ "proc-macro-warning", "proc-macro2", "quote", - "syn 2.0.38", + "syn 2.0.58", ] [[package]] @@ -4012,7 +4012,7 @@ dependencies = [ "proc-macro-crate", "proc-macro2", "quote", - "syn 2.0.38", + "syn 2.0.58", ] [[package]] @@ -4150,6 +4150,7 @@ dependencies = [ "mina-hasher", "mina-p2p-messages", "multihash 0.18.1", + "openmina-macros", "redux", "serde", "serde_json", @@ -4160,6 +4161,19 @@ dependencies = [ "tracing", ] +[[package]] +name = "openmina-macros" +version = "0.0.1" +dependencies = [ + "anyhow", + "openmina-core", + "proc-macro2", + "quote", + "rust-format", + "syn 2.0.58", + "tracing", +] + [[package]] name = "openmina-node-invariants" version = "0.3.0" @@ -4270,7 +4284,7 @@ checksum = "a948666b637a0f465e8564c73e89d4dde00d72d4d473cc972f390fc3dcee7d9c" dependencies = [ "proc-macro2", "quote", - "syn 2.0.38", + "syn 2.0.58", ] [[package]] @@ -4349,6 +4363,7 @@ dependencies = [ "multiaddr", "multihash 0.18.1", "openmina-core", + "openmina-macros", "quick-protobuf", "rand 0.8.5", "redux", @@ -4511,7 +4526,7 @@ dependencies = [ "pest_meta", "proc-macro2", "quote", - "syn 2.0.38", + "syn 2.0.58", ] [[package]] @@ -4542,7 +4557,7 @@ checksum = "4359fd9c9171ec6e8c62926d6faaf553a8dc3f64e1507e76da7911b4f6a04405" dependencies = [ "proc-macro2", "quote", - "syn 2.0.38", + "syn 2.0.58", ] [[package]] @@ -4739,14 +4754,14 @@ checksum = "9b698b0b09d40e9b7c1a47b132d66a8b54bcd20583d9b6d06e4535e383b4405c" dependencies = [ "proc-macro2", "quote", - "syn 2.0.38", + "syn 2.0.58", ] [[package]] name = "proc-macro2" -version = "1.0.69" +version = "1.0.79" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "134c189feb4956b20f6f547d2cf727d4c0fe06722b20a0eec87ed445a97f92da" +checksum = "e835ff2298f5721608eb1a980ecaee1aef2c132bf95ecc026a11b7bf3c01c02e" dependencies = [ "unicode-ident", ] @@ -4771,7 +4786,7 @@ checksum = "440f724eba9f6996b75d63681b0a92b06947f1457076d503a4d2e2c8f56442b8" dependencies = [ "proc-macro2", "quote", - "syn 2.0.38", + "syn 2.0.58", ] [[package]] @@ -4851,9 +4866,9 @@ dependencies = [ [[package]] name = "quote" -version = "1.0.33" +version = "1.0.35" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "5267fca4496028628a95160fc423a33e8b2e6af8a5302579e322e4b520293cae" +checksum = "291ec9ab5efd934aaf503a6466c5d5251535d108ee747472c3977cc5acc868ef" dependencies = [ "proc-macro2", ] @@ -5259,6 +5274,9 @@ name = "rust-format" version = "0.3.4" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "60e7c00b6c3bf5e38a880eec01d7e829d12ca682079f8238a464def3c4b31627" +dependencies = [ + "proc-macro2", +] [[package]] name = "rustc-demangle" @@ -5532,7 +5550,7 @@ checksum = "67c5609f394e5c2bd7fc51efda478004ea80ef42fee983d5c67a65e34f32c0e3" dependencies = [ "proc-macro2", "quote", - "syn 2.0.38", + "syn 2.0.58", ] [[package]] @@ -5618,7 +5636,7 @@ dependencies = [ "darling 0.20.6", "proc-macro2", "quote", - "syn 2.0.38", + "syn 2.0.58", ] [[package]] @@ -5970,9 +5988,9 @@ dependencies = [ [[package]] name = "syn" -version = "2.0.38" +version = "2.0.58" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "e96b79aaa137db8f61e26363a0c9b47d8b4ec75da28b7d1d614c2303e232408b" +checksum = "44cfb93f38070beee36b3fef7d4f5a16f27751d94b187b666a5cc5e9b0d30687" dependencies = [ "proc-macro2", "quote", @@ -6069,7 +6087,7 @@ checksum = "266b2e40bc00e5a6c09c3584011e08b06f123c00362c92b975ba9843aaaa14b8" dependencies = [ "proc-macro2", "quote", - "syn 2.0.38", + "syn 2.0.58", ] [[package]] @@ -6155,7 +6173,7 @@ checksum = "5b8a1e28f2deaa14e508979454cb3a223b10b938b45af148bc0986de36f1923b" dependencies = [ "proc-macro2", "quote", - "syn 2.0.38", + "syn 2.0.58", ] [[package]] @@ -6297,7 +6315,7 @@ checksum = "34704c8d6ebcbc939824180af020566b01a7c01f80641264eba0999f6c2b6be7" dependencies = [ "proc-macro2", "quote", - "syn 2.0.38", + "syn 2.0.58", ] [[package]] @@ -6791,7 +6809,7 @@ dependencies = [ "once_cell", "proc-macro2", "quote", - "syn 2.0.38", + "syn 2.0.58", "wasm-bindgen-shared", ] @@ -6825,7 +6843,7 @@ checksum = "54681b18a46765f095758388f2d0cf16eb8d4169b639ab575a8f5693af210c7b" dependencies = [ "proc-macro2", "quote", - "syn 2.0.38", + "syn 2.0.58", "wasm-bindgen-backend", "wasm-bindgen-shared", ] @@ -7451,7 +7469,7 @@ checksum = "9ce1b18ccd8e73a9321186f97e46f9f04b778851177567b1975109d26a08d2a6" dependencies = [ "proc-macro2", "quote", - "syn 2.0.38", + "syn 2.0.58", ] [[package]] @@ -7471,7 +7489,7 @@ checksum = "ce36e65b0d2999d2aafac989fb249189a141aee1f53c612c1f37d72631959f69" dependencies = [ "proc-macro2", "quote", - "syn 2.0.38", + "syn 2.0.58", ] [[package]] diff --git a/Cargo.toml b/Cargo.toml index ad7c0542f9..23d56b9afc 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -3,6 +3,7 @@ cargo-features = ["named-profiles"] [workspace] members = [ "core", + "macros", "ledger", "snark", "p2p", diff --git a/core/Cargo.toml b/core/Cargo.toml index 5345bab6a6..a037db32d7 100644 --- a/core/Cargo.toml +++ b/core/Cargo.toml @@ -16,6 +16,7 @@ redux = { workspace = true } tokio = { version = "1.26", features = ["sync"] } time = { version = "0.3", features = ["formatting"] } multihash = { version = "0.18.1", features = ["blake2b"] } +openmina-macros = { path = "../macros" } mina-hasher = { workspace = true } mina-p2p-messages = { workspace = true } diff --git a/core/src/lib.rs b/core/src/lib.rs index 1053fcb302..5c96fc0001 100644 --- a/core/src/lib.rs +++ b/core/src/lib.rs @@ -26,3 +26,6 @@ pub fn preshared_key(chain_id: &str) -> [u8; 32] { psk_fixed.copy_from_slice(hash.as_ref()); psk_fixed } + +pub use log::ActionEvent; +pub use openmina_macros::*; diff --git a/macros/Cargo.toml b/macros/Cargo.toml new file mode 100644 index 0000000000..2cb7db1a32 --- /dev/null +++ b/macros/Cargo.toml @@ -0,0 +1,20 @@ +[package] +name = "openmina-macros" +version = "0.0.1" +edition = "2021" +license = "Apache-2.0" +authors = [ "Alexander Koptelov " ] + +[lib] +proc-macro = true + +[dependencies] +proc-macro2 = "1.0.79" +quote = "1.0.35" +syn = "2.0.53" + +[dev-dependencies] +openmina-core = { path = "../core" } +tracing = "0.1.40" +rust-format = { version = "0.3", features = ["token_stream"] } +anyhow = "1.0.81" diff --git a/macros/src/action_event.md b/macros/src/action_event.md new file mode 100644 index 0000000000..d7cac3d096 --- /dev/null +++ b/macros/src/action_event.md @@ -0,0 +1,153 @@ +Derives `[openmina_core::ActionEvent]` trait implementation for action. + +### Action containers + +For action containers, it simply delegates to inner actions. + + +``` +# use openmina_core::ActionEvent; +# +#[derive(ActionEvent)] +enum ActionContainer { + SubAction1(Action1), +} +#[derive(ActionEvent)] +enum Action1 { + Init, + Done, +} + +ActionContainer::SubAction1(Action1::Init).action_event(context); +``` + +``` +impl ActionEvent for ActionContainer { + fn action_event(&self, context: &T) + where T: ActionContext + { + match self { + ActionContainer(action) => action.action_event(context), + } + } +} + +impl ActionEvent for Action1 { + fn action_event(&self, context: &T) + where T: ActionContext + { + match self { + Action1::Init => openmina_core::log::action_debug!(context), + Action1::Done => openmina_core::log::action_debug!(context), + } + } +} + +``` + +### Tracing level + +By default, tracing event of level `debug` is generated for an action. It can be +overriden by using `#[action_event(level = ...)]` attribute. Also, actions that +names ends with `Error` or `Warn` will be traced with `warn` level. + +``` +#[derive(openmina_macros::ActionEvent)] +#[action_event(level = trace)] +pub enum Action { + ActionDefaultLevel, + #[action_event(level = warn)] + ActionOverrideLevel, + WithErrorAction, + WithWarnAction, +} +``` + +``` +impl openmina_core::ActionEvent for Action { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + match self { + Action::ActionDefaultLevel => openmina_core::action_trace!(context), + Action::ActionOverrideLevel => openmina_core::action_warn!(context), + Action::WithErrorAction => openmina_core::action_warn!(context), + Action::WithWarnAction => openmina_core::action_warn!(context), + } + } +} +``` + +### Summary field + + +If an action has doc-comment, its first line will be used for `summary` field of +tracing events for the action. + +``` +#[derive(openmina_macros::ActionEvent)] +pub enum Action { + Unit, + /// documentation + UnitWithDoc, + /// Multiline documentation. + /// Another line. + /// + /// And another. + UnitWithMultilineDoc, +} + +``` + +``` +impl openmina_core::ActionEvent for Action { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + match self { + Action::Unit => openmina_core::action_debug!(context), + Action::UnitWithDoc => openmina_core::action_debug!(context, summary = "documentation"), + Action::UnitWithMultilineDoc => openmina_core::action_debug!(context, summary = "Multiline documentation"), + } + } +} + +``` + +### Fields + +Certain fields can be added to the tracing event, using `#[action_event(fields(...))]` attribute. + +``` +#[derive(openmina_macros::ActionEvent)] +pub enum Action { + NoFields { f1: bool }, + #[action_event(fields(f1))] + Field { f1: bool }, + #[action_event(fields(f = f1))] + FieldWithName { f1: bool }, + #[action_event(fields(debug(f1)))] + DebugField { f1: bool }, + #[action_event(fields(display(f1)))] + DisplayField { f1: bool }, +} +``` + +```rust +impl openmina_core::ActionEvent for Action { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + match self { + Action::NoFields { f1 } => openmina_core::action_debug!(context), + Action::Field { f1 } => openmina_core::action_debug!(context, f1 = f1), + Action::FieldWithName { f1 } => openmina_core::action_debug!(context, f = f1), + Action::DebugField { f1 } => openmina_core::action_debug!(context, f1 = debug(f1)), + Action::DisplayField { f1 } => openmina_core::action_debug!(context, f1 = display(f1)), + } + } +} +``` diff --git a/macros/src/action_event.rs b/macros/src/action_event.rs new file mode 100644 index 0000000000..45f8281cd0 --- /dev/null +++ b/macros/src/action_event.rs @@ -0,0 +1,401 @@ +use std::convert::TryInto; + +use proc_macro2::*; +use quote::*; +use syn::*; + +#[derive(Clone, Debug)] +enum Level { + Error, + Warn, + Info, + Debug, + Trace, +} + +impl TryFrom for Level { + type Error = Error; + + fn try_from(value: Expr) -> Result { + let Expr::Path(ExprPath { path, .. }) = value else { + return Err(Error::new_spanned(value, "ident is expected")); + }; + let level = match path.require_ident()?.to_string().to_lowercase().as_str() { + "error" => Level::Error, + "warn" => Level::Warn, + "info" => Level::Info, + "debug" => Level::Debug, + "trace" => Level::Trace, + _ => return Err(Error::new_spanned(path, "incorrect value")), + }; + Ok(level) + } +} + +impl ToTokens for Level { + fn to_tokens(&self, tokens: &mut TokenStream) { + let ident = match self { + Level::Error => format_ident!("action_error"), + Level::Warn => format_ident!("action_warn"), + Level::Info => format_ident!("action_info"), + Level::Debug => format_ident!("action_debug"), + Level::Trace => format_ident!("action_trace"), + }; + tokens.extend(quote!(#ident)); + } +} + +#[derive(Clone, Debug)] +enum FieldsSpec { + /// List of expressions for fields to be added to the tracing, with + /// optional ident for filtering. + Some(Vec<(Option, TokenStream)>), +} + +#[derive(Clone, Debug, Default)] +struct ActionEventAttrs { + level: Option, + fields: Option, +} + +pub fn expand(input: DeriveInput) -> Result { + let Data::Enum(enum_data) = &input.data else { + return Err(Error::new_spanned(input, "should be enum")); + }; + let type_name = &input.ident; + let trait_name = quote!(openmina_core::ActionEvent); // TODO + let input_attrs = action_event_attrs(&input.attrs)?; + let variants = enum_data + .variants + .iter() + .map(|v| { + let variant_name = &v.ident; + let mut args = vec![quote!(context)]; + let variant_attrs = action_event_attrs(&v.attrs)?; + match &v.fields { + Fields::Unnamed(fields) => { + if fields.unnamed.len() != 1 { + return Err(Error::new_spanned( + fields, + "only single-item variant supported", + )); + } + if fields.unnamed.len() != 1 { + return Err(Error::new_spanned( + fields, + "only single-item variant supported", + )); + } + Ok(quote! { + #type_name :: #variant_name (action) => action.action_event(#(#args),*), + }) + } + Fields::Named(fields_named) => { + let field_names = fields_named.named.iter().map(|named| &named.ident); + args.extend(summary_field(&v.attrs)?); + args.extend(fields(&variant_attrs.fields, &input_attrs.fields, fields_named)?); + let level = level(&variant_attrs.level, &v.ident, &input_attrs.level); + Ok(quote! { + #type_name :: #variant_name { #(#field_names),* } => openmina_core::#level!(#(#args),*), + }) + } + Fields::Unit => { + args.extend(summary_field(&v.attrs)?); + let level = level(&variant_attrs.level, &v.ident, &input_attrs.level); + Ok(quote! { + #type_name :: #variant_name => openmina_core::#level!(#(#args),*), + }) + } + } + }) + .collect::>>()?; + + Ok(quote! { + impl #trait_name for #type_name { + fn action_event(&self, context: &T) + where T: openmina_core::log::EventContext, + { + #[allow(unused_variables)] + match self { + #(#variants)* + } + } + } + }) +} + +fn level(variant_level: &Option, variant_name: &Ident, enum_level: &Option) -> Level { + variant_level + .as_ref() + .cloned() + .or_else(|| { + let s = variant_name.to_string(); + (s.ends_with("Error") || s.ends_with("Warn")).then_some(Level::Warn) + }) + .or_else(|| enum_level.as_ref().cloned()) + .unwrap_or(Level::Debug) +} + +fn fields( + variant_fields: &Option, + enum_fields: &Option, + fields: &FieldsNamed, +) -> Result> { + variant_fields + .as_ref() + .or(enum_fields.as_ref()) + .map_or_else(|| Ok(Vec::new()), |f| filter_fields(f, fields)) +} + +fn filter_fields(field_spec: &FieldsSpec, fields: &FieldsNamed) -> Result> { + match field_spec { + FieldsSpec::Some(f) => f + .iter() + .filter(|(name, _)| { + name.as_ref().map_or(true, |name| { + fields.named.iter().any(|n| Some(name) == n.ident.as_ref()) + }) + }) + .map(|(_, expr)| Ok(expr.clone())) + .collect(), + } +} + +fn action_event_attrs(attrs: &Vec) -> Result { + attrs + .iter() + .filter(|attr| attr.path().is_ident("action_event")) + .try_fold(ActionEventAttrs::default(), |mut attrs, attr| { + let nested = + attr.parse_args_with(punctuated::Punctuated::::parse_terminated)?; + nested.into_iter().try_for_each(|meta| { + match meta { + // #[level = ...] + Meta::NameValue(name_value) if name_value.path.is_ident("level") => { + let _ = attrs.level.insert(name_value.value.try_into()?); + } + // #[fields(...)] + Meta::List(list) if list.path.is_ident("fields") => { + let nested = list.parse_args_with( + punctuated::Punctuated::::parse_terminated, + )?; + let fields = nested + .iter() + .map(|meta| { + match meta { + // field + Meta::Path(path) => { + let ident = path.require_ident()?; + Ok((Some(ident.clone()), quote!(#ident = #ident))) + } + // field = expr + Meta::NameValue(name_value) => { + let field = name_value.path.require_ident()?; + let expr = &name_value.value; + match expr { + Expr::Path(ExprPath { path, .. }) => { + if let Ok(other_field) = path.require_ident() { + // field = other_field + return Ok(( + Some(other_field.clone()), + quote!(#field = #other_field), + )); + } + } + _ => {} + } + Ok((None, quote!(#field = #expr))) + } + // debug(field) + // display(field) + Meta::List(list) + if list.path.is_ident("debug") + || list.path.is_ident("display") => + { + let conv = list.path.require_ident()?; + let Expr::Path(field) = list.parse_args::()? else { + return Err(Error::new_spanned( + list, + "identifier is expected", + )); + }; + let field = field.path.require_ident()?; + Ok((Some(field.clone()), quote!(#field = #conv(#field)))) + } + _ => Err(Error::new_spanned(meta, "unrecognized repr")), + } + }) + .collect::>>()?; + let _ = attrs.fields.insert(FieldsSpec::Some(fields)); + } + _ => return Err(Error::new_spanned(meta, "unrecognized repr")), + } + Ok(()) + })?; + Ok(attrs) + }) +} + +fn summary_field(attrs: &Vec) -> Result> { + let Some(doc_attr) = attrs.iter().find(|attr| attr.path().is_ident("doc")) else { + return Ok(None); + }; + let name_value = doc_attr.meta.require_name_value()?; + let Expr::Lit(ExprLit { + lit: Lit::Str(lit), .. + }) = &name_value.value + else { + return Ok(None); + }; + let value = lit.value(); + let trimmed = value.trim(); + let stripped = trimmed.strip_suffix('.').unwrap_or(trimmed); + Ok(Some(quote!(summary = #stripped))) +} + +#[cfg(test)] +mod tests { + use rust_format::{Formatter, RustFmt}; + + fn test(input: &str, expected: &str) -> anyhow::Result<()> { + let fmt = RustFmt::default(); + + let expected = fmt.format_str(expected)?; + let input = syn::parse_str::(input)?; + let output = super::expand(input)?; + let output = fmt.format_tokens(output)?; + assert_eq!( + output, expected, + "\n<<<<<<\n{}======\n{}>>>>>>", + output, expected + ); + Ok(()) + } + + #[test] + fn test_delegate() -> anyhow::Result<()> { + let input = r#" +#[derive(openmina_macros::ActionEvent)] +pub enum SuperAction { + Sub1(SubAction1), + Sub2(SubAction2), +} +"#; + let expected = r#" +impl openmina_core::ActionEvent for SuperAction { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + #[allow(unused_variables)] + match self { + SuperAction::Sub1(action) => action.action_event(context), + SuperAction::Sub2(action) => action.action_event(context), + } + } +} +"#; + test(input, expected) + } + + #[test] + fn test_unit() -> anyhow::Result<()> { + let input = r#" +#[derive(openmina_macros::ActionEvent)] +pub enum Action { + Unit, + /// documentation + UnitWithDoc, + /// Multiline documentation. + /// Another line. + /// + /// And another. + UnitWithMultilineDoc, +} +"#; + let expected = r#" +impl openmina_core::ActionEvent for Action { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + #[allow(unused_variables)] + match self { + Action::Unit => openmina_core::action_debug!(context), + Action::UnitWithDoc => openmina_core::action_debug!(context, summary = "documentation"), + Action::UnitWithMultilineDoc => openmina_core::action_debug!(context, summary = "Multiline documentation"), + } + } +} +"#; + test(input, expected) + } + + #[test] + fn test_level() -> anyhow::Result<()> { + let input = r#" +#[derive(openmina_macros::ActionEvent)] +#[action_event(level = trace)] +pub enum Action { + ActionDefaultLevel, + #[action_event(level = warn)] + ActionOverrideLevel, + ActionWithError, + ActionWithWarn, +} +"#; + let expected = r#" +impl openmina_core::ActionEvent for Action { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + #[allow(unused_variables)] + match self { + Action::ActionDefaultLevel => openmina_core::action_trace!(context), + Action::ActionOverrideLevel => openmina_core::action_warn!(context), + Action::ActionWithError => openmina_core::action_warn!(context), + Action::ActionWithWarn => openmina_core::action_warn!(context), + } + } +} +"#; + test(input, expected) + } + + #[test] + fn test_fields() -> anyhow::Result<()> { + let input = r#" +#[derive(openmina_core::ActionEvent)] +pub enum Action { + NoFields { f1: bool }, + #[action_event(fields(f1))] + Field { f1: bool }, + #[action_event(fields(f = f1))] + FieldWithName { f1: bool }, + #[action_event(fields(debug(f1)))] + DebugField { f1: bool }, + #[action_event(fields(display(f1)))] + DisplayField { f1: bool }, +} +"#; + let expected = r#" +impl openmina_core::ActionEvent for Action { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + #[allow(unused_variables)] + match self { + Action::NoFields { f1 } => openmina_core::action_debug!(context), + Action::Field { f1 } => openmina_core::action_debug!(context, f1 = f1), + Action::FieldWithName { f1 } => openmina_core::action_debug!(context, f = f1), + Action::DebugField { f1 } => openmina_core::action_debug!(context, f1 = debug(f1)), + Action::DisplayField { f1 } => openmina_core::action_debug!(context, f1 = display(f1)), + } + } +} +"#; + test(input, expected) + } +} diff --git a/macros/src/lib.rs b/macros/src/lib.rs new file mode 100644 index 0000000000..7181354e2d --- /dev/null +++ b/macros/src/lib.rs @@ -0,0 +1,11 @@ +#[doc = include_str!("action_event.md")] +#[proc_macro_derive(ActionEvent, attributes(action_event))] +pub fn action_event(input: proc_macro::TokenStream) -> proc_macro::TokenStream { + let input = syn::parse_macro_input!(input as syn::DeriveInput); + match action_event::expand(input) { + Ok(tokens) => tokens.into(), + Err(err) => err.to_compile_error().into(), + } +} + +mod action_event; diff --git a/p2p/Cargo.toml b/p2p/Cargo.toml index e7b98421fc..98b441485b 100644 --- a/p2p/Cargo.toml +++ b/p2p/Cargo.toml @@ -42,6 +42,7 @@ mina-p2p-messages = { workspace = true } salsa-simple = { path = "../tools/salsa-simple" } openmina-core = { path = "../core" } +openmina-macros = { path = "../macros" } quick-protobuf = "0.8.1" crypto-bigint = { version = "0.5.5", features = ["generic-array", "serde", "alloc"] } diff --git a/p2p/src/network/kad/bootstrap/p2p_network_kad_bootstrap_actions.rs b/p2p/src/network/kad/bootstrap/p2p_network_kad_bootstrap_actions.rs index d721f68841..93c8041564 100644 --- a/p2p/src/network/kad/bootstrap/p2p_network_kad_bootstrap_actions.rs +++ b/p2p/src/network/kad/bootstrap/p2p_network_kad_bootstrap_actions.rs @@ -1,20 +1,21 @@ -use openmina_core::{action_debug, log::ActionEvent}; +use openmina_core::ActionEvent; use redux::EnablingCondition; use serde::{Deserialize, Serialize}; use crate::{P2pAction, P2pNetworkKadAction, P2pNetworkKadLatestRequestPeers, P2pState, PeerId}; -#[derive(Clone, Debug, Serialize, Deserialize)] +#[derive(Clone, Debug, Serialize, Deserialize, ActionEvent)] +#[action_event(fields(display(peer_id), debug(closest_peers), error))] pub enum P2pNetworkKadBootstrapAction { + /// Create `FIND_NODE` request. CreateRequests, + /// `FIND_NODE` request successful. RequestDone { peer_id: PeerId, closest_peers: P2pNetworkKadLatestRequestPeers, }, - RequestError { - peer_id: PeerId, - error: String, - }, + /// `FIND_NODE` request failed. + RequestError { peer_id: PeerId, error: String }, } impl EnablingCondition for P2pNetworkKadBootstrapAction { @@ -47,24 +48,24 @@ impl From for P2pAction { } } -impl ActionEvent for P2pNetworkKadBootstrapAction { - fn action_event(&self, context: &T) - where - T: openmina_core::log::EventContext, - { - match self { - P2pNetworkKadBootstrapAction::CreateRequests => action_debug!(context), - P2pNetworkKadBootstrapAction::RequestDone { - peer_id, - closest_peers, - } => action_debug!( - context, - peer_id = display(peer_id), - closest_peers = debug(closest_peers) - ), - P2pNetworkKadBootstrapAction::RequestError { peer_id, error } => { - action_debug!(context, peer_id = display(peer_id), error = display(error)) - } - } - } -} +// impl ActionEvent for P2pNetworkKadBootstrapAction { +// fn action_event(&self, context: &T) +// where +// T: openmina_core::log::EventContext, +// { +// match self { +// P2pNetworkKadBootstrapAction::CreateRequests => action_debug!(context), +// P2pNetworkKadBootstrapAction::RequestDone { +// peer_id, +// closest_peers, +// } => action_debug!( +// context, +// peer_id = display(peer_id), +// closest_peers = debug(closest_peers) +// ), +// P2pNetworkKadBootstrapAction::RequestError { peer_id, error } => { +// action_debug!(context, peer_id = display(peer_id), error = display(error)) +// } +// } +// } +// } diff --git a/p2p/src/network/kad/p2p_network_kad_actions.rs b/p2p/src/network/kad/p2p_network_kad_actions.rs index 33984e3266..91c87301a3 100644 --- a/p2p/src/network/kad/p2p_network_kad_actions.rs +++ b/p2p/src/network/kad/p2p_network_kad_actions.rs @@ -1,6 +1,6 @@ use std::net::SocketAddr; -use openmina_core::{action_debug, action_info, log::ActionEvent}; +use openmina_core::ActionEvent; use redux::EnablingCondition; use serde::{Deserialize, Serialize}; @@ -12,7 +12,7 @@ use crate::{ use super::bootstrap::P2pNetworkKadBootstrapAction; /// Kademlia actions. -#[derive(Debug, Clone, Serialize, Deserialize, derive_more::From)] +#[derive(Debug, Clone, Serialize, Deserialize, derive_more::From, ActionEvent)] pub enum P2pNetworkKadAction { System(P2pNetworkKademliaAction), Bootstrap(P2pNetworkKadBootstrapAction), @@ -38,8 +38,17 @@ impl From for P2pAction { } /// Kademlia system actions -#[derive(Debug, Clone, Serialize, Deserialize)] +#[derive(Debug, Clone, Serialize, Deserialize, ActionEvent)] +#[action_event(fields( + display(addr), + display(peer_id), + stream_id, + display(key), + debug(closest_peers) +))] pub enum P2pNetworkKademliaAction { + /// Answer `FIND_NODE` request. + /// /// Answers peer's `FIND_NODE` request by querying routing table for closest nodes. AnswerFindNodeRequest { addr: SocketAddr, @@ -47,6 +56,8 @@ pub enum P2pNetworkKademliaAction { stream_id: StreamId, key: PeerId, }, + /// Udate result of scheduled outgoing `FIND_NODE`. + /// /// Udates result of scheduled outgoing `FIND_NODE` request to a peer. UpdateFindNodeRequest { addr: SocketAddr, @@ -54,9 +65,11 @@ pub enum P2pNetworkKademliaAction { stream_id: StreamId, closest_peers: Vec, }, - /// Performs local node's Kademlia bootstrap. + /// Perform local node's Kademlia bootstrap. + #[action_event(level = info)] StartBootstrap { key: PeerId }, /// Bootstrap is finished. + #[action_event(level = info)] BootstrapFinished, } @@ -96,54 +109,40 @@ impl From for P2pAction { } } -impl ActionEvent for P2pNetworkKadAction { - fn action_event(&self, context: &T) - where - T: openmina_core::log::EventContext, - { - match self { - P2pNetworkKadAction::System(action) => action.action_event(context), - P2pNetworkKadAction::Bootstrap(action) => action.action_event(context), - P2pNetworkKadAction::Request(action) => action.action_event(context), - P2pNetworkKadAction::Stream(action) => action.action_event(context), - } - } -} - -impl ActionEvent for P2pNetworkKademliaAction { - fn action_event(&self, context: &T) - where - T: openmina_core::log::EventContext, - { - match self { - P2pNetworkKademliaAction::AnswerFindNodeRequest { - addr, - peer_id, - stream_id, - key, - } => action_debug!( - context, - addr = display(addr), - peer_id = display(peer_id), - stream_id, - key = display(key) - ), - P2pNetworkKademliaAction::UpdateFindNodeRequest { - addr, - peer_id, - stream_id, - closest_peers, - } => action_debug!( - context, - addr = display(addr), - peer_id = display(peer_id), - stream_id, - closest_peers = debug(closest_peers) - ), - P2pNetworkKademliaAction::StartBootstrap { key } => { - action_info!(context, key = display(key)) - } - P2pNetworkKademliaAction::BootstrapFinished => action_debug!(context), - } - } -} +// impl ActionEvent for P2pNetworkKademliaAction { +// fn action_event(&self, context: &T) +// where +// T: openmina_core::log::EventContext, +// { +// match self { +// P2pNetworkKademliaAction::AnswerFindNodeRequest { +// addr, +// peer_id, +// stream_id, +// key, +// } => action_debug!( +// context, +// addr = display(addr), +// peer_id = display(peer_id), +// stream_id, +// key = display(key) +// ), +// P2pNetworkKademliaAction::UpdateFindNodeRequest { +// addr, +// peer_id, +// stream_id, +// closest_peers, +// } => action_debug!( +// context, +// addr = display(addr), +// peer_id = display(peer_id), +// stream_id, +// closest_peers = debug(closest_peers) +// ), +// P2pNetworkKademliaAction::StartBootstrap { key } => { +// action_info!(context, key = display(key)) +// } +// P2pNetworkKademliaAction::BootstrapFinished => action_debug!(context), +// } +// } +// } diff --git a/p2p/src/network/kad/request/p2p_network_kad_request_actions.rs b/p2p/src/network/kad/request/p2p_network_kad_request_actions.rs index b035323d36..2f38cc30a7 100644 --- a/p2p/src/network/kad/request/p2p_network_kad_request_actions.rs +++ b/p2p/src/network/kad/request/p2p_network_kad_request_actions.rs @@ -1,12 +1,13 @@ use std::net::SocketAddr; -use openmina_core::{action_debug, action_trace, log::ActionEvent}; +use openmina_core::ActionEvent; use redux::EnablingCondition; use serde::{Deserialize, Serialize}; use crate::{P2pAction, P2pNetworkKadEntry, P2pState, PeerId, StreamId}; -#[derive(Clone, Debug, Serialize, Deserialize)] +#[derive(Clone, Debug, Serialize, Deserialize, ActionEvent)] +#[action_event(fields(display(peer_id), display(addr), display(key), stream_id, error))] pub enum P2pNetworkKadRequestAction { New { peer_id: PeerId, @@ -37,6 +38,7 @@ pub enum P2pNetworkKadRequestAction { stream_id: StreamId, data: Vec, }, + #[action_event(level = trace)] Prune { peer_id: PeerId, }, @@ -82,56 +84,56 @@ impl From for P2pAction { } } -impl ActionEvent for P2pNetworkKadRequestAction { - fn action_event(&self, context: &T) - where - T: openmina_core::log::EventContext, - { - match self { - P2pNetworkKadRequestAction::New { peer_id, addr, key } => action_debug!( - context, - peer_id = display(peer_id), - addr = display(addr), - key = display(key) - ), - P2pNetworkKadRequestAction::PeerIsConnecting { peer_id } => { - action_debug!(context, peer_id = display(peer_id)) - } - P2pNetworkKadRequestAction::MuxReady { peer_id, addr } => { - action_debug!(context, peer_id = display(peer_id), addr = display(addr)) - } - P2pNetworkKadRequestAction::StreamIsCreating { peer_id, stream_id } => { - action_debug!(context, peer_id = display(peer_id), stream_id) - } - P2pNetworkKadRequestAction::StreamReady { - peer_id, - stream_id, - addr, - } => action_debug!( - context, - peer_id = display(peer_id), - stream_id, - addr = display(addr) - ), - P2pNetworkKadRequestAction::RequestSent { peer_id } => { - action_debug!(context, peer_id = display(peer_id)) - } - P2pNetworkKadRequestAction::ReplyReceived { - peer_id, - stream_id, - data, - } => action_debug!( - context, - peer_id = display(peer_id), - stream_id, - data = debug(data) - ), - P2pNetworkKadRequestAction::Prune { peer_id } => { - action_trace!(context, peer_id = display(peer_id)) - } - P2pNetworkKadRequestAction::Error { peer_id, error } => { - action_debug!(context, peer_id = display(peer_id), error = display(error)) - } - } - } -} +// impl ActionEvent for P2pNetworkKadRequestAction { +// fn action_event(&self, context: &T) +// where +// T: openmina_core::log::EventContext, +// { +// match self { +// P2pNetworkKadRequestAction::New { peer_id, addr, key } => action_debug!( +// context, +// peer_id = display(peer_id), +// addr = display(addr), +// key = display(key) +// ), +// P2pNetworkKadRequestAction::PeerIsConnecting { peer_id } => { +// action_debug!(context, peer_id = display(peer_id)) +// } +// P2pNetworkKadRequestAction::MuxReady { peer_id, addr } => { +// action_debug!(context, peer_id = display(peer_id), addr = display(addr)) +// } +// P2pNetworkKadRequestAction::StreamIsCreating { peer_id, stream_id } => { +// action_debug!(context, peer_id = display(peer_id), stream_id) +// } +// P2pNetworkKadRequestAction::StreamReady { +// peer_id, +// stream_id, +// addr, +// } => action_debug!( +// context, +// peer_id = display(peer_id), +// stream_id, +// addr = display(addr) +// ), +// P2pNetworkKadRequestAction::RequestSent { peer_id } => { +// action_debug!(context, peer_id = display(peer_id)) +// } +// P2pNetworkKadRequestAction::ReplyReceived { +// peer_id, +// stream_id, +// data, +// } => action_debug!( +// context, +// peer_id = display(peer_id), +// stream_id, +// data = debug(data) +// ), +// P2pNetworkKadRequestAction::Prune { peer_id } => { +// action_trace!(context, peer_id = display(peer_id)) +// } +// P2pNetworkKadRequestAction::Error { peer_id, error } => { +// action_debug!(context, peer_id = display(peer_id), error = display(error)) +// } +// } +// } +// } diff --git a/p2p/src/network/kad/request/p2p_network_kad_request_effects.rs b/p2p/src/network/kad/request/p2p_network_kad_request_effects.rs index 2a1b7cfd11..510e66f4ce 100644 --- a/p2p/src/network/kad/request/p2p_network_kad_request_effects.rs +++ b/p2p/src/network/kad/request/p2p_network_kad_request_effects.rs @@ -1,6 +1,5 @@ use std::net::SocketAddr; -use openmina_core::warn; use redux::ActionMeta; use crate::{ @@ -18,7 +17,7 @@ use crate::{ use super::{super::stream::P2pNetworkKademliaStreamAction, P2pNetworkKadRequestAction}; impl P2pNetworkKadRequestAction { - pub fn effects(self, meta: &ActionMeta, store: &mut Store) -> Result<(), String> + pub fn effects(self, _meta: &ActionMeta, store: &mut Store) -> Result<(), String> where Store: crate::P2pStore, { @@ -186,7 +185,6 @@ impl P2pNetworkKadRequestAction { store.dispatch(P2pNetworkKadRequestAction::Prune { peer_id }); } A::Error { peer_id, error } => { - warn!(meta.time(); "error requesting FIND_NODE: {error}"); let bootstrap_request = discovery_state .bootstrap_state() .and_then(|bootstrap_state| bootstrap_state.request(&peer_id)) diff --git a/p2p/src/network/kad/stream/p2p_network_kad_stream_actions.rs b/p2p/src/network/kad/stream/p2p_network_kad_stream_actions.rs index fceaa781fb..fd8ba3abac 100644 --- a/p2p/src/network/kad/stream/p2p_network_kad_stream_actions.rs +++ b/p2p/src/network/kad/stream/p2p_network_kad_stream_actions.rs @@ -1,6 +1,6 @@ use std::net::SocketAddr; -use openmina_core::{action_debug, action_trace, log::ActionEvent}; +use openmina_core::ActionEvent; use redux::EnablingCondition; use serde::{Deserialize, Serialize}; @@ -10,7 +10,8 @@ use crate::{ }; /// Kademlia stream related actions. -#[derive(Debug, Clone, Serialize, Deserialize)] +#[derive(Debug, Clone, Serialize, Deserialize, ActionEvent)] +#[action_event(fields(display(addr), display(peer_id), stream_id, incoming, debug(data)))] pub enum P2pNetworkKademliaStreamAction { /// Creates a new stream state. New { @@ -76,6 +77,7 @@ pub enum P2pNetworkKademliaStreamAction { }, /// Removes the closed stream from the state. + #[action_event(level = trace)] Prune { addr: SocketAddr, peer_id: PeerId, @@ -121,120 +123,120 @@ impl From for P2pAction { } } -impl ActionEvent for P2pNetworkKademliaStreamAction { - fn action_event(&self, context: &T) - where - T: openmina_core::log::EventContext, - { - match self { - P2pNetworkKademliaStreamAction::New { - addr, - peer_id, - stream_id, - incoming, - } => action_debug!( - context, - addr = display(addr), - peer_id = display(peer_id), - stream_id, - incoming - ), - P2pNetworkKademliaStreamAction::IncomingData { - addr, - peer_id, - stream_id, - data, - } => action_debug!( - context, - addr = display(addr), - peer_id = display(peer_id), - stream_id, - data = debug(data) - ), - P2pNetworkKademliaStreamAction::RemoteClose { - addr, - peer_id, - stream_id, - } => action_debug!( - context, - addr = display(addr), - peer_id = display(peer_id), - stream_id - ), - P2pNetworkKademliaStreamAction::WaitIncoming { - addr, - peer_id, - stream_id, - } => action_debug!( - context, - addr = display(addr), - peer_id = display(peer_id), - stream_id - ), - P2pNetworkKademliaStreamAction::WaitOutgoing { - addr, - peer_id, - stream_id, - } => action_debug!( - context, - addr = display(addr), - peer_id = display(peer_id), - stream_id - ), - P2pNetworkKademliaStreamAction::SendRequest { - addr, - peer_id, - stream_id, - data, - } => action_debug!( - context, - addr = display(addr), - peer_id = display(peer_id), - stream_id, - data = debug(data) - ), - P2pNetworkKademliaStreamAction::SendResponse { - addr, - peer_id, - stream_id, - data, - } => action_debug!( - context, - addr = display(addr), - peer_id = display(peer_id), - stream_id, - data = debug(data) - ), - P2pNetworkKademliaStreamAction::OutgoingDataReady { - addr, - peer_id, - stream_id, - } => action_debug!( - context, - addr = display(addr), - peer_id = display(peer_id), - stream_id - ), - P2pNetworkKademliaStreamAction::Close { - addr, - peer_id, - stream_id, - } => action_debug!( - context, - addr = display(addr), - peer_id = display(peer_id), - stream_id - ), - P2pNetworkKademliaStreamAction::Prune { - addr, - peer_id, - stream_id, - } => action_trace!( - context, - addr = display(addr), - peer_id = display(peer_id), - stream_id - ), - } - } -} +// impl ActionEvent for P2pNetworkKademliaStreamAction { +// fn action_event(&self, context: &T) +// where +// T: openmina_core::log::EventContext, +// { +// match self { +// P2pNetworkKademliaStreamAction::New { +// addr, +// peer_id, +// stream_id, +// incoming, +// } => action_debug!( +// context, +// addr = display(addr), +// peer_id = display(peer_id), +// stream_id, +// incoming +// ), +// P2pNetworkKademliaStreamAction::IncomingData { +// addr, +// peer_id, +// stream_id, +// data, +// } => action_debug!( +// context, +// addr = display(addr), +// peer_id = display(peer_id), +// stream_id, +// data = debug(data) +// ), +// P2pNetworkKademliaStreamAction::RemoteClose { +// addr, +// peer_id, +// stream_id, +// } => action_debug!( +// context, +// addr = display(addr), +// peer_id = display(peer_id), +// stream_id +// ), +// P2pNetworkKademliaStreamAction::WaitIncoming { +// addr, +// peer_id, +// stream_id, +// } => action_debug!( +// context, +// addr = display(addr), +// peer_id = display(peer_id), +// stream_id +// ), +// P2pNetworkKademliaStreamAction::WaitOutgoing { +// addr, +// peer_id, +// stream_id, +// } => action_debug!( +// context, +// addr = display(addr), +// peer_id = display(peer_id), +// stream_id +// ), +// P2pNetworkKademliaStreamAction::SendRequest { +// addr, +// peer_id, +// stream_id, +// data, +// } => action_debug!( +// context, +// addr = display(addr), +// peer_id = display(peer_id), +// stream_id, +// data = debug(data) +// ), +// P2pNetworkKademliaStreamAction::SendResponse { +// addr, +// peer_id, +// stream_id, +// data, +// } => action_debug!( +// context, +// addr = display(addr), +// peer_id = display(peer_id), +// stream_id, +// data = debug(data) +// ), +// P2pNetworkKademliaStreamAction::OutgoingDataReady { +// addr, +// peer_id, +// stream_id, +// } => action_debug!( +// context, +// addr = display(addr), +// peer_id = display(peer_id), +// stream_id +// ), +// P2pNetworkKademliaStreamAction::Close { +// addr, +// peer_id, +// stream_id, +// } => action_debug!( +// context, +// addr = display(addr), +// peer_id = display(peer_id), +// stream_id +// ), +// P2pNetworkKademliaStreamAction::Prune { +// addr, +// peer_id, +// stream_id, +// } => action_trace!( +// context, +// addr = display(addr), +// peer_id = display(peer_id), +// stream_id +// ), +// } +// } +// } From d041277a775f337c501be341b423a0cedb937523 Mon Sep 17 00:00:00 2001 From: Alexander Koptelov Date: Thu, 4 Apr 2024 20:29:40 +0300 Subject: [PATCH 4/7] feat(actions): subfield access support --- macros/src/action_event.rs | 71 ++++++++++++++++++++++++++++++-------- 1 file changed, 57 insertions(+), 14 deletions(-) diff --git a/macros/src/action_event.rs b/macros/src/action_event.rs index 45f8281cd0..ed7cd255a2 100644 --- a/macros/src/action_event.rs +++ b/macros/src/action_event.rs @@ -190,21 +190,10 @@ fn action_event_attrs(attrs: &Vec) -> Result { } // field = expr Meta::NameValue(name_value) => { - let field = name_value.path.require_ident()?; + let event_field = name_value.path.require_ident()?; let expr = &name_value.value; - match expr { - Expr::Path(ExprPath { path, .. }) => { - if let Ok(other_field) = path.require_ident() { - // field = other_field - return Ok(( - Some(other_field.clone()), - quote!(#field = #other_field), - )); - } - } - _ => {} - } - Ok((None, quote!(#field = #expr))) + let maybe_field = get_field_name(expr); + Ok((maybe_field.cloned(), quote!(#event_field = #expr))) } // debug(field) // display(field) @@ -236,6 +225,23 @@ fn action_event_attrs(attrs: &Vec) -> Result { }) } +fn get_field_name(expr: &Expr) -> Option<&Ident> { + match expr { + Expr::Path(path) => path.path.require_ident().ok(), + Expr::Field(field) => get_field_name(&field.base), + Expr::Reference(reference) => get_field_name(&reference.expr), + Expr::Unary(ExprUnary { expr, .. }) => get_field_name(expr), + Expr::Call(call) => match call.func.as_ref() { + Expr::Path(path) if path.path.is_ident("display") || path.path.is_ident("debug") => { + call.args.first().and_then(|arg| get_field_name(arg)) + } + Expr::Field(field) => get_field_name(&field.base), + _ => None, + }, + _ => None, + } +} + fn summary_field(attrs: &Vec) -> Result> { let Some(doc_attr) = attrs.iter().find(|attr| attr.path().is_ident("doc")) else { return Ok(None); @@ -373,6 +379,10 @@ pub enum Action { Field { f1: bool }, #[action_event(fields(f = f1))] FieldWithName { f1: bool }, + #[action_event(fields(f = f.subfield))] + FieldExpr { f: WithSubfield }, + #[action_event(fields(f = display(f.subfield)))] + FieldDisplayExpr { f: WithSubfield }, #[action_event(fields(debug(f1)))] DebugField { f1: bool }, #[action_event(fields(display(f1)))] @@ -390,11 +400,44 @@ impl openmina_core::ActionEvent for Action { Action::NoFields { f1 } => openmina_core::action_debug!(context), Action::Field { f1 } => openmina_core::action_debug!(context, f1 = f1), Action::FieldWithName { f1 } => openmina_core::action_debug!(context, f = f1), + Action::FieldExpr { f } => openmina_core::action_debug!(context, f = f.subfield), + Action::FieldDisplayExpr { f } => openmina_core::action_debug!(context, f = display(f.subfield)), Action::DebugField { f1 } => openmina_core::action_debug!(context, f1 = debug(f1)), Action::DisplayField { f1 } => openmina_core::action_debug!(context, f1 = display(f1)), } } } +"#; + test(input, expected) + } + + #[test] + fn test_filtered_fields() -> anyhow::Result<()> { + let input = r#" +#[derive(openmina_core::ActionEvent)] +#[action_event(fields(f1, f2 = f2.sub, f3 = display(f3.sub), f4 = foo()))] +pub enum Action { + Unit, + AllFields { f1: bool, f2: WithSub, f3: WithSub }, + OnlyF1 { f1: bool }, + WithF3 { f1: bool, f3: WithSub }, +} +"#; + let expected = r#" +impl openmina_core::ActionEvent for Action { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + #[allow(unused_variables)] + match self { + Action::Unit => openmina_core::action_debug!(context), + Action::AllFields { f1, f2, f3 } => openmina_core::action_debug!(context, f1 = f1, f2 = f2.sub, f3 = display(f3.sub), f4 = foo()), + Action::OnlyF1 { f1 } => openmina_core::action_debug!(context, f1 = f1, f4 = foo()), + Action::WithF3 { f1, f3 } => openmina_core::action_debug!(context, f1 = f1, f3 = display(f3.sub), f4 = foo()), + } + } +} "#; test(input, expected) } From 6a1ba4f1329094cca9d743965e249ee421a5120d Mon Sep 17 00:00:00 2001 From: Alexander Koptelov Date: Thu, 4 Apr 2024 22:21:25 +0300 Subject: [PATCH 5/7] feat(actions): derive: arbitrary expr --- macros/src/action_event.md | 31 +++++++++++++++++++++++++++ macros/src/action_event.rs | 43 ++++++++++++++++++++++++++++++++++++++ 2 files changed, 74 insertions(+) diff --git a/macros/src/action_event.md b/macros/src/action_event.md index d7cac3d096..40e2432ecf 100644 --- a/macros/src/action_event.md +++ b/macros/src/action_event.md @@ -151,3 +151,34 @@ impl openmina_core::ActionEvent for Action { } } ``` + +### Logging using custom expression. + +When an action needs some custom logic to log (e.g. different logging basing on +a field's enum variant), logging can be delegated to a function implementing +that logic. + +``` +#[derive(openmina_core::ActionEvent)] +pub enum Action { + #[action_event(expr(foo(context)))] + Unit, + #[action_event(expr(bar(context, f1)))] + Named { f1: bool }, +} +``` + +``` +impl openmina_core::ActionEvent for Action { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + #[allow(unused_variables)] + match self { + Action::Unit => foo(context), + Action::Named { f1 } => bar(context, f1), + } + } +} +``` diff --git a/macros/src/action_event.rs b/macros/src/action_event.rs index ed7cd255a2..abf97a4890 100644 --- a/macros/src/action_event.rs +++ b/macros/src/action_event.rs @@ -56,6 +56,7 @@ enum FieldsSpec { struct ActionEventAttrs { level: Option, fields: Option, + expr: Option, } pub fn expand(input: DeriveInput) -> Result { @@ -92,6 +93,11 @@ pub fn expand(input: DeriveInput) -> Result { } Fields::Named(fields_named) => { let field_names = fields_named.named.iter().map(|named| &named.ident); + if let Some(expr) = variant_attrs.expr { + return Ok(quote! { + #type_name :: #variant_name { #(#field_names),* } => #expr, + }); + } args.extend(summary_field(&v.attrs)?); args.extend(fields(&variant_attrs.fields, &input_attrs.fields, fields_named)?); let level = level(&variant_attrs.level, &v.ident, &input_attrs.level); @@ -100,6 +106,11 @@ pub fn expand(input: DeriveInput) -> Result { }) } Fields::Unit => { + if let Some(expr) = variant_attrs.expr { + return Ok(quote! { + #type_name :: #variant_name => #expr, + }); + } args.extend(summary_field(&v.attrs)?); let level = level(&variant_attrs.level, &v.ident, &input_attrs.level); Ok(quote! { @@ -174,6 +185,10 @@ fn action_event_attrs(attrs: &Vec) -> Result { Meta::NameValue(name_value) if name_value.path.is_ident("level") => { let _ = attrs.level.insert(name_value.value.try_into()?); } + // #[expr(...)] + Meta::List(list) if list.path.is_ident("expr") => { + let _ = attrs.expr.insert(list.parse_args::()?); + } // #[fields(...)] Meta::List(list) if list.path.is_ident("fields") => { let nested = list.parse_args_with( @@ -438,6 +453,34 @@ impl openmina_core::ActionEvent for Action { } } } +"#; + test(input, expected) + } + + #[test] + fn test_call() -> anyhow::Result<()> { + let input = r#" +#[derive(openmina_core::ActionEvent)] +pub enum Action { + #[action_event(expr(foo(context)))] + Unit, + #[action_event(expr(foo(context, f1)))] + Named { f1: bool }, +} +"#; + let expected = r#" +impl openmina_core::ActionEvent for Action { + fn action_event(&self, context: &T) + where + T: openmina_core::log::EventContext, + { + #[allow(unused_variables)] + match self { + Action::Unit => foo(context), + Action::Named { f1 } => foo(context, f1), + } + } +} "#; test(input, expected) } From cb3f37b1af8ae87d75ea31ab686b4317c226f5af Mon Sep 17 00:00:00 2001 From: Alexander Koptelov Date: Thu, 4 Apr 2024 22:22:00 +0300 Subject: [PATCH 6/7] feat(actions): derive all ActionEvent --- .../block_producer/block_producer_actions.rs | 44 ++-- .../block_producer_vrf_evaluator_actions.rs | 205 +++++------------- .../external_snark_worker_actions.rs | 34 +-- .../transition_frontier_genesis_actions.rs | 26 +-- ...on_frontier_sync_ledger_snarked_actions.rs | 4 +- ...ion_frontier_sync_ledger_staged_actions.rs | 4 +- ...transition_frontier_sync_ledger_actions.rs | 3 +- .../sync/transition_frontier_sync_actions.rs | 60 ++--- .../transition_frontier_actions.rs | 33 +-- .../best_tip/p2p_channels_best_tip_actions.rs | 46 +--- .../channels/rpc/p2p_channels_rpc_actions.rs | 67 +----- .../snark/p2p_channels_snark_actions.rs | 70 +----- ...p_channels_snark_job_commitment_actions.rs | 54 +---- .../p2p_connection_incoming_actions.rs | 65 ++---- .../p2p_connection_outgoing_actions.rs | 81 ++----- .../p2p_disconnection_actions.rs | 29 +-- p2p/src/discovery/p2p_discovery_actions.rs | 36 +-- p2p/src/listen/p2p_listen_actions.rs | 31 +-- .../p2p_network_kad_bootstrap_actions.rs | 22 -- .../network/kad/p2p_network_kad_actions.rs | 38 ---- .../p2p_network_kad_request_actions.rs | 54 ----- .../stream/p2p_network_kad_stream_actions.rs | 118 ---------- .../noise/p2p_network_noise_actions.rs | 51 +---- .../network/pnet/p2p_network_pnet_actions.rs | 25 +-- .../network/rpc/p2p_network_rpc_actions.rs | 152 ++++--------- .../p2p_network_scheduler_actions.rs | 82 +------ .../select/p2p_network_select_actions.rs | 54 +---- .../yamux/p2p_network_yamux_actions.rs | 51 +---- p2p/src/peer/p2p_peer_actions.rs | 34 +-- .../work_verify/snark_work_verify_actions.rs | 36 +-- 30 files changed, 246 insertions(+), 1363 deletions(-) diff --git a/node/src/block_producer/block_producer_actions.rs b/node/src/block_producer/block_producer_actions.rs index 3c5a1c53a9..328cda6108 100644 --- a/node/src/block_producer/block_producer_actions.rs +++ b/node/src/block_producer/block_producer_actions.rs @@ -1,7 +1,6 @@ use mina_p2p_messages::v2::MinaBaseProofStableV2; use openmina_core::block::ArcBlockWithHash; -use openmina_core::log::ActionEvent; -use openmina_core::{action_info, action_trace}; +use openmina_core::ActionEvent; use serde::{Deserialize, Serialize}; use super::vrf_evaluator::BlockProducerVrfEvaluatorAction; @@ -13,13 +12,24 @@ use super::{ pub type BlockProducerActionWithMeta = redux::ActionWithMeta; pub type BlockProducerActionWithMetaRef<'a> = redux::ActionWithMeta<&'a BlockProducerAction>; -#[derive(Serialize, Deserialize, Debug, Clone)] +#[derive(Serialize, Deserialize, Debug, Clone, ActionEvent)] +#[action_event(level = trace)] pub enum BlockProducerAction { VrfEvaluator(BlockProducerVrfEvaluatorAction), BestTipUpdate { best_tip: ArcBlockWithHash, }, WonSlotSearch, + #[action_event( + level = info, + fields( + slot = won_slot.global_slot.slot_number.as_u32(), + slot_time = openmina_core::log::to_rfc_3339(won_slot.slot_time) + .unwrap_or_else(|_| "".to_owned()), + current_time = openmina_core::log::to_rfc_3339(context.timestamp()) + .unwrap_or_else(|_| "".to_owned()), + ) + )] WonSlot { won_slot: BlockProducerWonSlot, }, @@ -148,31 +158,3 @@ impl redux::EnablingCondition for BlockProducerAction { } } } - -impl ActionEvent for BlockProducerAction { - fn action_event(&self, context: &T) - where - T: openmina_core::log::EventContext, - { - match self { - BlockProducerAction::VrfEvaluator(action) => action.action_event(context), - BlockProducerAction::WonSlot { - won_slot: - BlockProducerWonSlot { - slot_time, - global_slot, - .. - }, - } => action_info!( - context, - summary = "Won slot", - slot = global_slot.slot_number.as_u32(), - slot_time = openmina_core::log::to_rfc_3339(*slot_time) - .unwrap_or_else(|_| "".to_owned()), - current_time = openmina_core::log::to_rfc_3339(context.timestamp()) - .unwrap_or_else(|_| "".to_owned()), - ), - _ => action_trace!(context), - } - } -} diff --git a/node/src/block_producer/vrf_evaluator/block_producer_vrf_evaluator_actions.rs b/node/src/block_producer/vrf_evaluator/block_producer_vrf_evaluator_actions.rs index 649d04a09a..c2e15e5dfd 100644 --- a/node/src/block_producer/vrf_evaluator/block_producer_vrf_evaluator_actions.rs +++ b/node/src/block_producer/vrf_evaluator/block_producer_vrf_evaluator_actions.rs @@ -6,9 +6,8 @@ use mina_p2p_messages::v2::{ ConsensusProofOfStakeDataEpochDataStakingValueVersionedValueStableV1, LedgerHash, }; use openmina_core::action_info; -use openmina_core::action_trace; use openmina_core::block::ArcBlockWithHash; -use openmina_core::log::ActionEvent; +use openmina_core::ActionEvent; use serde::{Deserialize, Serialize}; use vrf::VrfEvaluationOutput; use vrf::VrfWonSlot; @@ -20,21 +19,26 @@ pub type BlockProducerVrfEvaluatorActionWithMeta = pub type BlockProducerVrfEvaluatorActionWithMetaRef<'a> = redux::ActionWithMeta<&'a BlockProducerVrfEvaluatorAction>; -#[derive(Serialize, Deserialize, Debug, Clone)] +#[derive(Serialize, Deserialize, Debug, Clone, ActionEvent)] +#[action_event(level = info)] pub enum BlockProducerVrfEvaluatorAction { - EvaluateSlot { - vrf_input: VrfEvaluatorInput, - }, + /// Vrf Evaluation requested. + #[action_event(fields(debug(vrp_input)))] + EvaluateSlot { vrf_input: VrfEvaluatorInput }, + /// Evaluation successful. + #[action_event(expr(log_vrf_output(context, vrf_output)))] ProcessSlotEvaluationSuccess { vrf_output: VrfEvaluationOutput, staking_ledger_hash: LedgerHash, }, - InitializeEvaluator { - best_tip: ArcBlockWithHash, - }, + #[action_event(level = trace)] + InitializeEvaluator { best_tip: ArcBlockWithHash }, + /// Checking possible Vrf evaluations. FinalizeEvaluatorInitialization { previous_epoch_and_height: Option<(u32, u32)>, }, + /// Checking possible Vrf evaluations. + #[action_event(level = info, fields(current_epoch_number, current_best_tip_slot, current_best_tip_global_slot))] CheckEpochEvaluability { current_epoch_number: u32, current_best_tip_height: u32, @@ -45,6 +49,8 @@ pub enum BlockProducerVrfEvaluatorAction { next_epoch_data: ConsensusProofOfStakeDataEpochDataNextValueVersionedValueStableV1, transition_frontier_size: u32, }, + /// Initalize epoch vrf evaluation. + #[action_event(level = info, fields(current_epoch_number, current_best_tip_slot, current_best_tip_global_slot))] InitializeEpochEvaluation { current_epoch_number: u32, current_best_tip_slot: u32, @@ -55,6 +61,8 @@ pub enum BlockProducerVrfEvaluatorAction { producer: AccountPublicKey, transition_frontier_size: u32, }, + /// Constructing delegator table. + #[action_event(level = info, fields(current_epoch_number, current_best_tip_slot, current_best_tip_global_slot))] BeginDelegatorTableConstruction { staking_epoch_data: EpochData, producer: AccountPublicKey, @@ -65,6 +73,8 @@ pub enum BlockProducerVrfEvaluatorAction { next_epoch_first_slot: u32, transition_frontier_size: u32, }, + /// Delegator table constructed. + #[action_event(level = info, fields(current_epoch_number, current_best_tip_slot, current_best_tip_global_slot))] FinalizeDelegatorTableConstruction { staking_epoch_data: EpochData, producer: AccountPublicKey, @@ -75,6 +85,8 @@ pub enum BlockProducerVrfEvaluatorAction { next_epoch_first_slot: u32, transition_frontier_size: u32, }, + /// Selecting starting slot. + #[action_event(level = info, fields(current_global_slot, current_best_tip_height))] SelectInitialSlot { current_global_slot: u32, current_best_tip_height: u32, @@ -84,6 +96,8 @@ pub enum BlockProducerVrfEvaluatorAction { staking_epoch_data: EpochData, next_epoch_first_slot: u32, }, + /// Starting epoch evaluation. + #[action_event(level = info, fields(current_epoch_number, current_best_tip_slot, current_best_tip_global_slot))] BeginEpochEvaluation { current_best_tip_height: u32, current_best_tip_slot: u32, @@ -92,18 +106,25 @@ pub enum BlockProducerVrfEvaluatorAction { staking_epoch_data: EpochData, latest_evaluated_global_slot: u32, }, + /// Saving last block height in epoch. + #[action_event(level = info, fields(epoch_number, last_block_height))] RecordLastBlockHeightInEpoch { epoch_number: u32, last_block_height: u32, }, + #[action_event(level = trace)] ContinueEpochEvaluation { latest_evaluated_global_slot: u32, epoch_number: u32, }, + /// Epoch evaluation finished. + #[action_event(level = info, fields(epoch_number, latest_evaluated_global_slot))] FinishEpochEvaluation { epoch_number: u32, latest_evaluated_global_slot: u32, }, + /// Waiting for epoch to evaluate. + #[action_event(level = info, fields(current_epoch_number, current_best_tip_height))] WaitForNextEvaluation { current_epoch_number: u32, current_best_tip_height: u32, @@ -112,13 +133,15 @@ pub enum BlockProducerVrfEvaluatorAction { last_epoch_block_height: Option, transition_frontier_size: u32, }, + /// Checking epoch bounds. + #[action_event(level = trace)] CheckEpochBounds { epoch_number: u32, latest_evaluated_global_slot: u32, }, - CleanupOldSlots { - current_epoch_number: u32, - }, + /// Cleaning up old won slots. + #[action_event(level = trace)] + CleanupOldSlots { current_epoch_number: u32 }, } impl redux::EnablingCondition for BlockProducerVrfEvaluatorAction { @@ -222,147 +245,23 @@ impl From for crate::Action { } } -impl ActionEvent for BlockProducerVrfEvaluatorAction { - fn action_event(&self, context: &T) - where - T: openmina_core::log::EventContext, - { - match self { - BlockProducerVrfEvaluatorAction::EvaluateSlot { vrf_input } => action_info!( - context, - summary = "Vrf Evaluation requested", - input = debug(vrf_input) - ), - BlockProducerVrfEvaluatorAction::ProcessSlotEvaluationSuccess { - vrf_output, .. - } => match vrf_output { - VrfEvaluationOutput::SlotWon(VrfWonSlot { - global_slot, - vrf_output, - .. - }) => action_info!( - context, - summary = "Slot evaluation result - won slot", - global_slot, - vrf_output = display(vrf_output) - ), - VrfEvaluationOutput::SlotLost(_) => { - action_info!(context, summary = "Slot evaluation result - lost slot") - } - }, - BlockProducerVrfEvaluatorAction::InitializeEvaluator { .. } => { - action_trace!(context) - } - BlockProducerVrfEvaluatorAction::FinalizeEvaluatorInitialization { .. } => { - action_info!(context, summary = "Vrf evaluator initilaized") - } - BlockProducerVrfEvaluatorAction::CheckEpochEvaluability { - current_epoch_number, - current_best_tip_slot, - current_best_tip_global_slot, - .. - } => action_info!( - context, - summary = "Checking possible Vrf evaluations", - current_epoch_number, - current_best_tip_slot, - current_best_tip_global_slot - ), - BlockProducerVrfEvaluatorAction::InitializeEpochEvaluation { - current_epoch_number, - current_best_tip_slot, - current_best_tip_global_slot, - .. - } => action_info!( - context, - summary = "Constructing delegator table", /* TODO: check the name*/ - current_epoch_number, - current_best_tip_slot, - current_best_tip_global_slot - ), - BlockProducerVrfEvaluatorAction::BeginDelegatorTableConstruction { - current_epoch_number, - current_best_tip_slot, - current_best_tip_global_slot, - .. - } => action_info!( - context, - summary = "Constructing delegator table", - current_epoch_number, - current_best_tip_slot, - current_best_tip_global_slot - ), - BlockProducerVrfEvaluatorAction::FinalizeDelegatorTableConstruction { - current_epoch_number, - current_best_tip_slot, - current_best_tip_global_slot, - .. - } => action_info!( - context, - summary = "Delegator table constructed", - current_epoch_number, - current_best_tip_slot, - current_best_tip_global_slot - ), - BlockProducerVrfEvaluatorAction::SelectInitialSlot { - current_global_slot, - current_best_tip_height, - .. - } => action_info!( - context, - summary = "Selecting starting slot", - current_global_slot, - current_best_tip_height - ), - BlockProducerVrfEvaluatorAction::BeginEpochEvaluation { - current_epoch_number, - current_best_tip_slot, - current_best_tip_global_slot, - .. - } => action_info!( - context, - summary = "Starting epoch evaluation", - current_epoch_number, - current_best_tip_slot, - current_best_tip_global_slot - ), - BlockProducerVrfEvaluatorAction::RecordLastBlockHeightInEpoch { - epoch_number, - last_block_height, - } => action_info!( - context, - summary = "Saving last block height in epoch", - epoch_number, - last_block_height - ), - BlockProducerVrfEvaluatorAction::ContinueEpochEvaluation { .. } => { - action_trace!(context) - } - BlockProducerVrfEvaluatorAction::FinishEpochEvaluation { - epoch_number, - latest_evaluated_global_slot, - } => action_info!( - context, - summary = "Epoch evaluation finished", - epoch_number, - latest_evaluated_global_slot - ), - BlockProducerVrfEvaluatorAction::WaitForNextEvaluation { - current_epoch_number, - current_best_tip_height, - .. - } => action_info!( - context, - summary = "Waiting for epoch to evaluate", - current_epoch_number, - current_best_tip_height - ), - BlockProducerVrfEvaluatorAction::CheckEpochBounds { .. } => { - action_trace!(context, summary = "Checking epoch bounds") - } - BlockProducerVrfEvaluatorAction::CleanupOldSlots { .. } => { - action_trace!(context, summary = "Cleaning up old won slots") - } +fn log_vrf_output(context: &T, vrf_output: &VrfEvaluationOutput) +where + T: openmina_core::log::EventContext, +{ + match vrf_output { + VrfEvaluationOutput::SlotWon(VrfWonSlot { + global_slot, + vrf_output, + .. + }) => action_info!( + context, + summary = "Slot evaluation result - won slot", + global_slot, + vrf_output = display(vrf_output) + ), + VrfEvaluationOutput::SlotLost(_) => { + action_info!(context, summary = "Slot evaluation result - lost slot") } } } diff --git a/node/src/external_snark_worker/external_snark_worker_actions.rs b/node/src/external_snark_worker/external_snark_worker_actions.rs index cd27d962ce..776b231e41 100644 --- a/node/src/external_snark_worker/external_snark_worker_actions.rs +++ b/node/src/external_snark_worker/external_snark_worker_actions.rs @@ -1,6 +1,6 @@ use std::time::Duration; -use openmina_core::{action_debug, log::ActionEvent, snark::SnarkJobId}; +use openmina_core::{snark::SnarkJobId, ActionEvent}; use redux::{EnablingCondition, Timestamp}; use serde::{Deserialize, Serialize}; @@ -11,7 +11,8 @@ use super::{ SnarkWorkResult, }; -#[derive(Debug, Clone, Serialize, Deserialize)] +#[derive(Debug, Clone, Serialize, Deserialize, ActionEvent)] +#[action_event(fields(display(job_id), display(error)))] pub enum ExternalSnarkWorkerAction { Start, Started, @@ -134,32 +135,3 @@ impl EnablingCondition for ExternalSnarkWorkerAction { } } } - -impl ActionEvent for ExternalSnarkWorkerAction { - fn action_event(&self, context: &T) - where - T: openmina_core::log::EventContext, - { - match self { - ExternalSnarkWorkerAction::Start - | ExternalSnarkWorkerAction::Started - | ExternalSnarkWorkerAction::Kill - | ExternalSnarkWorkerAction::Killed - | ExternalSnarkWorkerAction::WorkCancelled - | ExternalSnarkWorkerAction::PruneWork => action_debug!(context), - ExternalSnarkWorkerAction::SubmitWork { job_id, .. } => { - action_debug!(context, job_id = display(job_id)) - } - ExternalSnarkWorkerAction::WorkResult { .. } => action_debug!(context), - ExternalSnarkWorkerAction::CancelWork => todo!(), - ExternalSnarkWorkerAction::WorkError { error } => { - action_debug!(context, error = display(error)) - } - ExternalSnarkWorkerAction::Error { error, .. } => { - action_debug!(context, error = display(error)) - } - ExternalSnarkWorkerAction::StartTimeout { .. } => action_debug!(context), - ExternalSnarkWorkerAction::WorkTimeout { .. } => action_debug!(context), - } - } -} diff --git a/node/src/transition_frontier/genesis/transition_frontier_genesis_actions.rs b/node/src/transition_frontier/genesis/transition_frontier_genesis_actions.rs index a3a1bb1f59..ab42b7c1e1 100644 --- a/node/src/transition_frontier/genesis/transition_frontier_genesis_actions.rs +++ b/node/src/transition_frontier/genesis/transition_frontier_genesis_actions.rs @@ -1,5 +1,5 @@ use mina_p2p_messages::v2; -use openmina_core::{action_info, action_trace, log::ActionEvent}; +use openmina_core::ActionEvent; use serde::{Deserialize, Serialize}; use super::{GenesisConfigLoaded, TransitionFrontierGenesisState}; @@ -9,7 +9,8 @@ pub type TransitionFrontierGenesisActionWithMeta = pub type TransitionFrontierGenesisActionWithMetaRef<'a> = redux::ActionWithMeta<&'a TransitionFrontierGenesisAction>; -#[derive(derive_more::From, Serialize, Deserialize, Debug, Clone)] +#[derive(derive_more::From, Serialize, Deserialize, Debug, Clone, ActionEvent)] +#[action_event(level = trace)] pub enum TransitionFrontierGenesisAction { LedgerLoadInit, LedgerLoadPending, @@ -18,7 +19,11 @@ pub enum TransitionFrontierGenesisAction { }, Produce, ProveInit, + /// Proving genesis block. + #[action_event(level = info)] ProvePending, + /// Genesis block proved. + #[action_event(level = info)] ProveSuccess { proof: Box, }, @@ -68,20 +73,3 @@ impl From for crate::Action { crate::transition_frontier::TransitionFrontierAction::Genesis(value).into() } } - -impl ActionEvent for TransitionFrontierGenesisAction { - fn action_event(&self, context: &T) - where - T: openmina_core::log::EventContext, - { - match self { - TransitionFrontierGenesisAction::ProvePending => { - action_info!(context, summary = "Genesis block proved") - } - TransitionFrontierGenesisAction::ProveSuccess { .. } => { - action_info!(context, summary = "Genesis block proved") - } - _ => action_trace!(context), - } - } -} diff --git a/node/src/transition_frontier/sync/ledger/snarked/transition_frontier_sync_ledger_snarked_actions.rs b/node/src/transition_frontier/sync/ledger/snarked/transition_frontier_sync_ledger_snarked_actions.rs index 8e3ad275d1..9d2fe9ba13 100644 --- a/node/src/transition_frontier/sync/ledger/snarked/transition_frontier_sync_ledger_snarked_actions.rs +++ b/node/src/transition_frontier/sync/ledger/snarked/transition_frontier_sync_ledger_snarked_actions.rs @@ -1,4 +1,5 @@ use mina_p2p_messages::v2::{LedgerHash, MinaBaseAccountBinableArgStableV2}; +use openmina_core::ActionEvent; use serde::{Deserialize, Serialize}; use crate::ledger::{LedgerAddress, LEDGER_DEPTH}; @@ -21,7 +22,8 @@ pub type TransitionFrontierSyncLedgerSnarkedActionWithMeta = pub type TransitionFrontierSyncLedgerSnarkedActionWithMetaRef<'a> = redux::ActionWithMeta<&'a TransitionFrontierSyncLedgerSnarkedAction>; -#[derive(Serialize, Deserialize, Debug, Clone)] +#[derive(Serialize, Deserialize, Debug, Clone, ActionEvent)] +#[action_event(level = trace)] pub enum TransitionFrontierSyncLedgerSnarkedAction { Pending, PeersQuery, diff --git a/node/src/transition_frontier/sync/ledger/staged/transition_frontier_sync_ledger_staged_actions.rs b/node/src/transition_frontier/sync/ledger/staged/transition_frontier_sync_ledger_staged_actions.rs index 05b2fdc397..7d89f31a5e 100644 --- a/node/src/transition_frontier/sync/ledger/staged/transition_frontier_sync_ledger_staged_actions.rs +++ b/node/src/transition_frontier/sync/ledger/staged/transition_frontier_sync_ledger_staged_actions.rs @@ -1,6 +1,7 @@ use std::sync::Arc; use mina_p2p_messages::v2::{self, LedgerHash}; +use openmina_core::ActionEvent; use serde::{Deserialize, Serialize}; use crate::p2p::channels::rpc::{P2pRpcId, StagedLedgerAuxAndPendingCoinbases}; @@ -17,7 +18,8 @@ pub type TransitionFrontierSyncLedgerStagedActionWithMeta = pub type TransitionFrontierSyncLedgerStagedActionWithMetaRef<'a> = redux::ActionWithMeta<&'a TransitionFrontierSyncLedgerStagedAction>; -#[derive(Serialize, Deserialize, Debug, Clone)] +#[derive(Serialize, Deserialize, Debug, Clone, ActionEvent)] +#[action_event(level = trace)] pub enum TransitionFrontierSyncLedgerStagedAction { PartsFetchPending, PartsPeerFetchInit, diff --git a/node/src/transition_frontier/sync/ledger/transition_frontier_sync_ledger_actions.rs b/node/src/transition_frontier/sync/ledger/transition_frontier_sync_ledger_actions.rs index 6133232c6c..2566be57c5 100644 --- a/node/src/transition_frontier/sync/ledger/transition_frontier_sync_ledger_actions.rs +++ b/node/src/transition_frontier/sync/ledger/transition_frontier_sync_ledger_actions.rs @@ -1,3 +1,4 @@ +use openmina_core::ActionEvent; use serde::{Deserialize, Serialize}; use crate::transition_frontier::sync::TransitionFrontierSyncAction; @@ -12,7 +13,7 @@ pub type TransitionFrontierSyncLedgerActionWithMeta = pub type TransitionFrontierSyncLedgerActionWithMetaRef<'a> = redux::ActionWithMeta<&'a TransitionFrontierSyncLedgerAction>; -#[derive(derive_more::From, Serialize, Deserialize, Debug, Clone)] +#[derive(derive_more::From, Serialize, Deserialize, Debug, Clone, ActionEvent)] pub enum TransitionFrontierSyncLedgerAction { Init, Snarked(TransitionFrontierSyncLedgerSnarkedAction), diff --git a/node/src/transition_frontier/sync/transition_frontier_sync_actions.rs b/node/src/transition_frontier/sync/transition_frontier_sync_actions.rs index dcbae30ad3..15ddd34468 100644 --- a/node/src/transition_frontier/sync/transition_frontier_sync_actions.rs +++ b/node/src/transition_frontier/sync/transition_frontier_sync_actions.rs @@ -1,8 +1,7 @@ use mina_p2p_messages::v2::StateHash; use openmina_core::block::ArcBlockWithHash; use openmina_core::consensus::consensus_take; -use openmina_core::log::ActionEvent; -use openmina_core::{action_debug, action_info}; +use openmina_core::ActionEvent; use serde::{Deserialize, Serialize}; use crate::p2p::channels::rpc::P2pRpcId; @@ -19,31 +18,42 @@ pub type TransitionFrontierSyncActionWithMeta = redux::ActionWithMeta = redux::ActionWithMeta<&'a TransitionFrontierSyncAction>; -#[derive(Serialize, Deserialize, Debug, Clone)] +#[derive(Serialize, Deserialize, Debug, Clone, ActionEvent)] pub enum TransitionFrontierSyncAction { /// Set transition frontier target to new best tip (for still unsynced frontiers) + #[action_event(level = info, fields( + block_hash = display(&best_tip.hash), + root_block_hash = display(&root_block.hash), + ))] Init { best_tip: ArcBlockWithHash, root_block: ArcBlockWithHash, blocks_inbetween: Vec, }, /// Set sync target to a new best tip (for already synced frontiers) + #[action_event(level = info)] BestTipUpdate { best_tip: ArcBlockWithHash, root_block: ArcBlockWithHash, blocks_inbetween: Vec, }, /// Staking Ledger sync is pending + #[action_event(level = info)] LedgerStakingPending, /// Staking Ledger sync was successful + #[action_event(level = info)] LedgerStakingSuccess, /// Next Epoch Ledger sync is pending + #[action_event(level = info)] LedgerNextEpochPending, /// Next Epoch Ledger sync was successful + #[action_event(level = info)] LedgerNextEpochSuccess, /// Transition frontier Root Ledger sync is pending + #[action_event(level = info)] LedgerRootPending, /// Transition frontier Root Ledger sync was successful + #[action_event(level = info)] LedgerRootSuccess, BlocksPending, BlocksPeersQuery, @@ -314,47 +324,3 @@ impl From for crate::Action { Self::TransitionFrontier(TransitionFrontierAction::Sync(value)) } } - -impl ActionEvent for TransitionFrontierSyncAction { - fn action_event(&self, context: &T) - where - T: openmina_core::log::EventContext, - { - match self { - TransitionFrontierSyncAction::Init { - best_tip, - root_block, - .. - } => action_info!( - context, - block_hash = display(&best_tip.hash), - root_block_hash = display(&root_block.hash), - summary = "Transition frontier sync init" - ), - TransitionFrontierSyncAction::BestTipUpdate { .. } => { - action_info!(context, summary = "New best tip received") - } - TransitionFrontierSyncAction::LedgerStakingPending => { - action_info!(context, summary = "Staking ledger sync pending") - } - TransitionFrontierSyncAction::LedgerStakingSuccess => { - action_info!(context, summary = "Staking ledger sync success") - } - TransitionFrontierSyncAction::LedgerNextEpochPending => { - action_info!(context, summary = "Next epoch ledger sync pending") - } - TransitionFrontierSyncAction::LedgerNextEpochSuccess => { - action_info!(context, summary = "Next epoch ledger sync success") - } - TransitionFrontierSyncAction::LedgerRootPending => action_info!( - context, - summary = "Transition frontier root ledger sync pending" - ), - TransitionFrontierSyncAction::LedgerRootSuccess => action_info!( - context, - summary = "Transition frontier root ledger sync success" - ), - _ => action_debug!(context), - } - } -} diff --git a/node/src/transition_frontier/transition_frontier_actions.rs b/node/src/transition_frontier/transition_frontier_actions.rs index 7ba22d82dd..63f466362e 100644 --- a/node/src/transition_frontier/transition_frontier_actions.rs +++ b/node/src/transition_frontier/transition_frontier_actions.rs @@ -1,8 +1,7 @@ use std::collections::BTreeSet; use mina_p2p_messages::v2::StateHash; -use openmina_core::action_info; -use openmina_core::log::ActionEvent; +use openmina_core::ActionEvent; use serde::{Deserialize, Serialize}; use super::genesis::TransitionFrontierGenesisAction; @@ -12,17 +11,21 @@ pub type TransitionFrontierActionWithMeta = redux::ActionWithMeta = redux::ActionWithMeta<&'a TransitionFrontierAction>; -#[derive(derive_more::From, Serialize, Deserialize, Debug, Clone)] +#[derive(derive_more::From, Serialize, Deserialize, Debug, Clone, ActionEvent)] pub enum TransitionFrontierAction { Genesis(TransitionFrontierGenesisAction), - /// Inject genesis block into the transition frontier, unless we already - /// have a better block there. + /// Inject genesis block into the transition frontier. + /// + /// Unless we already have a better block there. /// /// If this node is block producer, we produce proof for the genesis /// block, otherwise we don't need it so we use dummy proof instead. + #[action_event(level = info)] GenesisInject, Sync(TransitionFrontierSyncAction), + /// Transition frontier synced. + #[action_event(level = info)] Synced { /// Required protocol states for root block. needed_protocol_states: BTreeSet, @@ -52,23 +55,3 @@ impl redux::EnablingCondition for TransitionFrontierAction { } } } - -impl ActionEvent for TransitionFrontierAction { - fn action_event(&self, context: &T) - where - T: openmina_core::log::EventContext, - { - match self { - TransitionFrontierAction::Genesis(action) => action.action_event(context), - TransitionFrontierAction::GenesisInject => action_info!( - context, - summary = "Transition frontier reconstructed genesis ledger and block", - // TODO: fetch more fields from the state - ), - TransitionFrontierAction::Sync(action) => action.action_event(context), - TransitionFrontierAction::Synced { .. } => { - action_info!(context, summary = "Transition frontier synced") - } - } - } -} diff --git a/p2p/src/channels/best_tip/p2p_channels_best_tip_actions.rs b/p2p/src/channels/best_tip/p2p_channels_best_tip_actions.rs index a67d756fe1..dc13fd93b1 100644 --- a/p2p/src/channels/best_tip/p2p_channels_best_tip_actions.rs +++ b/p2p/src/channels/best_tip/p2p_channels_best_tip_actions.rs @@ -1,4 +1,4 @@ -use openmina_core::{action_debug, block::ArcBlockWithHash, log::ActionEvent}; +use openmina_core::{block::ArcBlockWithHash, ActionEvent}; use serde::{Deserialize, Serialize}; use crate::{ @@ -11,27 +11,34 @@ use super::BestTipPropagationState; pub type P2pChannelsBestTipActionWithMetaRef<'a> = redux::ActionWithMeta<&'a P2pChannelsBestTipAction>; -#[derive(Debug, Clone, Serialize, Deserialize)] +#[derive(Debug, Clone, Serialize, Deserialize, ActionEvent)] +#[action_event(fields(display(peer_id), best_tip = display(&best_tip.hash)))] pub enum P2pChannelsBestTipAction { + /// Initialize best tip channel. Init { peer_id: PeerId, }, Pending { peer_id: PeerId, }, + /// Best tip channel is ready. Ready { peer_id: PeerId, }, + /// Send best tip request. RequestSend { peer_id: PeerId, }, + /// Best tip response is received. Received { peer_id: PeerId, best_tip: ArcBlockWithHash, }, + /// Best tip request is received. RequestReceived { peer_id: PeerId, }, + /// Best tip response is sent. ResponseSend { peer_id: PeerId, best_tip: ArcBlockWithHash, @@ -130,38 +137,3 @@ impl From for crate::P2pAction { Self::Channels(P2pChannelsAction::BestTip(action)) } } - -impl ActionEvent for P2pChannelsBestTipAction { - fn action_event(&self, context: &T) - where - T: openmina_core::log::EventContext, - { - match self { - P2pChannelsBestTipAction::Init { peer_id } => { - action_debug!(context, peer_id = display(peer_id)) - } - P2pChannelsBestTipAction::Pending { peer_id } => { - action_debug!(context, peer_id = display(peer_id)) - } - P2pChannelsBestTipAction::Ready { peer_id } => { - action_debug!(context, peer_id = display(peer_id)) - } - P2pChannelsBestTipAction::RequestSend { peer_id } => { - action_debug!(context, peer_id = display(peer_id)) - } - P2pChannelsBestTipAction::Received { peer_id, best_tip } => action_debug!( - context, - peer_id = display(peer_id), - best_tip = display(&best_tip.hash) - ), - P2pChannelsBestTipAction::RequestReceived { peer_id } => { - action_debug!(context, peer_id = display(peer_id)) - } - P2pChannelsBestTipAction::ResponseSend { peer_id, best_tip } => action_debug!( - context, - peer_id = display(peer_id), - best_tip = display(&best_tip.hash) - ), - } - } -} diff --git a/p2p/src/channels/rpc/p2p_channels_rpc_actions.rs b/p2p/src/channels/rpc/p2p_channels_rpc_actions.rs index 8dbd1c83d1..6c170d6ef8 100644 --- a/p2p/src/channels/rpc/p2p_channels_rpc_actions.rs +++ b/p2p/src/channels/rpc/p2p_channels_rpc_actions.rs @@ -1,4 +1,4 @@ -use openmina_core::{action_debug, action_trace, log::ActionEvent}; +use openmina_core::ActionEvent; use redux::Timestamp; use serde::{Deserialize, Serialize}; @@ -10,7 +10,8 @@ pub type P2pChannelsRpcActionWithMetaRef<'a> = redux::ActionWithMeta<&'a P2pChan pub const MAX_P2P_RPC_REMOTE_CONCURRENT_REQUESTS: usize = 5; -#[derive(Serialize, Deserialize, Debug, Clone)] +#[derive(Serialize, Deserialize, Debug, Clone, ActionEvent)] +#[action_event(fields(display(peer_id)))] pub enum P2pChannelsRpcAction { Init { peer_id: PeerId, @@ -171,65 +172,3 @@ impl From for crate::P2pAction { Self::Channels(P2pChannelsAction::Rpc(a)) } } - -impl ActionEvent for P2pChannelsRpcAction { - fn action_event(&self, context: &T) - where - T: openmina_core::log::EventContext, - { - match self { - P2pChannelsRpcAction::Init { peer_id } => { - action_debug!(context, peer_id = display(peer_id)) - } - P2pChannelsRpcAction::Pending { peer_id } => { - action_trace!(context, peer_id = display(peer_id)) - } - P2pChannelsRpcAction::Ready { peer_id } => { - action_debug!(context, peer_id = display(peer_id)) - } - P2pChannelsRpcAction::RequestSend { - peer_id, - id, - request, - } => action_debug!( - context, - peer_id = display(peer_id), - id, - request = debug(request) - ), - P2pChannelsRpcAction::Timeout { peer_id, id } => { - action_debug!(context, peer_id = display(peer_id), id) - } - P2pChannelsRpcAction::ResponseReceived { - peer_id, - id, - response, - } => action_debug!( - context, - peer_id = display(peer_id), - id, - response = debug(response) - ), - P2pChannelsRpcAction::RequestReceived { - peer_id, - id, - request, - } => action_debug!( - context, - peer_id = display(peer_id), - id, - request = debug(request) - ), - P2pChannelsRpcAction::ResponseSend { - peer_id, - id, - response, - } => action_debug!( - context, - peer_id = display(peer_id), - id, - response = debug(response) - ), - } - } -} diff --git a/p2p/src/channels/snark/p2p_channels_snark_actions.rs b/p2p/src/channels/snark/p2p_channels_snark_actions.rs index 0963a31048..520fe085f0 100644 --- a/p2p/src/channels/snark/p2p_channels_snark_actions.rs +++ b/p2p/src/channels/snark/p2p_channels_snark_actions.rs @@ -1,12 +1,13 @@ use crate::{channels::P2pChannelsAction, P2pState, PeerId}; -use openmina_core::{action_debug, action_trace, log::ActionEvent, snark::Snark}; +use openmina_core::{snark::Snark, ActionEvent}; use serde::{Deserialize, Serialize}; use super::{P2pChannelsSnarkState, SnarkInfo, SnarkPropagationState}; pub type P2pChannelsSnarkActionWithMetaRef<'a> = redux::ActionWithMeta<&'a P2pChannelsSnarkAction>; -#[derive(Serialize, Deserialize, Debug, Clone)] +#[derive(Serialize, Deserialize, Debug, Clone, ActionEvent)] +#[action_event(fields(display(peer_id)))] pub enum P2pChannelsSnarkAction { Init { peer_id: PeerId, @@ -179,68 +180,3 @@ impl From for crate::P2pAction { Self::Channels(P2pChannelsAction::Snark(action)) } } - -impl ActionEvent for P2pChannelsSnarkAction { - fn action_event(&self, context: &T) - where - T: openmina_core::log::EventContext, - { - match self { - P2pChannelsSnarkAction::Init { peer_id } => { - action_debug!(context, peer_id = display(peer_id)) - } - P2pChannelsSnarkAction::Pending { peer_id } => { - action_trace!(context, peer_id = display(peer_id)) - } - P2pChannelsSnarkAction::Ready { peer_id } => { - action_debug!(context, peer_id = display(peer_id)) - } - P2pChannelsSnarkAction::RequestSend { peer_id, limit } => { - action_trace!(context, peer_id = display(peer_id), limit) - } - P2pChannelsSnarkAction::PromiseReceived { - peer_id, - promised_count, - } => action_trace!(context, peer_id = display(peer_id), promised_count), - P2pChannelsSnarkAction::Received { peer_id, snark } => action_trace!( - context, - peer_id = display(peer_id), - snark.job_id = display(&snark.job_id), - snark.fee = debug(&snark.fee), - snark.prover = display(&snark.prover), - ), - P2pChannelsSnarkAction::RequestReceived { peer_id, limit } => { - action_trace!(context, peer_id = display(peer_id), limit) - } - P2pChannelsSnarkAction::ResponseSend { - peer_id, - snarks, - first_index, - last_index, - } => action_trace!( - context, - peer_id = display(peer_id), - snarks = debug(snarks), - first_index, - last_index - ), - P2pChannelsSnarkAction::Libp2pReceived { - peer_id, - snark, - nonce, - } => action_trace!( - context, - peer_id = display(peer_id), - snark.snarker = display(&snark.snarker), - snark.fee = debug(&snark.fee), - nonce - ), - P2pChannelsSnarkAction::Libp2pBroadcast { snark, nonce } => action_trace!( - context, - snark.snarker = display(&snark.snarker), - snark.fee = debug(&snark.fee), - nonce - ), - } - } -} diff --git a/p2p/src/channels/snark_job_commitment/p2p_channels_snark_job_commitment_actions.rs b/p2p/src/channels/snark_job_commitment/p2p_channels_snark_job_commitment_actions.rs index b211ffb78d..02ca96cb74 100644 --- a/p2p/src/channels/snark_job_commitment/p2p_channels_snark_job_commitment_actions.rs +++ b/p2p/src/channels/snark_job_commitment/p2p_channels_snark_job_commitment_actions.rs @@ -1,4 +1,4 @@ -use openmina_core::{action_debug, action_trace, log::ActionEvent}; +use openmina_core::ActionEvent; use serde::{Deserialize, Serialize}; use crate::{P2pState, PeerId}; @@ -10,7 +10,8 @@ use super::{ pub type P2pChannelsSnarkJobCommitmentActionWithMetaRef<'a> = redux::ActionWithMeta<&'a P2pChannelsSnarkJobCommitmentAction>; -#[derive(Debug, Clone, Serialize, Deserialize)] +#[derive(Debug, Clone, Serialize, Deserialize, ActionEvent)] +#[action_event(fields(display(peer_id)))] pub enum P2pChannelsSnarkJobCommitmentAction { Init { peer_id: PeerId, @@ -178,52 +179,3 @@ impl From for crate::P2pAction { Self::Channels(P2pChannelsAction::SnarkJobCommitment(action)) } } - -impl ActionEvent for P2pChannelsSnarkJobCommitmentAction { - fn action_event(&self, context: &T) - where - T: openmina_core::log::EventContext, - { - match self { - P2pChannelsSnarkJobCommitmentAction::Init { peer_id } => { - action_debug!(context, peer_id = display(peer_id)) - } - P2pChannelsSnarkJobCommitmentAction::Pending { peer_id } => { - action_trace!(context, peer_id = display(peer_id)) - } - P2pChannelsSnarkJobCommitmentAction::Ready { peer_id } => { - action_debug!(context, peer_id = display(peer_id)) - } - P2pChannelsSnarkJobCommitmentAction::RequestSend { peer_id, limit } => { - action_trace!(context, peer_id = display(peer_id), limit) - } - P2pChannelsSnarkJobCommitmentAction::PromiseReceived { - peer_id, - promised_count, - } => action_trace!(context, peer_id = display(peer_id), promised_count), - P2pChannelsSnarkJobCommitmentAction::Received { - peer_id, - commitment, - } => action_trace!( - context, - peer_id = display(peer_id), - commitment = debug(commitment) - ), - P2pChannelsSnarkJobCommitmentAction::RequestReceived { peer_id, limit } => { - action_trace!(context, peer_id = display(peer_id), limit) - } - P2pChannelsSnarkJobCommitmentAction::ResponseSend { - peer_id, - commitments, - first_index, - last_index, - } => action_trace!( - context, - peer_id = display(peer_id), - commitments = debug(commitments), - first_index, - last_index - ), - } - } -} diff --git a/p2p/src/connection/incoming/p2p_connection_incoming_actions.rs b/p2p/src/connection/incoming/p2p_connection_incoming_actions.rs index d76b79edef..f2db4d8dbf 100644 --- a/p2p/src/connection/incoming/p2p_connection_incoming_actions.rs +++ b/p2p/src/connection/incoming/p2p_connection_incoming_actions.rs @@ -1,6 +1,6 @@ use serde::{Deserialize, Serialize}; -use openmina_core::{action_debug, action_info, action_warn, log::ActionEvent, requests::RpcId}; +use openmina_core::{requests::RpcId, ActionEvent}; use crate::{webrtc, P2pAction, P2pState, PeerId}; @@ -9,12 +9,15 @@ use super::P2pConnectionIncomingInitOpts; pub type P2pConnectionIncomingActionWithMetaRef<'a> = redux::ActionWithMeta<&'a P2pConnectionIncomingAction>; -#[derive(Serialize, Deserialize, Debug, Clone)] +#[derive(Serialize, Deserialize, Debug, Clone, ActionEvent)] +#[action_event(fields(debug(opts), display(peer_id), display(error)))] pub enum P2pConnectionIncomingAction { + /// Incoming connection is initialized. Init { opts: P2pConnectionIncomingInitOpts, rpc_id: Option, }, + #[action_event(level = trace)] AnswerSdpCreatePending { peer_id: PeerId, }, @@ -33,26 +36,35 @@ pub enum P2pConnectionIncomingAction { AnswerSendSuccess { peer_id: PeerId, }, + /// Pending incoming connection finalization. + #[action_event(level = trace)] FinalizePending { peer_id: PeerId, }, + /// Error finalizing incoming connection. FinalizeError { peer_id: PeerId, error: String, }, + /// Incoming connection finalized. FinalizeSuccess { peer_id: PeerId, }, + /// Timeout establishing incoming connection. Timeout { peer_id: PeerId, }, + /// Error establishing incoming connection. Error { peer_id: PeerId, error: P2pConnectionIncomingError, }, + /// Incoming connection is succesful. + #[action_event(level = info)] Success { peer_id: PeerId, }, + /// Incoming libp2p connection is succesful. Libp2pReceived { peer_id: PeerId, }, @@ -209,52 +221,3 @@ impl From for P2pAction { Self::Connection(P2pConnectionAction::Incoming(a)) } } - -impl ActionEvent for P2pConnectionIncomingAction { - fn action_event(&self, context: &T) - where - T: openmina_core::log::EventContext, - { - match self { - P2pConnectionIncomingAction::Init { opts, .. } => { - action_debug!(context, opts = debug(opts)) - } - P2pConnectionIncomingAction::AnswerSdpCreatePending { peer_id } => { - action_debug!(context, peer_id = display(peer_id)) - } - P2pConnectionIncomingAction::AnswerSdpCreateError { peer_id, error } => { - action_debug!(context, peer_id = display(peer_id), error) - } - P2pConnectionIncomingAction::AnswerSdpCreateSuccess { peer_id, sdp } => { - action_debug!(context, peer_id = display(peer_id), sdp) - } - P2pConnectionIncomingAction::AnswerReady { peer_id, answer } => { - action_debug!(context, peer_id = display(peer_id), answer = debug(answer)) - } - P2pConnectionIncomingAction::AnswerSendSuccess { peer_id } => { - action_debug!(context, peer_id = display(peer_id)) - } - P2pConnectionIncomingAction::FinalizePending { peer_id } => { - action_debug!(context, peer_id = display(peer_id)) - } - P2pConnectionIncomingAction::FinalizeError { peer_id, error } => { - action_debug!(context, peer_id = display(peer_id), error) - } - P2pConnectionIncomingAction::FinalizeSuccess { peer_id } => { - action_debug!(context, peer_id = display(peer_id)) - } - P2pConnectionIncomingAction::Timeout { peer_id } => { - action_debug!(context, peer_id = display(peer_id)) - } - P2pConnectionIncomingAction::Error { peer_id, error } => { - action_warn!(context, peer_id = display(peer_id), error = display(error)) - } - P2pConnectionIncomingAction::Success { peer_id } => { - action_info!(context, peer_id = display(peer_id)) - } - P2pConnectionIncomingAction::Libp2pReceived { peer_id } => { - action_debug!(context, peer_id = display(peer_id)) - } - } - } -} diff --git a/p2p/src/connection/outgoing/p2p_connection_outgoing_actions.rs b/p2p/src/connection/outgoing/p2p_connection_outgoing_actions.rs index 17330e8268..893019b605 100644 --- a/p2p/src/connection/outgoing/p2p_connection_outgoing_actions.rs +++ b/p2p/src/connection/outgoing/p2p_connection_outgoing_actions.rs @@ -1,5 +1,4 @@ -use openmina_core::log::ActionEvent; -use openmina_core::{action_debug, action_info, action_warn}; +use openmina_core::ActionEvent; use serde::{Deserialize, Serialize}; use openmina_core::requests::RpcId; @@ -12,17 +11,25 @@ use super::{P2pConnectionOutgoingError, P2pConnectionOutgoingInitOpts}; pub type P2pConnectionOutgoingActionWithMetaRef<'a> = redux::ActionWithMeta<&'a P2pConnectionOutgoingAction>; -#[derive(Serialize, Deserialize, Debug, Clone)] +#[derive(Serialize, Deserialize, Debug, Clone, ActionEvent)] +#[action_event(fields(display(opts), display(peer_id), display(error)))] pub enum P2pConnectionOutgoingAction { + /// Initialize connection to a random peer. + #[action_event(level = trace)] RandomInit, + /// Initialize connection to a new peer. + #[action_event(level = info)] Init { opts: P2pConnectionOutgoingInitOpts, rpc_id: Option, }, + /// Reconnect to an existing peer. + #[action_event(level = info)] Reconnect { opts: P2pConnectionOutgoingInitOpts, rpc_id: Option, }, + #[action_event(level = trace)] OfferSdpCreatePending { peer_id: PeerId, }, @@ -41,6 +48,7 @@ pub enum P2pConnectionOutgoingAction { OfferSendSuccess { peer_id: PeerId, }, + #[action_event(level = trace)] AnswerRecvPending { peer_id: PeerId, }, @@ -52,23 +60,31 @@ pub enum P2pConnectionOutgoingAction { peer_id: PeerId, answer: webrtc::Answer, }, + #[action_event(level = trace)] FinalizePending { peer_id: PeerId, }, + /// Error finalizing outgoing connection. FinalizeError { peer_id: PeerId, error: String, }, + /// Outgoing connection succsessfully finalized. + #[action_event(level = info)] FinalizeSuccess { peer_id: PeerId, }, + /// Timeout establishing connection to a peer. Timeout { peer_id: PeerId, }, + /// Error connecting to a peer. Error { peer_id: PeerId, error: P2pConnectionOutgoingError, }, + /// Outgoing connection is successful. + #[action_event(level = info)] Success { peer_id: PeerId, }, @@ -284,62 +300,3 @@ impl From for crate::P2pAction { Self::Connection(P2pConnectionAction::Outgoing(a)) } } - -impl ActionEvent for P2pConnectionOutgoingAction { - fn action_event(&self, context: &T) - where - T: openmina_core::log::EventContext, - { - match self { - P2pConnectionOutgoingAction::RandomInit => action_debug!(context), - P2pConnectionOutgoingAction::Init { opts, rpc_id: _ } => { - action_debug!(context, opts = display(opts)) - } - P2pConnectionOutgoingAction::Reconnect { opts, rpc_id: _ } => { - action_debug!(context, opts = display(opts)) - } - P2pConnectionOutgoingAction::OfferSdpCreatePending { peer_id } => { - action_debug!(context, peer_id = display(peer_id)) - } - P2pConnectionOutgoingAction::OfferSdpCreateError { peer_id, error } => { - action_warn!(context, peer_id = display(peer_id), error) - } - P2pConnectionOutgoingAction::OfferSdpCreateSuccess { peer_id, sdp } => { - action_debug!(context, peer_id = display(peer_id), sdp) - } - P2pConnectionOutgoingAction::OfferReady { peer_id, offer } => { - action_debug!(context, peer_id = display(peer_id), offer = debug(offer)) - } - P2pConnectionOutgoingAction::OfferSendSuccess { peer_id } => { - action_debug!(context, peer_id = display(peer_id)) - } - P2pConnectionOutgoingAction::AnswerRecvPending { peer_id } => { - action_debug!(context, peer_id = display(peer_id)) - } - P2pConnectionOutgoingAction::AnswerRecvError { peer_id, error } => { - action_warn!(context, peer_id = display(peer_id), error = display(error)) - } - P2pConnectionOutgoingAction::AnswerRecvSuccess { peer_id, answer } => { - action_debug!(context, peer_id = display(peer_id), answer = debug(answer)) - } - P2pConnectionOutgoingAction::FinalizePending { peer_id } => { - action_debug!(context, peer_id = display(peer_id)) - } - P2pConnectionOutgoingAction::FinalizeError { peer_id, error } => { - action_warn!(context, peer_id = display(peer_id), error) - } - P2pConnectionOutgoingAction::FinalizeSuccess { peer_id } => { - action_debug!(context, peer_id = display(peer_id)) - } - P2pConnectionOutgoingAction::Timeout { peer_id } => { - action_debug!(context, peer_id = display(peer_id)) - } - P2pConnectionOutgoingAction::Error { peer_id, error } => { - action_debug!(context, peer_id = display(peer_id), error = display(error)) - } - P2pConnectionOutgoingAction::Success { peer_id } => { - action_info!(context, peer_id = display(peer_id)) - } - } - } -} diff --git a/p2p/src/disconnection/p2p_disconnection_actions.rs b/p2p/src/disconnection/p2p_disconnection_actions.rs index f223adbf2d..b941881438 100644 --- a/p2p/src/disconnection/p2p_disconnection_actions.rs +++ b/p2p/src/disconnection/p2p_disconnection_actions.rs @@ -1,4 +1,4 @@ -use openmina_core::{action_info, log::ActionEvent}; +use openmina_core::ActionEvent; use serde::{Deserialize, Serialize}; use super::P2pDisconnectionReason; @@ -6,15 +6,16 @@ use crate::{P2pPeerStatus, P2pState, PeerId}; pub type P2pDisconnectionActionWithMetaRef<'a> = redux::ActionWithMeta<&'a P2pDisconnectionAction>; -#[derive(Serialize, Deserialize, Debug, Clone)] +#[derive(Serialize, Deserialize, Debug, Clone, ActionEvent)] +#[action_event(fields(display(peer_id), display(reason)), level = info)] pub enum P2pDisconnectionAction { + /// Initialize disconnection. Init { peer_id: PeerId, reason: P2pDisconnectionReason, }, - Finish { - peer_id: PeerId, - }, + /// Finish disconnecting from a peer. + Finish { peer_id: PeerId }, } impl redux::EnablingCondition for P2pDisconnectionAction { @@ -29,21 +30,3 @@ impl redux::EnablingCondition for P2pDisconnectionAction { } } } - -impl ActionEvent for P2pDisconnectionAction { - fn action_event(&self, context: &T) - where - T: openmina_core::log::EventContext, - { - match self { - P2pDisconnectionAction::Init { peer_id, reason } => action_info!( - context, - peer_id = display(peer_id), - reason = display(reason) - ), - P2pDisconnectionAction::Finish { peer_id } => { - action_info!(context, peer_id = display(peer_id)) - } - } - } -} diff --git a/p2p/src/discovery/p2p_discovery_actions.rs b/p2p/src/discovery/p2p_discovery_actions.rs index a55c400aff..51ab8f5626 100644 --- a/p2p/src/discovery/p2p_discovery_actions.rs +++ b/p2p/src/discovery/p2p_discovery_actions.rs @@ -1,4 +1,4 @@ -use openmina_core::{action_debug, action_info, action_warn, log::ActionEvent}; +use openmina_core::ActionEvent; use serde::{Deserialize, Serialize}; use crate::{connection::outgoing::P2pConnectionOutgoingInitOpts, P2pState, PeerId}; @@ -7,7 +7,8 @@ use crate::{connection::outgoing::P2pConnectionOutgoingInitOpts, P2pState, PeerI pub type P2pDiscoveryActionWithMetaRef<'a> = redux::ActionWithMeta<&'a P2pDiscoveryAction>; -#[derive(Serialize, Deserialize, Debug, Clone)] +#[derive(Serialize, Deserialize, Debug, Clone, ActionEvent)] +#[action_event(fields(display(peer_id), debug(peers), debug(addresses), description))] pub enum P2pDiscoveryAction { Init { peer_id: PeerId, @@ -47,34 +48,3 @@ impl redux::EnablingCondition for P2pDiscoveryAction { } } } - -impl ActionEvent for P2pDiscoveryAction { - fn action_event(&self, context: &T) - where - T: openmina_core::log::EventContext, - { - match self { - P2pDiscoveryAction::Init { peer_id } => { - action_debug!(context, peer_id = display(peer_id)) - } - P2pDiscoveryAction::Success { peer_id, peers } => { - action_debug!(context, peer_id = display(peer_id), peers = debug(peers)) - } - P2pDiscoveryAction::KademliaBootstrap => action_debug!(context), - P2pDiscoveryAction::KademliaInit => action_debug!(context), - P2pDiscoveryAction::KademliaAddRoute { peer_id, addresses } => { - action_debug!( - context, - peer_id = display(peer_id), - addresses = debug(addresses) - ) - } - P2pDiscoveryAction::KademliaSuccess { peers } => { - action_info!(context, peers = debug(peers)) - } - P2pDiscoveryAction::KademliaFailure { description } => { - action_warn!(context, description) - } - } - } -} diff --git a/p2p/src/listen/p2p_listen_actions.rs b/p2p/src/listen/p2p_listen_actions.rs index c76e8b6319..7fd4774b1f 100644 --- a/p2p/src/listen/p2p_listen_actions.rs +++ b/p2p/src/listen/p2p_listen_actions.rs @@ -1,4 +1,4 @@ -use openmina_core::{action_debug, action_warn, log::ActionEvent}; +use openmina_core::ActionEvent; use redux::EnablingCondition; use serde::{Deserialize, Serialize}; @@ -6,7 +6,8 @@ use crate::{P2pListenerId, P2pState}; pub type P2pListenActionWithMetaRef<'a> = redux::ActionWithMeta<&'a P2pListenAction>; -#[derive(Serialize, Deserialize, Debug, Clone)] +#[derive(Serialize, Deserialize, Debug, Clone, ActionEvent)] +#[action_event(fields(display(listener_id), display(addr), error))] pub enum P2pListenAction { New { listener_id: P2pListenerId, @@ -27,29 +28,3 @@ pub enum P2pListenAction { } impl EnablingCondition for P2pListenAction {} - -impl ActionEvent for P2pListenAction { - fn action_event(&self, context: &T) - where - T: openmina_core::log::EventContext, - { - match self { - P2pListenAction::New { listener_id, addr } => action_debug!( - context, - listener_id = debug(listener_id), - addr = display(addr) - ), - P2pListenAction::Expired { listener_id, addr } => action_debug!( - context, - listener_id = debug(listener_id), - addr = display(addr) - ), - P2pListenAction::Error { listener_id, error } => { - action_warn!(context, listener_id = debug(listener_id), error) - } - P2pListenAction::Closed { listener_id, error } => { - action_debug!(context, listener_id = debug(listener_id), error) - } - } - } -} diff --git a/p2p/src/network/kad/bootstrap/p2p_network_kad_bootstrap_actions.rs b/p2p/src/network/kad/bootstrap/p2p_network_kad_bootstrap_actions.rs index 93c8041564..9fae385fc3 100644 --- a/p2p/src/network/kad/bootstrap/p2p_network_kad_bootstrap_actions.rs +++ b/p2p/src/network/kad/bootstrap/p2p_network_kad_bootstrap_actions.rs @@ -47,25 +47,3 @@ impl From for P2pAction { P2pNetworkKadAction::Bootstrap(value).into() } } - -// impl ActionEvent for P2pNetworkKadBootstrapAction { -// fn action_event(&self, context: &T) -// where -// T: openmina_core::log::EventContext, -// { -// match self { -// P2pNetworkKadBootstrapAction::CreateRequests => action_debug!(context), -// P2pNetworkKadBootstrapAction::RequestDone { -// peer_id, -// closest_peers, -// } => action_debug!( -// context, -// peer_id = display(peer_id), -// closest_peers = debug(closest_peers) -// ), -// P2pNetworkKadBootstrapAction::RequestError { peer_id, error } => { -// action_debug!(context, peer_id = display(peer_id), error = display(error)) -// } -// } -// } -// } diff --git a/p2p/src/network/kad/p2p_network_kad_actions.rs b/p2p/src/network/kad/p2p_network_kad_actions.rs index 91c87301a3..d9de6c6031 100644 --- a/p2p/src/network/kad/p2p_network_kad_actions.rs +++ b/p2p/src/network/kad/p2p_network_kad_actions.rs @@ -108,41 +108,3 @@ impl From for P2pAction { P2pAction::Network(P2pNetworkKadAction::System(value).into()) } } - -// impl ActionEvent for P2pNetworkKademliaAction { -// fn action_event(&self, context: &T) -// where -// T: openmina_core::log::EventContext, -// { -// match self { -// P2pNetworkKademliaAction::AnswerFindNodeRequest { -// addr, -// peer_id, -// stream_id, -// key, -// } => action_debug!( -// context, -// addr = display(addr), -// peer_id = display(peer_id), -// stream_id, -// key = display(key) -// ), -// P2pNetworkKademliaAction::UpdateFindNodeRequest { -// addr, -// peer_id, -// stream_id, -// closest_peers, -// } => action_debug!( -// context, -// addr = display(addr), -// peer_id = display(peer_id), -// stream_id, -// closest_peers = debug(closest_peers) -// ), -// P2pNetworkKademliaAction::StartBootstrap { key } => { -// action_info!(context, key = display(key)) -// } -// P2pNetworkKademliaAction::BootstrapFinished => action_debug!(context), -// } -// } -// } diff --git a/p2p/src/network/kad/request/p2p_network_kad_request_actions.rs b/p2p/src/network/kad/request/p2p_network_kad_request_actions.rs index 2f38cc30a7..c971eeab13 100644 --- a/p2p/src/network/kad/request/p2p_network_kad_request_actions.rs +++ b/p2p/src/network/kad/request/p2p_network_kad_request_actions.rs @@ -83,57 +83,3 @@ impl From for P2pAction { P2pAction::Network(super::super::P2pNetworkKadAction::Request(value).into()) } } - -// impl ActionEvent for P2pNetworkKadRequestAction { -// fn action_event(&self, context: &T) -// where -// T: openmina_core::log::EventContext, -// { -// match self { -// P2pNetworkKadRequestAction::New { peer_id, addr, key } => action_debug!( -// context, -// peer_id = display(peer_id), -// addr = display(addr), -// key = display(key) -// ), -// P2pNetworkKadRequestAction::PeerIsConnecting { peer_id } => { -// action_debug!(context, peer_id = display(peer_id)) -// } -// P2pNetworkKadRequestAction::MuxReady { peer_id, addr } => { -// action_debug!(context, peer_id = display(peer_id), addr = display(addr)) -// } -// P2pNetworkKadRequestAction::StreamIsCreating { peer_id, stream_id } => { -// action_debug!(context, peer_id = display(peer_id), stream_id) -// } -// P2pNetworkKadRequestAction::StreamReady { -// peer_id, -// stream_id, -// addr, -// } => action_debug!( -// context, -// peer_id = display(peer_id), -// stream_id, -// addr = display(addr) -// ), -// P2pNetworkKadRequestAction::RequestSent { peer_id } => { -// action_debug!(context, peer_id = display(peer_id)) -// } -// P2pNetworkKadRequestAction::ReplyReceived { -// peer_id, -// stream_id, -// data, -// } => action_debug!( -// context, -// peer_id = display(peer_id), -// stream_id, -// data = debug(data) -// ), -// P2pNetworkKadRequestAction::Prune { peer_id } => { -// action_trace!(context, peer_id = display(peer_id)) -// } -// P2pNetworkKadRequestAction::Error { peer_id, error } => { -// action_debug!(context, peer_id = display(peer_id), error = display(error)) -// } -// } -// } -// } diff --git a/p2p/src/network/kad/stream/p2p_network_kad_stream_actions.rs b/p2p/src/network/kad/stream/p2p_network_kad_stream_actions.rs index fd8ba3abac..bed2cad2ca 100644 --- a/p2p/src/network/kad/stream/p2p_network_kad_stream_actions.rs +++ b/p2p/src/network/kad/stream/p2p_network_kad_stream_actions.rs @@ -122,121 +122,3 @@ impl From for P2pAction { P2pAction::Network(super::super::P2pNetworkKadAction::Stream(value).into()) } } - -// impl ActionEvent for P2pNetworkKademliaStreamAction { -// fn action_event(&self, context: &T) -// where -// T: openmina_core::log::EventContext, -// { -// match self { -// P2pNetworkKademliaStreamAction::New { -// addr, -// peer_id, -// stream_id, -// incoming, -// } => action_debug!( -// context, -// addr = display(addr), -// peer_id = display(peer_id), -// stream_id, -// incoming -// ), -// P2pNetworkKademliaStreamAction::IncomingData { -// addr, -// peer_id, -// stream_id, -// data, -// } => action_debug!( -// context, -// addr = display(addr), -// peer_id = display(peer_id), -// stream_id, -// data = debug(data) -// ), -// P2pNetworkKademliaStreamAction::RemoteClose { -// addr, -// peer_id, -// stream_id, -// } => action_debug!( -// context, -// addr = display(addr), -// peer_id = display(peer_id), -// stream_id -// ), -// P2pNetworkKademliaStreamAction::WaitIncoming { -// addr, -// peer_id, -// stream_id, -// } => action_debug!( -// context, -// addr = display(addr), -// peer_id = display(peer_id), -// stream_id -// ), -// P2pNetworkKademliaStreamAction::WaitOutgoing { -// addr, -// peer_id, -// stream_id, -// } => action_debug!( -// context, -// addr = display(addr), -// peer_id = display(peer_id), -// stream_id -// ), -// P2pNetworkKademliaStreamAction::SendRequest { -// addr, -// peer_id, -// stream_id, -// data, -// } => action_debug!( -// context, -// addr = display(addr), -// peer_id = display(peer_id), -// stream_id, -// data = debug(data) -// ), -// P2pNetworkKademliaStreamAction::SendResponse { -// addr, -// peer_id, -// stream_id, -// data, -// } => action_debug!( -// context, -// addr = display(addr), -// peer_id = display(peer_id), -// stream_id, -// data = debug(data) -// ), -// P2pNetworkKademliaStreamAction::OutgoingDataReady { -// addr, -// peer_id, -// stream_id, -// } => action_debug!( -// context, -// addr = display(addr), -// peer_id = display(peer_id), -// stream_id -// ), -// P2pNetworkKademliaStreamAction::Close { -// addr, -// peer_id, -// stream_id, -// } => action_debug!( -// context, -// addr = display(addr), -// peer_id = display(peer_id), -// stream_id -// ), -// P2pNetworkKademliaStreamAction::Prune { -// addr, -// peer_id, -// stream_id, -// } => action_trace!( -// context, -// addr = display(addr), -// peer_id = display(peer_id), -// stream_id -// ), -// } -// } -// } diff --git a/p2p/src/network/noise/p2p_network_noise_actions.rs b/p2p/src/network/noise/p2p_network_noise_actions.rs index 5862d4d403..5433913de7 100644 --- a/p2p/src/network/noise/p2p_network_noise_actions.rs +++ b/p2p/src/network/noise/p2p_network_noise_actions.rs @@ -1,13 +1,14 @@ use std::net::SocketAddr; -use openmina_core::{action_trace, log::ActionEvent}; +use openmina_core::ActionEvent; use serde::{Deserialize, Serialize}; use crate::{Data, P2pNetworkAction, P2pState, PeerId}; use super::p2p_network_noise_state::{Pk, Sk}; -#[derive(Serialize, Deserialize, Debug, Clone)] +#[derive(Serialize, Deserialize, Debug, Clone, ActionEvent)] +#[action_event(level = trace, fields(display(addr), incoming, debug(data), display(peer_id)))] pub enum P2pNetworkNoiseAction { Init { addr: SocketAddr, @@ -37,6 +38,7 @@ pub enum P2pNetworkNoiseAction { data: Data, }, // the remote peer sends the data to internals thru noise + #[action_event(fields(display(addr), debug(data), debug(peer_id)))] DecryptedData { addr: SocketAddr, peer_id: Option, @@ -82,48 +84,3 @@ impl redux::EnablingCondition for P2pNetworkNoiseAction { } } } - -impl ActionEvent for P2pNetworkNoiseAction { - fn action_event(&self, context: &T) - where - T: openmina_core::log::EventContext, - { - match self { - P2pNetworkNoiseAction::Init { addr, incoming, .. } => { - action_trace!(context, addr = display(addr), incoming) - } - P2pNetworkNoiseAction::IncomingData { addr, data } => { - action_trace!(context, addr = display(addr), data = debug(data)) - } - P2pNetworkNoiseAction::IncomingChunk { addr, data } => { - action_trace!(context, addr = display(addr), data = debug(data)) - } - P2pNetworkNoiseAction::OutgoingChunk { addr, data } => { - action_trace!(context, addr = display(addr), data = debug(data)) - } - P2pNetworkNoiseAction::OutgoingData { addr, data } => { - action_trace!(context, addr = display(addr), data = debug(data)) - } - P2pNetworkNoiseAction::DecryptedData { - addr, - peer_id, - data, - } => action_trace!( - context, - addr = display(addr), - peer_id = debug(peer_id), - data = debug(data) - ), - P2pNetworkNoiseAction::HandshakeDone { - addr, - peer_id, - incoming, - } => action_trace!( - context, - addr = display(addr), - peer_id = display(peer_id), - incoming - ), - } - } -} diff --git a/p2p/src/network/pnet/p2p_network_pnet_actions.rs b/p2p/src/network/pnet/p2p_network_pnet_actions.rs index 881932a079..213f6ea6f7 100644 --- a/p2p/src/network/pnet/p2p_network_pnet_actions.rs +++ b/p2p/src/network/pnet/p2p_network_pnet_actions.rs @@ -1,11 +1,12 @@ use std::net::SocketAddr; -use openmina_core::{action_debug, action_trace, log::ActionEvent}; +use openmina_core::ActionEvent; use serde::{Deserialize, Serialize}; use crate::{Data, P2pState}; -#[derive(Serialize, Deserialize, Debug, Clone)] +#[derive(Serialize, Deserialize, Debug, Clone, ActionEvent)] +#[action_event(fields(display(addr), debug(data), incoming), level = trace)] pub enum P2pNetworkPnetAction { IncomingData { addr: SocketAddr, @@ -15,6 +16,7 @@ pub enum P2pNetworkPnetAction { addr: SocketAddr, data: Data, }, + #[action_event(level = debug)] SetupNonce { addr: SocketAddr, nonce: Data, @@ -43,22 +45,3 @@ impl redux::EnablingCondition for P2pNetworkPnetAction { true } } - -impl ActionEvent for P2pNetworkPnetAction { - fn action_event(&self, context: &T) - where - T: openmina_core::log::EventContext, - { - match self { - P2pNetworkPnetAction::IncomingData { addr, data } => { - action_trace!(context, addr = display(addr), data = debug(data)) - } - P2pNetworkPnetAction::OutgoingData { addr, data } => { - action_trace!(context, addr = display(addr), data = debug(data)) - } - P2pNetworkPnetAction::SetupNonce { addr, incoming, .. } => { - action_debug!(context, addr = display(addr), incoming) - } - } - } -} diff --git a/p2p/src/network/rpc/p2p_network_rpc_actions.rs b/p2p/src/network/rpc/p2p_network_rpc_actions.rs index 16d1037460..e15a0ad2a6 100644 --- a/p2p/src/network/rpc/p2p_network_rpc_actions.rs +++ b/p2p/src/network/rpc/p2p_network_rpc_actions.rs @@ -1,13 +1,14 @@ use std::net::SocketAddr; use mina_p2p_messages::rpc_kernel::{QueryHeader, ResponseHeader}; -use openmina_core::{action_debug, action_trace, log::ActionEvent}; +use openmina_core::{action_debug, action_trace, ActionEvent}; use serde::{Deserialize, Serialize}; use super::{super::*, *}; use crate::{P2pState, PeerId}; -#[derive(Serialize, Deserialize, Debug, Clone)] +#[derive(Serialize, Deserialize, Debug, Clone, ActionEvent)] +#[action_event(fields(display(addr), display(peer_id), incoming, stream_id, debug(data), fin))] pub enum P2pNetworkRpcAction { Init { addr: SocketAddr, @@ -15,12 +16,14 @@ pub enum P2pNetworkRpcAction { stream_id: StreamId, incoming: bool, }, + #[action_event(level = trace)] IncomingData { addr: SocketAddr, peer_id: PeerId, stream_id: StreamId, data: Data, }, + #[action_event(expr(log_message(context, message, addr, peer_id, stream_id)))] IncomingMessage { addr: SocketAddr, peer_id: PeerId, @@ -131,110 +134,45 @@ impl redux::EnablingCondition for P2pNetworkRpcAction { } } -impl ActionEvent for P2pNetworkRpcAction { - fn action_event(&self, context: &T) - where - T: openmina_core::log::EventContext, - { - match self { - P2pNetworkRpcAction::Init { - addr, - peer_id, - stream_id, - incoming, - } => action_debug!( - context, - addr = display(addr), - peer_id = display(peer_id), - stream_id, - incoming - ), - P2pNetworkRpcAction::IncomingData { - addr, - peer_id, - stream_id, - data, - } => action_trace!( - context, - addr = display(addr), - peer_id = display(peer_id), - stream_id, - data = debug(data) - ), - P2pNetworkRpcAction::IncomingMessage { - addr, - peer_id, - stream_id, - message, - } => match message { - RpcMessage::Handshake => action_trace!( - context, - addr = display(addr), - peer_id = display(peer_id), - stream_id, - message_kind = "handshake" - ), - RpcMessage::Heartbeat => action_trace!( - context, - addr = display(addr), - peer_id = display(peer_id), - stream_id, - message_kind = "heartbeat" - ), - RpcMessage::Query { header, .. } => action_debug!( - context, - addr = display(addr), - peer_id = display(peer_id), - stream_id, - message_kind = "query", - message_header = debug(header) - ), - RpcMessage::Response { header, .. } => action_debug!( - context, - addr = display(addr), - peer_id = display(peer_id), - stream_id, - message_kind = "response", - message_header = debug(header) - ), - }, - P2pNetworkRpcAction::PrunePending { peer_id, stream_id } => { - action_trace!(context, peer_id = display(peer_id), stream_id) - } - P2pNetworkRpcAction::OutgoingQuery { - peer_id, - query, - data, - } => action_debug!( - context, - peer_id = display(peer_id), - query = debug(query), - data = debug(data) - ), - P2pNetworkRpcAction::OutgoingResponse { - peer_id, - response, - data, - } => action_debug!( - context, - peer_id = display(peer_id), - response = debug(response), - data = debug(data) - ), - P2pNetworkRpcAction::OutgoingData { - addr, - peer_id, - stream_id, - data, - fin, - } => action_debug!( - context, - addr = display(addr), - peer_id = display(peer_id), - stream_id, - data = debug(data), - fin - ), - } +fn log_message( + context: &T, + message: &RpcMessage, + addr: &SocketAddr, + peer_id: &PeerId, + stream_id: &u32, +) where + T: openmina_core::log::EventContext, +{ + match message { + RpcMessage::Handshake => action_trace!( + context, + addr = display(addr), + peer_id = display(peer_id), + stream_id, + message_kind = "handshake" + ), + RpcMessage::Heartbeat => action_trace!( + context, + addr = display(addr), + peer_id = display(peer_id), + stream_id, + message_kind = "heartbeat" + ), + RpcMessage::Query { header, .. } => action_debug!( + context, + addr = display(addr), + peer_id = display(peer_id), + stream_id, + message_kind = "query", + message_header = debug(header) + ), + RpcMessage::Response { header, .. } => action_debug!( + context, + addr = display(addr), + peer_id = display(peer_id), + stream_id, + message_kind = "response", + message_header = debug(header) + ), } } diff --git a/p2p/src/network/scheduler/p2p_network_scheduler_actions.rs b/p2p/src/network/scheduler/p2p_network_scheduler_actions.rs index f315432e75..0d718cd95f 100644 --- a/p2p/src/network/scheduler/p2p_network_scheduler_actions.rs +++ b/p2p/src/network/scheduler/p2p_network_scheduler_actions.rs @@ -1,6 +1,6 @@ use std::net::{IpAddr, SocketAddr}; -use openmina_core::{action_debug, action_info, action_warn, log::ActionEvent}; +use openmina_core::ActionEvent; use serde::{Deserialize, Serialize}; use super::{ @@ -13,7 +13,8 @@ use super::{ use crate::{disconnection::P2pDisconnectionReason, P2pState, PeerId}; -#[derive(Serialize, Deserialize, Debug, Clone)] +#[derive(Serialize, Deserialize, Debug, Clone, ActionEvent)] +#[action_event(fields(display(ip), display(listener), display(addr), debug(result), select_kind = debug(kind)))] pub enum P2pNetworkSchedulerAction { InterfaceDetected { ip: IpAddr, @@ -24,6 +25,7 @@ pub enum P2pNetworkSchedulerAction { IncomingConnectionIsReady { listener: SocketAddr, }, + #[action_event(fields(debug(addr), debug(result)))] IncomingDidAccept { addr: Option, result: Result<(), String>, @@ -123,79 +125,3 @@ impl redux::EnablingCondition for P2pNetworkSchedulerAction { } } } - -impl ActionEvent for P2pNetworkSchedulerAction { - fn action_event(&self, context: &T) - where - T: openmina_core::log::EventContext, - { - match self { - P2pNetworkSchedulerAction::InterfaceDetected { ip } => { - action_debug!(context, ip = display(ip)) - } - P2pNetworkSchedulerAction::InterfaceExpired { ip } => { - action_debug!(context, ip = display(ip)) - } - P2pNetworkSchedulerAction::IncomingConnectionIsReady { listener } => { - action_debug!(context, listener = display(listener)) - } - P2pNetworkSchedulerAction::IncomingDidAccept { - addr, - result: Ok(_), - } => action_debug!(context, addr = debug(addr)), - P2pNetworkSchedulerAction::IncomingDidAccept { - addr, - result: Err(error), - } => action_debug!(context, addr = debug(addr), error = display(error)), - P2pNetworkSchedulerAction::OutgoingDidConnect { - addr, - result: Ok(_), - } => action_debug!(context, addr = display(addr)), - P2pNetworkSchedulerAction::OutgoingDidConnect { - addr, - result: Err(error), - } => action_debug!(context, addr = display(addr), error = display(error)), - P2pNetworkSchedulerAction::IncomingDataIsReady { addr } => { - action_debug!(context, addr = display(addr)) - } - P2pNetworkSchedulerAction::IncomingDataDidReceive { - addr, - result: Ok(data), - } => action_debug!(context, addr = display(addr), data = debug(data)), - P2pNetworkSchedulerAction::IncomingDataDidReceive { - addr, - result: Err(error), - } => action_debug!(context, addr = display(addr), error = display(error)), - P2pNetworkSchedulerAction::SelectDone { - addr, - kind, - protocol, - incoming, - } => action_debug!( - context, - addr = display(addr), - select_kind = debug(kind), - protocol = debug(protocol), - incoming = incoming - ), - P2pNetworkSchedulerAction::SelectError { addr, kind, error } => action_warn!( - context, - addr = display(addr), - select_kind = debug(kind), - error = display(error) - ), - P2pNetworkSchedulerAction::YamuxDidInit { addr, peer_id } => { - action_debug!(context, addr = display(addr), peer_id = display(peer_id)) - } - P2pNetworkSchedulerAction::Disconnect { addr, reason } => { - action_info!(context, addr = display(addr), reason = display(reason)) - } - P2pNetworkSchedulerAction::Error { addr, error } => { - action_warn!(context, addr = display(addr), error = display(error)) - } - P2pNetworkSchedulerAction::Disconnected { addr, reason } => { - action_info!(context, addr = display(addr), reason = display(reason)) - } - } - } -} diff --git a/p2p/src/network/select/p2p_network_select_actions.rs b/p2p/src/network/select/p2p_network_select_actions.rs index 61eec36f0b..7a672280f5 100644 --- a/p2p/src/network/select/p2p_network_select_actions.rs +++ b/p2p/src/network/select/p2p_network_select_actions.rs @@ -1,14 +1,17 @@ use std::net::SocketAddr; -use openmina_core::{action_debug, action_trace, log::ActionEvent}; +use openmina_core::ActionEvent; use serde::{Deserialize, Serialize}; use crate::{Data, P2pState, PeerId}; use super::{super::*, *}; -#[derive(derive_more::From, Serialize, Deserialize, Debug, Clone)] +#[derive(derive_more::From, Serialize, Deserialize, Debug, Clone, ActionEvent)] +#[action_event(fields(display(addr), select_kind = debug(kind), debug(data), send_handshake, fin, debug(token), debug(tokens)))] pub enum P2pNetworkSelectAction { + /// Initialize protocol selection. + /// /// Multistream Select protocol is running multiple times: /// When Pnet protocol is done for newly established TCP connection. We don't have `peer_id` yet. /// When Noise protocol is done and we have a `peer_id`. @@ -19,6 +22,7 @@ pub enum P2pNetworkSelectAction { incoming: bool, send_handshake: bool, }, + #[action_event(level = trace)] IncomingData { addr: SocketAddr, kind: SelectKind, @@ -101,49 +105,3 @@ impl redux::EnablingCondition for P2pNetworkSelectAction { } } } - -impl ActionEvent for P2pNetworkSelectAction { - fn action_event(&self, context: &T) - where - T: openmina_core::log::EventContext, - { - match self { - P2pNetworkSelectAction::Init { - addr, - kind, - incoming, - send_handshake, - } => action_debug!( - context, - addr = display(addr), - select_kind = debug(kind), - incoming, - send_handshake - ), - P2pNetworkSelectAction::IncomingData { - addr, - kind, - data, - fin, - } => action_trace!( - context, - addr = display(addr), - select_kind = debug(kind), - data = debug(data), - fin - ), - P2pNetworkSelectAction::IncomingToken { addr, kind, token } => action_debug!( - context, - addr = display(addr), - select_kind = debug(kind), - token = debug(token) - ), - P2pNetworkSelectAction::OutgoingTokens { addr, kind, tokens } => action_debug!( - context, - addr = display(addr), - select_kind = debug(kind), - tokens = debug(tokens) - ), - } - } -} diff --git a/p2p/src/network/yamux/p2p_network_yamux_actions.rs b/p2p/src/network/yamux/p2p_network_yamux_actions.rs index 60015e9526..0a1dc68642 100644 --- a/p2p/src/network/yamux/p2p_network_yamux_actions.rs +++ b/p2p/src/network/yamux/p2p_network_yamux_actions.rs @@ -1,12 +1,13 @@ use std::net::SocketAddr; -use openmina_core::{action_debug, action_trace, log::ActionEvent}; +use openmina_core::ActionEvent; use serde::{Deserialize, Serialize}; use super::p2p_network_yamux_state::{StreamId, YamuxFrame, YamuxPing}; use crate::{token, Data, P2pState}; -#[derive(Serialize, Deserialize, Debug, Clone)] +#[derive(Serialize, Deserialize, Debug, Clone, ActionEvent)] +#[action_event(fields(display(addr), stream_id, debug(data), fin, debug(stream_kind)))] pub enum P2pNetworkYamuxAction { IncomingData { addr: SocketAddr, @@ -18,10 +19,12 @@ pub enum P2pNetworkYamuxAction { data: Data, fin: bool, }, + #[action_event(level = trace)] IncomingFrame { addr: SocketAddr, frame: YamuxFrame, }, + #[action_event(level = trace)] OutgoingFrame { addr: SocketAddr, frame: YamuxFrame, @@ -78,47 +81,3 @@ impl redux::EnablingCondition for P2pNetworkYamuxAction { } } } - -impl ActionEvent for P2pNetworkYamuxAction { - fn action_event(&self, context: &T) - where - T: openmina_core::log::EventContext, - { - match self { - P2pNetworkYamuxAction::IncomingData { addr, data } => { - action_debug!(context, addr = debug(addr), data = debug(data)) - } - P2pNetworkYamuxAction::OutgoingData { - addr, - stream_id, - data, - fin, - } => action_debug!( - context, - addr = display(addr), - stream_id, - data = debug(data), - fin - ), - P2pNetworkYamuxAction::IncomingFrame { addr, frame } => { - action_trace!(context, addr = display(addr), frame = debug(frame)) - } - P2pNetworkYamuxAction::OutgoingFrame { addr, frame } => { - action_trace!(context, addr = display(addr), frame = debug(frame)) - } - P2pNetworkYamuxAction::PingStream { addr, ping } => { - action_debug!(context, addr = display(addr), ping = debug(ping)) - } - P2pNetworkYamuxAction::OpenStream { - addr, - stream_id, - stream_kind, - } => action_debug!( - context, - addr = display(addr), - stream_id, - stream_kind = debug(stream_kind) - ), - } - } -} diff --git a/p2p/src/peer/p2p_peer_actions.rs b/p2p/src/peer/p2p_peer_actions.rs index 9f2274f821..cb111d7344 100644 --- a/p2p/src/peer/p2p_peer_actions.rs +++ b/p2p/src/peer/p2p_peer_actions.rs @@ -1,4 +1,4 @@ -use openmina_core::{action_info, block::ArcBlockWithHash, log::ActionEvent}; +use openmina_core::{block::ArcBlockWithHash, ActionEvent}; use serde::{Deserialize, Serialize}; use crate::{P2pState, PeerId}; @@ -6,12 +6,12 @@ use crate::{P2pState, PeerId}; pub type P2pPeerActionWithMeta = redux::ActionWithMeta; pub type P2pPeerActionWithMetaRef<'a> = redux::ActionWithMeta<&'a P2pPeerAction>; -#[derive(Serialize, Deserialize, Debug, Clone)] +#[derive(Serialize, Deserialize, Debug, Clone, ActionEvent)] +#[action_event(level = info, fields(display(peer_id), best_tip = display(&best_tip.hash), incoming))] pub enum P2pPeerAction { - Ready { - peer_id: PeerId, - incoming: bool, - }, + /// Peer is ready. + Ready { peer_id: PeerId, incoming: bool }, + /// Peer's best tip is updated. BestTipUpdate { peer_id: PeerId, best_tip: ArcBlockWithHash, @@ -42,25 +42,3 @@ impl redux::EnablingCondition for P2pPeerAction { } } } - -impl ActionEvent for P2pPeerAction { - fn action_event(&self, context: &T) - where - T: openmina_core::log::EventContext, - { - match self { - P2pPeerAction::Ready { peer_id, incoming } => action_info!( - context, - summary = "Peer is ready", - peer_id = display(peer_id), - incoming, - ), - P2pPeerAction::BestTipUpdate { peer_id, best_tip } => action_info!( - context, - summary = "Best tip updated", - peer_id = display(peer_id), - best_tip = display(&best_tip.hash), - ), - } - } -} diff --git a/snark/src/work_verify/snark_work_verify_actions.rs b/snark/src/work_verify/snark_work_verify_actions.rs index 3bbc08fb2e..a0bd6155f8 100644 --- a/snark/src/work_verify/snark_work_verify_actions.rs +++ b/snark/src/work_verify/snark_work_verify_actions.rs @@ -1,14 +1,16 @@ use serde::{Deserialize, Serialize}; -use openmina_core::{action_info, action_trace, action_warn, log::ActionEvent, snark::Snark}; +use openmina_core::{snark::Snark, ActionEvent}; use super::{SnarkWorkVerifyError, SnarkWorkVerifyId}; pub type SnarkWorkVerifyActionWithMeta = redux::ActionWithMeta; pub type SnarkWorkVerifyActionWithMetaRef<'a> = redux::ActionWithMeta<&'a SnarkWorkVerifyAction>; -#[derive(Serialize, Deserialize, Debug, Clone)] +#[derive(Serialize, Deserialize, Debug, Clone, ActionEvent)] +#[action_event(level = trace, fields(display(req_id), display(error)))] pub enum SnarkWorkVerifyAction { + #[action_event(level = info)] Init { req_id: SnarkWorkVerifyId, batch: Vec, @@ -21,6 +23,7 @@ pub enum SnarkWorkVerifyAction { req_id: SnarkWorkVerifyId, error: SnarkWorkVerifyError, }, + #[action_event(level = info)] Success { req_id: SnarkWorkVerifyId, }, @@ -58,32 +61,3 @@ impl redux::EnablingCondition for SnarkWorkVerifyAction { } } } - -impl ActionEvent for SnarkWorkVerifyAction { - fn action_event(&self, context: &T) - where - T: openmina_core::log::EventContext, - { - match self { - SnarkWorkVerifyAction::Init { req_id, batch, .. } => action_info!( - context, - req_id = display(req_id), - trace_batch = - serde_json::to_string(&batch.iter().map(|v| v.job_id()).collect::>()) - .ok() - ), - SnarkWorkVerifyAction::Pending { req_id } => { - action_trace!(context, req_id = display(req_id)) - } - SnarkWorkVerifyAction::Error { req_id, error } => { - action_warn!(context, req_id = display(req_id), error = display(error)) - } - SnarkWorkVerifyAction::Success { req_id } => { - action_info!(context, req_id = display(req_id)) - } - SnarkWorkVerifyAction::Finish { req_id } => { - action_trace!(context, req_id = display(req_id)) - } - } - } -} From 1d0297435917f7feb46382b3c0726c3a78a526d9 Mon Sep 17 00:00:00 2001 From: Alexander Koptelov Date: Fri, 5 Apr 2024 12:24:01 +0300 Subject: [PATCH 7/7] feat(actions): cosmetic fixes --- macros/src/action_event.md | 40 ++++++++++++++++++-------------------- macros/src/action_event.rs | 6 +++--- 2 files changed, 22 insertions(+), 24 deletions(-) diff --git a/macros/src/action_event.md b/macros/src/action_event.md index 40e2432ecf..6267af32b8 100644 --- a/macros/src/action_event.md +++ b/macros/src/action_event.md @@ -5,7 +5,7 @@ Derives `[openmina_core::ActionEvent]` trait implementation for action. For action containers, it simply delegates to inner actions. -``` +```rust # use openmina_core::ActionEvent; # #[derive(ActionEvent)] @@ -21,7 +21,7 @@ enum Action1 { ActionContainer::SubAction1(Action1::Init).action_event(context); ``` -``` +```rust impl ActionEvent for ActionContainer { fn action_event(&self, context: &T) where T: ActionContext @@ -37,12 +37,11 @@ impl ActionEvent for Action1 { where T: ActionContext { match self { - Action1::Init => openmina_core::log::action_debug!(context), - Action1::Done => openmina_core::log::action_debug!(context), + Action1::Init => openmina_core::action_debug!(context), + Action1::Done => openmina_core::action_debug!(context), } } } - ``` ### Tracing level @@ -51,29 +50,30 @@ By default, tracing event of level `debug` is generated for an action. It can be overriden by using `#[action_event(level = ...)]` attribute. Also, actions that names ends with `Error` or `Warn` will be traced with `warn` level. -``` -#[derive(openmina_macros::ActionEvent)] +```rust +#[derive(openmina_core::ActionEvent)] #[action_event(level = trace)] pub enum Action { ActionDefaultLevel, #[action_event(level = warn)] ActionOverrideLevel, - WithErrorAction, - WithWarnAction, + ActionWithError, + ActionWithWarn, } ``` -``` +```rust impl openmina_core::ActionEvent for Action { fn action_event(&self, context: &T) where T: openmina_core::log::EventContext, { + #[allow(unused_variables)] match self { Action::ActionDefaultLevel => openmina_core::action_trace!(context), Action::ActionOverrideLevel => openmina_core::action_warn!(context), - Action::WithErrorAction => openmina_core::action_warn!(context), - Action::WithWarnAction => openmina_core::action_warn!(context), + Action::ActionWithError => openmina_core::action_warn!(context), + Action::ActionWithWarn => openmina_core::action_warn!(context), } } } @@ -85,8 +85,8 @@ impl openmina_core::ActionEvent for Action { If an action has doc-comment, its first line will be used for `summary` field of tracing events for the action. -``` -#[derive(openmina_macros::ActionEvent)] +```rust +#[derive(openmina_core::ActionEvent)] pub enum Action { Unit, /// documentation @@ -97,10 +97,9 @@ pub enum Action { /// And another. UnitWithMultilineDoc, } - ``` -``` +```rust impl openmina_core::ActionEvent for Action { fn action_event(&self, context: &T) where @@ -113,15 +112,14 @@ impl openmina_core::ActionEvent for Action { } } } - ``` ### Fields Certain fields can be added to the tracing event, using `#[action_event(fields(...))]` attribute. -``` -#[derive(openmina_macros::ActionEvent)] +```rust +#[derive(openmina_core::ActionEvent)] pub enum Action { NoFields { f1: bool }, #[action_event(fields(f1))] @@ -158,7 +156,7 @@ When an action needs some custom logic to log (e.g. different logging basing on a field's enum variant), logging can be delegated to a function implementing that logic. -``` +```rust #[derive(openmina_core::ActionEvent)] pub enum Action { #[action_event(expr(foo(context)))] @@ -168,7 +166,7 @@ pub enum Action { } ``` -``` +```rust impl openmina_core::ActionEvent for Action { fn action_event(&self, context: &T) where diff --git a/macros/src/action_event.rs b/macros/src/action_event.rs index abf97a4890..12908e17df 100644 --- a/macros/src/action_event.rs +++ b/macros/src/action_event.rs @@ -296,7 +296,7 @@ mod tests { #[test] fn test_delegate() -> anyhow::Result<()> { let input = r#" -#[derive(openmina_macros::ActionEvent)] +#[derive(openmina_core::ActionEvent)] pub enum SuperAction { Sub1(SubAction1), Sub2(SubAction2), @@ -322,7 +322,7 @@ impl openmina_core::ActionEvent for SuperAction { #[test] fn test_unit() -> anyhow::Result<()> { let input = r#" -#[derive(openmina_macros::ActionEvent)] +#[derive(openmina_core::ActionEvent)] pub enum Action { Unit, /// documentation @@ -355,7 +355,7 @@ impl openmina_core::ActionEvent for Action { #[test] fn test_level() -> anyhow::Result<()> { let input = r#" -#[derive(openmina_macros::ActionEvent)] +#[derive(openmina_core::ActionEvent)] #[action_event(level = trace)] pub enum Action { ActionDefaultLevel,