diff --git a/Cargo.lock b/Cargo.lock index 02ccf11661443..0175b3b92477a 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -24198,6 +24198,7 @@ dependencies = [ "sp-core 28.0.0", "sp-io 30.0.0", "sp-runtime 31.0.1", + "sp-tracing 16.0.0", "sp-weights 27.0.0", "staging-xcm", "staging-xcm-executor", diff --git a/polkadot/xcm/pallet-xcm/src/lib.rs b/polkadot/xcm/pallet-xcm/src/lib.rs index e018b5ec211f7..55e0be5288186 100644 --- a/polkadot/xcm/pallet-xcm/src/lib.rs +++ b/polkadot/xcm/pallet-xcm/src/lib.rs @@ -1437,8 +1437,10 @@ pub mod pallet { ClaimAsset { assets, ticket }, DepositAsset { assets: AllCounted(number_of_assets).into(), beneficiary }, ]); - let weight = - T::Weigher::weight(&mut message).map_err(|()| Error::::UnweighableMessage)?; + let weight = T::Weigher::weight(&mut message).map_err(|error| { + tracing::debug!(target: "xcm::pallet_xcm::claim_assets", ?error, "Failed to calculate weight"); + Error::::UnweighableMessage + })?; let mut hash = message.using_encoded(sp_io::hashing::blake2_256); let outcome = T::XcmExecutor::prepare_and_execute( origin_location, @@ -2069,7 +2071,10 @@ impl Pallet { ); let weight = - T::Weigher::weight(&mut local_xcm).map_err(|()| Error::::UnweighableMessage)?; + T::Weigher::weight(&mut local_xcm).map_err(|error| { + tracing::debug!(target: "xcm::pallet_xcm::execute_xcm_transfer", ?error, "Failed to calculate weight"); + Error::::UnweighableMessage + })?; let mut hash = local_xcm.using_encoded(sp_io::hashing::blake2_256); let outcome = T::XcmExecutor::prepare_and_execute( origin.clone(), @@ -2947,12 +2952,12 @@ impl Pallet { pub fn query_xcm_weight(message: VersionedXcm<()>) -> Result { let message = Xcm::<()>::try_from(message.clone()) .map_err(|e| { - tracing::error!(target: "xcm::pallet_xcm::query_xcm_weight", ?e, ?message, "Failed to convert versioned message"); + tracing::debug!(target: "xcm::pallet_xcm::query_xcm_weight", ?e, ?message, "Failed to convert versioned message"); XcmPaymentApiError::VersionedConversionFailed })?; - T::Weigher::weight(&mut message.clone().into()).map_err(|()| { - tracing::error!(target: "xcm::pallet_xcm::query_xcm_weight", ?message, "Error when querying XCM weight"); + T::Weigher::weight(&mut message.clone().into()).map_err(|error| { + tracing::debug!(target: "xcm::pallet_xcm::query_xcm_weight", ?error, ?message, "Error when querying XCM weight"); XcmPaymentApiError::WeightNotComputable }) } diff --git a/polkadot/xcm/xcm-builder/Cargo.toml b/polkadot/xcm/xcm-builder/Cargo.toml index 92a3f0203261e..85b9c9c77ec4e 100644 --- a/polkadot/xcm/xcm-builder/Cargo.toml +++ b/polkadot/xcm/xcm-builder/Cargo.toml @@ -41,6 +41,7 @@ polkadot-primitives = { workspace = true, default-features = true } polkadot-runtime-parachains = { workspace = true, default-features = true } polkadot-test-runtime = { workspace = true } primitive-types = { features = ["codec", "num-traits", "scale-info"], workspace = true } +sp-tracing = { features = ["test-utils"], workspace = true, default-features = true } xcm-simulator = { workspace = true, default-features = true } [features] diff --git a/polkadot/xcm/xcm-builder/src/tests/weight.rs b/polkadot/xcm/xcm-builder/src/tests/weight.rs index 637e30cce998b..a2d44b3a8b311 100644 --- a/polkadot/xcm/xcm-builder/src/tests/weight.rs +++ b/polkadot/xcm/xcm-builder/src/tests/weight.rs @@ -153,30 +153,60 @@ fn errors_should_return_unused_weight() { #[test] fn weight_bounds_should_respect_instructions_limit() { + use sp_tracing::capture_test_logs; + + sp_tracing::init_for_tests(); MaxInstructions::set(3); - let mut message = Xcm(vec![ClearOrigin; 4]); // 4 instructions are too many. - assert_eq!(::Weigher::weight(&mut message), Err(())); - - let mut message = - Xcm(vec![SetErrorHandler(Xcm(vec![ClearOrigin])), SetAppendix(Xcm(vec![ClearOrigin]))]); - // 4 instructions are too many, even when hidden within 2. - assert_eq!(::Weigher::weight(&mut message), Err(())); - - let mut message = - Xcm(vec![SetErrorHandler(Xcm(vec![SetErrorHandler(Xcm(vec![SetErrorHandler(Xcm( - vec![ClearOrigin], - ))]))]))]); - // 4 instructions are too many, even when it's just one that's 3 levels deep. - assert_eq!(::Weigher::weight(&mut message), Err(())); - - let mut message = - Xcm(vec![SetErrorHandler(Xcm(vec![SetErrorHandler(Xcm(vec![ClearOrigin]))]))]); - // 3 instructions are OK. - assert_eq!( - ::Weigher::weight(&mut message), - Ok(Weight::from_parts(30, 30)) - ); + let log_capture = capture_test_logs!({ + let mut message = Xcm(vec![ClearOrigin; 4]); + assert_eq!( + ::Weigher::weight(&mut message), + Err(XcmError::ExceedsStackLimit) + ); + }); + assert!(log_capture.contains( + "Weight calculation failed for message error=ExceedsStackLimit instructions_left=3 message_length=4" + )); + + let log_capture = capture_test_logs!({ + let mut message = + Xcm(vec![SetErrorHandler(Xcm(vec![ClearOrigin])), SetAppendix(Xcm(vec![ClearOrigin]))]); + // 4 instructions are too many, even when hidden within 2. + assert_eq!( + ::Weigher::weight(&mut message), + Err(XcmError::ExceedsStackLimit) + ); + }); + assert!(log_capture.contains( + "Weight calculation failed for message error=ExceedsStackLimit instructions_left=0 message_length=2" + )); + + let log_capture = capture_test_logs!({ + let mut message = + Xcm(vec![SetErrorHandler(Xcm(vec![SetErrorHandler(Xcm(vec![SetErrorHandler( + Xcm(vec![ClearOrigin]), + )]))]))]); + // 4 instructions are too many, even when it's just one that's 3 levels deep. + assert_eq!( + ::Weigher::weight(&mut message), + Err(XcmError::ExceedsStackLimit) + ); + }); + assert!(log_capture.contains( + "Weight calculation failed for message error=ExceedsStackLimit instructions_left=0 message_length=1" + )); + + let log_capture = capture_test_logs!({ + let mut message = + Xcm(vec![SetErrorHandler(Xcm(vec![SetErrorHandler(Xcm(vec![ClearOrigin]))]))]); + // 3 instructions are OK. + assert_eq!( + ::Weigher::weight(&mut message), + Ok(Weight::from_parts(30, 30)) + ); + }); + assert!(!log_capture.contains("Weight calculation failed for message")); } #[test] diff --git a/polkadot/xcm/xcm-builder/src/weight.rs b/polkadot/xcm/xcm-builder/src/weight.rs index 9e90053bf27fc..13339a304ab2e 100644 --- a/polkadot/xcm/xcm-builder/src/weight.rs +++ b/polkadot/xcm/xcm-builder/src/weight.rs @@ -38,38 +38,61 @@ pub struct FixedWeightBounds(PhantomData<(T, C, M)>); impl, C: Decode + GetDispatchInfo, M: Get> WeightBounds for FixedWeightBounds { - fn weight(message: &mut Xcm) -> Result { + fn weight(message: &mut Xcm) -> Result { tracing::trace!(target: "xcm::weight", ?message, "FixedWeightBounds"); let mut instructions_left = M::get(); - Self::weight_with_limit(message, &mut instructions_left) + Self::weight_with_limit(message, &mut instructions_left).inspect_err(|&error| { + tracing::debug!( + target: "xcm::weight", + ?error, + ?instructions_left, + message_length = ?message.0.len(), + "Weight calculation failed for message" + ); + }) } - fn instr_weight(instruction: &mut Instruction) -> Result { - Self::instr_weight_with_limit(instruction, &mut u32::max_value()) + fn instr_weight(instruction: &mut Instruction) -> Result { + let mut max_value = u32::MAX; + Self::instr_weight_with_limit(instruction, &mut max_value).inspect_err(|&error| { + tracing::debug!( + target: "xcm::weight", + ?error, + ?instruction, + instrs_limit = ?max_value, + "Weight calculation failed for instruction" + ); + }) } } impl, C: Decode + GetDispatchInfo, M> FixedWeightBounds { - fn weight_with_limit(message: &mut Xcm, instrs_limit: &mut u32) -> Result { + fn weight_with_limit(message: &mut Xcm, instrs_limit: &mut u32) -> Result { let mut r: Weight = Weight::zero(); - *instrs_limit = instrs_limit.checked_sub(message.0.len() as u32).ok_or(())?; + *instrs_limit = instrs_limit + .checked_sub(message.0.len() as u32) + .ok_or_else(|| XcmError::ExceedsStackLimit)?; for instruction in message.0.iter_mut() { r = r .checked_add(&Self::instr_weight_with_limit(instruction, instrs_limit)?) - .ok_or(())?; + .ok_or_else(|| XcmError::Overflow)?; } Ok(r) } fn instr_weight_with_limit( instruction: &mut Instruction, instrs_limit: &mut u32, - ) -> Result { + ) -> Result { let instr_weight = match instruction { - Transact { ref mut call, .. } => call.ensure_decoded()?.get_dispatch_info().call_weight, + Transact { ref mut call, .. } => + call.ensure_decoded() + .map_err(|_| XcmError::FailedToDecode)? + .get_dispatch_info() + .call_weight, SetErrorHandler(xcm) | SetAppendix(xcm) | ExecuteWithOrigin { xcm, .. } => Self::weight_with_limit(xcm, instrs_limit)?, _ => Weight::zero(), }; - T::get().checked_add(&instr_weight).ok_or(()) + T::get().checked_add(&instr_weight).ok_or_else(|| XcmError::Overflow) } } @@ -81,13 +104,30 @@ where M: Get, Instruction: xcm::latest::GetWeight, { - fn weight(message: &mut Xcm) -> Result { + fn weight(message: &mut Xcm) -> Result { tracing::trace!(target: "xcm::weight", ?message, "WeightInfoBounds"); let mut instructions_left = M::get(); - Self::weight_with_limit(message, &mut instructions_left) + Self::weight_with_limit(message, &mut instructions_left).inspect_err(|&error| { + tracing::debug!( + target: "xcm::weight", + ?error, + ?instructions_left, + message_length = ?message.0.len(), + "Weight calculation failed for message" + ); + }) } - fn instr_weight(instruction: &mut Instruction) -> Result { - Self::instr_weight_with_limit(instruction, &mut u32::max_value()) + fn instr_weight(instruction: &mut Instruction) -> Result { + let mut max_value = u32::MAX; + Self::instr_weight_with_limit(instruction, &mut max_value).inspect_err(|&error| { + tracing::debug!( + target: "xcm::weight", + ?error, + ?instruction, + instrs_limit = ?max_value, + "Weight calculation failed for instruction" + ); + }) } } @@ -98,26 +138,35 @@ where M: Get, Instruction: xcm::latest::GetWeight, { - fn weight_with_limit(message: &mut Xcm, instrs_limit: &mut u32) -> Result { + fn weight_with_limit(message: &mut Xcm, instrs_limit: &mut u32) -> Result { let mut r: Weight = Weight::zero(); - *instrs_limit = instrs_limit.checked_sub(message.0.len() as u32).ok_or(())?; + *instrs_limit = instrs_limit + .checked_sub(message.0.len() as u32) + .ok_or_else(|| XcmError::ExceedsStackLimit)?; for instruction in message.0.iter_mut() { r = r .checked_add(&Self::instr_weight_with_limit(instruction, instrs_limit)?) - .ok_or(())?; + .ok_or_else(|| XcmError::Overflow)?; } Ok(r) } fn instr_weight_with_limit( instruction: &mut Instruction, instrs_limit: &mut u32, - ) -> Result { + ) -> Result { let instr_weight = match instruction { - Transact { ref mut call, .. } => call.ensure_decoded()?.get_dispatch_info().call_weight, + Transact { ref mut call, .. } => + call.ensure_decoded() + .map_err(|_| XcmError::FailedToDecode)? + .get_dispatch_info() + .call_weight, SetErrorHandler(xcm) | SetAppendix(xcm) => Self::weight_with_limit(xcm, instrs_limit)?, _ => Weight::zero(), }; - instruction.weight().checked_add(&instr_weight).ok_or(()) + instruction + .weight() + .checked_add(&instr_weight) + .ok_or_else(|| XcmError::Overflow) } } diff --git a/polkadot/xcm/xcm-executor/src/lib.rs b/polkadot/xcm/xcm-executor/src/lib.rs index a14c417217634..974e7e04b83f7 100644 --- a/polkadot/xcm/xcm-executor/src/lib.rs +++ b/polkadot/xcm/xcm-executor/src/lib.rs @@ -233,7 +233,15 @@ impl ExecuteXcm for XcmExecutor Result> { match Config::Weigher::weight(&mut message) { Ok(weight) => Ok(WeighedMessage(weight, message)), - Err(_) => Err(message), + Err(error) => { + tracing::debug!( + target: "xcm::prepare", + ?error, + ?message, + "Failed to calculate weight for XCM message; execution aborted" + ); + Err(message) + }, } } fn execute( @@ -1426,7 +1434,15 @@ impl XcmExecutor { RefundSurplus => self.refund_surplus(), SetErrorHandler(mut handler) => { let handler_weight = Config::Weigher::weight(&mut handler) - .map_err(|()| XcmError::WeightNotComputable)?; + .map_err(|error| { + tracing::debug!( + target: "xcm::executor::SetErrorHandler", + ?error, + ?handler, + "Failed to calculate weight" + ); + XcmError::WeightNotComputable + })?; self.total_surplus.saturating_accrue(self.error_handler_weight); self.error_handler = handler; self.error_handler_weight = handler_weight; @@ -1434,7 +1450,15 @@ impl XcmExecutor { }, SetAppendix(mut appendix) => { let appendix_weight = Config::Weigher::weight(&mut appendix) - .map_err(|()| XcmError::WeightNotComputable)?; + .map_err(|error| { + tracing::debug!( + target: "xcm::executor::SetErrorHandler", + ?error, + ?appendix, + "Failed to calculate weight" + ); + XcmError::WeightNotComputable + })?; self.total_surplus.saturating_accrue(self.appendix_weight); self.appendix = appendix; self.appendix_weight = appendix_weight; diff --git a/polkadot/xcm/xcm-executor/src/tests/mock.rs b/polkadot/xcm/xcm-executor/src/tests/mock.rs index 567d170b16279..52b3aef56c405 100644 --- a/polkadot/xcm/xcm-executor/src/tests/mock.rs +++ b/polkadot/xcm/xcm-executor/src/tests/mock.rs @@ -89,11 +89,11 @@ impl GetDispatchInfo for TestCall { /// Test weigher that just returns a fixed weight for every program. pub struct TestWeigher; impl WeightBounds for TestWeigher { - fn weight(_message: &mut Xcm) -> Result { + fn weight(_message: &mut Xcm) -> Result { Ok(Weight::from_parts(2, 2)) } - fn instr_weight(_instruction: &mut Instruction) -> Result { + fn instr_weight(_instruction: &mut Instruction) -> Result { Ok(Weight::from_parts(2, 2)) } } diff --git a/polkadot/xcm/xcm-executor/src/traits/weight.rs b/polkadot/xcm/xcm-executor/src/traits/weight.rs index 4e41aa5b47530..c61ba2fe16d40 100644 --- a/polkadot/xcm/xcm-executor/src/traits/weight.rs +++ b/polkadot/xcm/xcm-executor/src/traits/weight.rs @@ -22,11 +22,11 @@ use xcm::latest::{prelude::*, Weight}; pub trait WeightBounds { /// Return the maximum amount of weight that an attempted execution of this message could /// consume. - fn weight(message: &mut Xcm) -> Result; + fn weight(message: &mut Xcm) -> Result; /// Return the maximum amount of weight that an attempted execution of this instruction could /// consume. - fn instr_weight(instruction: &mut Instruction) -> Result; + fn instr_weight(instruction: &mut Instruction) -> Result; } /// Charge for weight in order to execute XCM. diff --git a/prdoc/pr_8535.prdoc b/prdoc/pr_8535.prdoc new file mode 100644 index 0000000000000..12f9c7ee15ef2 --- /dev/null +++ b/prdoc/pr_8535.prdoc @@ -0,0 +1,12 @@ +title: Make `WeightBounds` return `XcmError` to surface failures +doc: +- audience: Runtime Dev + description: |- + Improved XCM weight calculation error handling and traceability. The `WeightBounds` trait now returns detailed `XcmError` types instead of opaque results, allowing downstream consumers to access specific error context for failures like instruction decoding issues, weight overflows, and instruction limit violations. Added structured debug logging with contextual information to aid in diagnosing weight estimation failures during message preparation and execution. +crates: +- name: pallet-xcm + bump: patch +- name: staging-xcm-builder + bump: major +- name: staging-xcm-executor + bump: major