diff --git a/crates/hashi/src/metrics.rs b/crates/hashi/src/metrics.rs index c994c97fd7..c4f8c150f9 100644 --- a/crates/hashi/src/metrics.rs +++ b/crates/hashi/src/metrics.rs @@ -113,6 +113,8 @@ pub struct Metrics { pub mpc_sign_failures_total: IntCounterVec, /// Post-restart key recoveries that found suspicious local state pub mpc_recovery_suspicious_total: IntCounter, + pub mpc_avid_rounds_total: IntCounterVec, + pub mpc_avid_complaints_recovered_total: IntCounter, // MPC profiling metrics pub mpc_reconfig_total_duration_seconds: HistogramVec, @@ -663,6 +665,19 @@ impl Metrics { registry, ) .unwrap(), + mpc_avid_rounds_total: register_int_counter_vec_with_registry!( + "hashi_mpc_avid_rounds_total", + "AVID nonce rounds consumed, by resolved certificate kind", + &["kind"], + registry, + ) + .unwrap(), + mpc_avid_complaints_recovered_total: register_int_counter_with_registry!( + "hashi_mpc_avid_complaints_recovered_total", + "AVID nonce shares recovered via the complaint protocol", + registry, + ) + .unwrap(), mpc_recovery_suspicious_total: register_int_counter_with_registry!( "hashi_mpc_recovery_suspicious_total", "Post-restart key recoveries where local state contradicted the on-chain key \ diff --git a/crates/hashi/src/mpc/mpc_except_signing.rs b/crates/hashi/src/mpc/mpc_except_signing.rs index ed43edde11..10cea361b5 100644 --- a/crates/hashi/src/mpc/mpc_except_signing.rs +++ b/crates/hashi/src/mpc/mpc_except_signing.rs @@ -495,6 +495,15 @@ impl MpcManager { request.dealer ))); } + tracing::info!( + "AVID echo pull served: requester {:?}, dealer {:?}, batch_index={batch_index}, \ + common={}, vote={}, echo={}", + requester, + request.dealer, + common.is_some(), + avid_vote.is_some(), + echo.is_some() + ); Ok(RetrieveMessagesResponse { messages: Messages::AvidNonceRetrieval(AvidNonceRetrievalMessage { common, @@ -2485,6 +2494,17 @@ impl MpcManager { unreachable!("routed by the AVID complaint check") } }; + tracing::info!( + "AVID nonce complaint answered: accuser {:?}, dealer {:?}, batch_index={batch_index}, \ + kind {}", + caller, + request.dealer, + match &request.complaint { + ProtocolComplaint::AvidReveal(_) => "reveal", + ProtocolComplaint::AvidBlame { .. } => "blame", + _ => unreachable!("routed by the AVID complaint check"), + } + ); Ok(ComplaintResponse::NonceGenerationAvid(response)) } @@ -2513,6 +2533,11 @@ impl MpcManager { ciphertext: state.own_ciphertext, }; self.try_sign_avid_nonce_optimistic(dealer, batch_index, &message)?; + tracing::info!( + "AVID nonce output re-derived from persisted round state: dealer {:?}, \ + batch_index={batch_index}", + dealer + ); Ok(()) } @@ -2717,11 +2742,12 @@ impl MpcManager { .await; } let pending = dealer_data.total_reduced_weight - confirmed; - let (max_faulty, min_confirm_weight) = { + let (max_faulty, min_confirm_weight, address) = { let mgr = mpc_manager.read().unwrap(); ( mgr.mpc_config.max_faulty as u32, (mgr.mpc_config.threshold + mgr.mpc_config.max_faulty) as u32, + mgr.address, ) }; if pending > max_faulty || confirmed < min_confirm_weight { @@ -2731,6 +2757,10 @@ impl MpcManager { ); return Ok(()); } + tracing::info!( + "AVID nonce round entered the pessimistic path: dealer {address:?}, \ + batch_index={batch_index}, confirmed weight {confirmed}, pending weight {pending}" + ); let confirm_cert = aggregator .finish() .expect("signatures should always be valid"); @@ -2803,6 +2833,12 @@ impl MpcManager { } } if (vote_aggregator.reduced_weight() as u32) >= dealer_data.vote_quorum_weight { + tracing::info!( + "AVID nonce Vote quorum reached: dealer {address:?}, batch_index={batch_index}, \ + weight {} >= {}", + vote_aggregator.reduced_weight(), + dealer_data.vote_quorum_weight + ); let cert = vote_aggregator .finish() .expect("signatures should always be valid"); @@ -2859,6 +2895,7 @@ impl MpcManager { batch_index: u32, nonce_cert: &DealerCertificate, p2p_channel: &impl P2PChannel, + metrics: &Metrics, ) -> MpcResult { let (request, signers) = { let mgr = mpc_manager.read().unwrap(); @@ -2963,7 +3000,12 @@ impl MpcManager { &vote_cert, &mut rng, ) { - Ok(batch_avss_avid::DecodeAndDecryptOutcome::Valid(..)) => {} + Ok(batch_avss_avid::DecodeAndDecryptOutcome::Valid(..)) => { + tracing::info!( + "AVID laggard decode completed: dealer {:?}, batch_index={batch_index}", + dealer + ); + } Ok(batch_avss_avid::DecodeAndDecryptOutcome::InvalidDecryption(complaint)) => { return Ok(( CertKind::AvidVote, @@ -2999,6 +3041,7 @@ impl MpcManager { complaint, complaint_signers, p2p_channel, + metrics, ) .await { @@ -3011,6 +3054,7 @@ impl MpcManager { Ok(kind) } + #[allow(clippy::too_many_arguments)] async fn recover_avid_nonce_shares_via_complaint( mpc_manager: &Arc>, dealer: Address, @@ -3019,6 +3063,7 @@ impl MpcManager { complaint: ProtocolComplaint, signers: Vec
, p2p_channel: &impl P2PChannel, + metrics: &Metrics, ) -> MpcResult<()> { let epoch = { let mgr = mpc_manager.read().unwrap(); @@ -3099,6 +3144,13 @@ impl MpcManager { let mut mgr = mpc_manager.write().unwrap(); mgr.dealer_avid_nonce_outputs .insert((batch_index, dealer), output); + tracing::info!( + "AVID nonce shares recovered via complaint: dealer {:?}, \ + batch_index={batch_index}, responses used {}", + dealer, + verified.len() + ); + metrics.mpc_avid_complaints_recovered_total.inc(); return Ok(()); } } @@ -3190,6 +3242,7 @@ impl MpcManager { batch_index, &nonce_cert, p2p_channel, + metrics, ) .await; drop(_timer); @@ -3239,6 +3292,18 @@ impl MpcManager { .weight_of(party_id) .map_err(|_| MpcError::ProtocolFailed("Missing dealer weight".to_string()))? }; + tracing::info!( + "AVID nonce round consumed: dealer {:?}, batch_index={batch_index}, kind {:?}", + dealer, + kind + ); + metrics + .mpc_avid_rounds_total + .with_label_values(&[match kind { + CertKind::AvssVote => "confirm", + CertKind::AvidVote => "vote", + }]) + .inc(); dealer_weight_sum += dealer_weight as u32; certified_dealers.insert(dealer); } diff --git a/crates/hashi/src/mpc/mpc_except_signing_tests.rs b/crates/hashi/src/mpc/mpc_except_signing_tests.rs index 94e7dea9cc..0090497980 100644 --- a/crates/hashi/src/mpc/mpc_except_signing_tests.rs +++ b/crates/hashi/src/mpc/mpc_except_signing_tests.rs @@ -12087,12 +12087,13 @@ async fn test_run_as_avid_nonce_party_consumes_full_cert_and_ignores_thin() { let party = Arc::new(RwLock::new(managers.remove(&setup.address(1)).unwrap())); let mock_p2p = MockP2PChannel::new(managers, setup.address(1)); let mut mock_tob = MockOrderedBroadcastChannel::new(vec![thin_cert, full_cert]); + let metrics = test_metrics(); let certified = MpcManager::run_as_avid_nonce_party( &party, batch_index, &mock_p2p, &mut mock_tob, - &test_metrics(), + &metrics, ) .await .unwrap(); @@ -12103,6 +12104,14 @@ async fn test_run_as_avid_nonce_party_consumes_full_cert_and_ignores_thin() { Some(0), "the thin cert was ignored — the full cert had to be consumed for the quorum" ); + assert!( + metrics + .mpc_avid_rounds_total + .with_label_values(&["confirm"]) + .get() + >= 1, + "a confirm-kind consumption must be counted" + ); } #[tokio::test] @@ -12215,12 +12224,13 @@ async fn test_run_as_avid_nonce_party_laggard_pulls_and_decodes() { voters.insert(dealer_addr, dealer.into_inner().unwrap()); let laggard = Arc::new(RwLock::new(setup.create_manager(5))); let laggard_p2p = MockP2PChannel::new(voters, setup.address(5)); + let metrics = test_metrics(); let result = MpcManager::run_as_avid_nonce_party( &laggard, batch_index, &laggard_p2p, &mut mock_tob, - &test_metrics(), + &metrics, ) .await; assert!(result.is_err(), "mock TOB runs dry: {result:?}"); @@ -12230,6 +12240,14 @@ async fn test_run_as_avid_nonce_party_laggard_pulls_and_decodes() { .contains_key(&(batch_index, dealer_addr)), "the laggard decoded its share from pulled echoes" ); + assert!( + metrics + .mpc_avid_rounds_total + .with_label_values(&["vote"]) + .get() + >= 1, + "a vote-kind consumption must be counted" + ); } #[tokio::test] @@ -12588,12 +12606,13 @@ async fn test_run_as_avid_nonce_party_recovers_via_complaint() { ); let party = Arc::new(RwLock::new(victim_mgr)); let party_p2p = MockP2PChannel::new(nodes, victim); + let metrics = test_metrics(); let result = MpcManager::run_as_avid_nonce_party( &party, batch_index, &party_p2p, &mut mock_tob, - &test_metrics(), + &metrics, ) .await; assert!(result.is_err(), "mock TOB runs dry: {result:?}"); @@ -12603,6 +12622,10 @@ async fn test_run_as_avid_nonce_party_recovers_via_complaint() { .contains_key(&(batch_index, dealer_addr)), "the victim recovered its share via the complaint path" ); + assert!( + metrics.mpc_avid_complaints_recovered_total.get() >= 1, + "the complaint recovery must be counted" + ); } #[test]