diff --git a/xcm/pallet-xcm/src/lib.rs b/xcm/pallet-xcm/src/lib.rs index 393d015d6592..f9d3bc05e08c 100644 --- a/xcm/pallet-xcm/src/lib.rs +++ b/xcm/pallet-xcm/src/lib.rs @@ -1192,6 +1192,11 @@ pub mod pallet { /// Note that a particular destination to whom we would like to send a message is unknown /// and queue it for version discovery. fn note_unknown_version(dest: &MultiLocation) { + log::trace!( + target: "xcm::pallet_xcm::note_unknown_version", + "XCM version is unknown for destination: {:?}", + dest, + ); let versioned_dest = VersionedMultiLocation::from(dest.clone()); VersionDiscoveryQueue::::mutate(|q| { if let Some(index) = q.iter().position(|i| &i.0 == &versioned_dest) { @@ -1214,7 +1219,14 @@ pub mod pallet { Self::note_unknown_version(dest); SafeXcmVersion::::get() }) - .ok_or(()) + .ok_or_else(|| { + log::trace!( + target: "xcm::pallet_xcm::wrap_version", + "Could not determine a version to wrap XCM for destination: {:?}", + dest, + ); + () + }) .and_then(|v| xcm.into().into_version(v.min(XCM_VERSION))) } } diff --git a/xcm/xcm-builder/src/barriers.rs b/xcm/xcm-builder/src/barriers.rs index b1305666fa09..ef7333e6d140 100644 --- a/xcm/xcm-builder/src/barriers.rs +++ b/xcm/xcm-builder/src/barriers.rs @@ -35,6 +35,11 @@ impl ShouldExecute for TakeWeightCredit { max_weight: Weight, weight_credit: &mut Weight, ) -> Result<(), ()> { + log::trace!( + target: "xcm::barriers", + "TakeWeightCredit origin: {:?}, message: {:?}, max_weight: {:?}, weight_credit: {:?}", + _origin, _message, max_weight, weight_credit, + ); *weight_credit = weight_credit.checked_sub(max_weight).ok_or(())?; Ok(()) } @@ -53,6 +58,11 @@ impl> ShouldExecute for AllowTopLevelPaidExecutionFro max_weight: Weight, _weight_credit: &mut Weight, ) -> Result<(), ()> { + log::trace!( + target: "xcm::barriers", + "AllowTopLevelPaidExecutionFrom origin: {:?}, message: {:?}, max_weight: {:?}, weight_credit: {:?}", + origin, message, max_weight, _weight_credit, + ); ensure!(T::contains(origin), ()); let mut iter = message.0.iter_mut(); let i = iter.next().ok_or(())?; @@ -91,6 +101,11 @@ impl> ShouldExecute for AllowUnpaidExecutionFrom { _max_weight: Weight, _weight_credit: &mut Weight, ) -> Result<(), ()> { + log::trace!( + target: "xcm::barriers", + "AllowUnpaidExecutionFrom origin: {:?}, message: {:?}, max_weight: {:?}, weight_credit: {:?}", + origin, _message, _max_weight, _weight_credit, + ); ensure!(T::contains(origin), ()); Ok(()) } @@ -117,6 +132,11 @@ impl ShouldExecute for AllowKnownQueryResponses Result<(), ()> { + log::trace!( + target: "xcm::barriers", + "AllowKnownQueryResponses origin: {:?}, message: {:?}, max_weight: {:?}, weight_credit: {:?}", + origin, message, _max_weight, _weight_credit, + ); match message.0.first() { Some(QueryResponse { query_id, .. }) if ResponseHandler::expecting_response(origin, *query_id) => @@ -136,6 +156,11 @@ impl> ShouldExecute for AllowSubscriptionsFrom { _max_weight: Weight, _weight_credit: &mut Weight, ) -> Result<(), ()> { + log::trace!( + target: "xcm::barriers", + "AllowSubscriptionsFrom origin: {:?}, message: {:?}, max_weight: {:?}, weight_credit: {:?}", + origin, message, _max_weight, _weight_credit, + ); ensure!(T::contains(origin), ()); match (message.0.len(), message.0.first()) { (1, Some(SubscribeVersion { .. })) | (1, Some(UnsubscribeVersion)) => Ok(()), diff --git a/xcm/xcm-builder/src/currency_adapter.rs b/xcm/xcm-builder/src/currency_adapter.rs index 164720e24a9a..23da4fcfc8a4 100644 --- a/xcm/xcm-builder/src/currency_adapter.rs +++ b/xcm/xcm-builder/src/currency_adapter.rs @@ -97,6 +97,7 @@ impl< for CurrencyAdapter { fn can_check_in(_origin: &MultiLocation, what: &MultiAsset) -> Result { + log::trace!(target: "xcm::currency_adapter", "can_check_in origin: {:?}, what: {:?}", _origin, what); // Check we handle this asset. let amount: Currency::Balance = Matcher::matches_fungible(what).ok_or(Error::AssetNotFound)?; @@ -116,6 +117,7 @@ impl< } fn check_in(_origin: &MultiLocation, what: &MultiAsset) { + log::trace!(target: "xcm::currency_adapter", "check_in origin: {:?}, what: {:?}", _origin, what); if let Some(amount) = Matcher::matches_fungible(what) { if let Some(checked_account) = CheckedAccount::get() { let ok = Currency::withdraw( @@ -134,6 +136,7 @@ impl< } fn check_out(_dest: &MultiLocation, what: &MultiAsset) { + log::trace!(target: "xcm::currency_adapter", "check_out dest: {:?}, what: {:?}", _dest, what); if let Some(amount) = Matcher::matches_fungible(what) { if let Some(checked_account) = CheckedAccount::get() { Currency::deposit_creating(&checked_account, amount); @@ -142,7 +145,7 @@ impl< } fn deposit_asset(what: &MultiAsset, who: &MultiLocation) -> Result { - log::trace!("xcm::currency_adapter deposit_asset {:?} {:?}", what, who); + log::trace!(target: "xcm::currency_adapter", "deposit_asset what: {:?}, who: {:?}", what, who); // Check we handle this asset. let amount: u128 = Matcher::matches_fungible(&what).ok_or(Error::AssetNotFound)?.saturated_into(); @@ -155,6 +158,7 @@ impl< } fn withdraw_asset(what: &MultiAsset, who: &MultiLocation) -> result::Result { + log::trace!(target: "xcm::currency_adapter", "withdraw_asset what: {:?}, who: {:?}", what, who); // Check we handle this asset. let amount: u128 = Matcher::matches_fungible(what).ok_or(Error::AssetNotFound)?.saturated_into(); diff --git a/xcm/xcm-builder/src/filter_asset_location.rs b/xcm/xcm-builder/src/filter_asset_location.rs index 9794c2f44f5b..a1e1763d0e40 100644 --- a/xcm/xcm-builder/src/filter_asset_location.rs +++ b/xcm/xcm-builder/src/filter_asset_location.rs @@ -25,6 +25,7 @@ use xcm_executor::traits::FilterAssetLocation; pub struct NativeAsset; impl FilterAssetLocation for NativeAsset { fn filter_asset_location(asset: &MultiAsset, origin: &MultiLocation) -> bool { + log::trace!(target: "xcm::filter_asset_location", "NativeAsset asset: {:?}, origin: {:?}", asset, origin); matches!(asset.id, Concrete(ref id) if id == origin) } } @@ -33,6 +34,7 @@ impl FilterAssetLocation for NativeAsset { pub struct Case(PhantomData); impl> FilterAssetLocation for Case { fn filter_asset_location(asset: &MultiAsset, origin: &MultiLocation) -> bool { + log::trace!(target: "xcm::filter_asset_location", "Case asset: {:?}, origin: {:?}", asset, origin); let (a, o) = T::get(); a.contains(asset) && &o == origin } diff --git a/xcm/xcm-builder/src/fungibles_adapter.rs b/xcm/xcm-builder/src/fungibles_adapter.rs index d63703368a8c..082e3b6955df 100644 --- a/xcm/xcm-builder/src/fungibles_adapter.rs +++ b/xcm/xcm-builder/src/fungibles_adapter.rs @@ -123,6 +123,11 @@ impl< from: &MultiLocation, to: &MultiLocation, ) -> result::Result { + log::trace!( + target: "xcm::fungibles_adapter", + "transfer_asset what: {:?}, from: {:?}, to: {:?}", + what, from, to + ); // Check we handle this asset. let (asset_id, amount) = Matcher::matches_fungibles(what)?; let source = AccountIdConverter::convert_ref(from) @@ -161,6 +166,11 @@ impl< > { fn can_check_in(_origin: &MultiLocation, what: &MultiAsset) -> Result { + log::trace!( + target: "xcm::fungibles_adapter", + "can_check_in origin: {:?}, what: {:?}", + _origin, what + ); // Check we handle this asset. let (asset_id, amount) = Matcher::matches_fungibles(what)?; if CheckAsset::contains(&asset_id) { @@ -174,6 +184,11 @@ impl< } fn check_in(_origin: &MultiLocation, what: &MultiAsset) { + log::trace!( + target: "xcm::fungibles_adapter", + "check_in origin: {:?}, what: {:?}", + _origin, what + ); if let Ok((asset_id, amount)) = Matcher::matches_fungibles(what) { if CheckAsset::contains(&asset_id) { let checking_account = CheckingAccount::get(); @@ -187,6 +202,11 @@ impl< } fn check_out(_dest: &MultiLocation, what: &MultiAsset) { + log::trace!( + target: "xcm::fungibles_adapter", + "check_out dest: {:?}, what: {:?}", + _dest, what + ); if let Ok((asset_id, amount)) = Matcher::matches_fungibles(what) { if CheckAsset::contains(&asset_id) { let checking_account = CheckingAccount::get(); @@ -197,6 +217,11 @@ impl< } fn deposit_asset(what: &MultiAsset, who: &MultiLocation) -> Result { + log::trace!( + target: "xcm::fungibles_adapter", + "deposit_asset what: {:?}, who: {:?}", + what, who, + ); // Check we handle this asset. let (asset_id, amount) = Matcher::matches_fungibles(what)?; let who = AccountIdConverter::convert_ref(who) @@ -209,6 +234,11 @@ impl< what: &MultiAsset, who: &MultiLocation, ) -> result::Result { + log::trace!( + target: "xcm::fungibles_adapter", + "withdraw_asset what: {:?}, who: {:?}", + what, who, + ); // Check we handle this asset. let (asset_id, amount) = Matcher::matches_fungibles(what)?; let who = AccountIdConverter::convert_ref(who) diff --git a/xcm/xcm-builder/src/origin_conversion.rs b/xcm/xcm-builder/src/origin_conversion.rs index 9f33347e378d..b42c8fcff9ef 100644 --- a/xcm/xcm-builder/src/origin_conversion.rs +++ b/xcm/xcm-builder/src/origin_conversion.rs @@ -37,6 +37,11 @@ where kind: OriginKind, ) -> Result { let origin = origin.into(); + log::trace!( + target: "xcm::origin_conversion", + "SovereignSignedViaLocation origin: {:?}, kind: {:?}", + origin, kind, + ); if let OriginKind::SovereignAccount = kind { let location = LocationConverter::convert(origin)?; Ok(Origin::signed(location).into()) @@ -53,6 +58,7 @@ impl ConvertOrigin for ParentAsSuperuser { kind: OriginKind, ) -> Result { let origin = origin.into(); + log::trace!(target: "xcm::origin_conversion", "ParentAsSuperuser origin: {:?}, kind: {:?}", origin, kind); if kind == OriginKind::Superuser && origin.contains_parents_only(1) { Ok(Origin::root()) } else { @@ -69,7 +75,9 @@ impl, Origin: OriginTrait> ConvertOrigin origin: impl Into, kind: OriginKind, ) -> Result { - match (kind, origin.into()) { + let origin = origin.into(); + log::trace!(target: "xcm::origin_conversion", "ChildSystemParachainAsSuperuser origin: {:?}, kind: {:?}", origin, kind); + match (kind, origin) { ( OriginKind::Superuser, MultiLocation { parents: 0, interior: X1(Junction::Parachain(id)) }, @@ -87,7 +95,13 @@ impl, Origin: OriginTrait> ConvertOrigin origin: impl Into, kind: OriginKind, ) -> Result { - match (kind, origin.into()) { + let origin = origin.into(); + log::trace!( + target: "xcm::origin_conversion", + "SiblingSystemParachainAsSuperuser origin: {:?}, kind: {:?}", + origin, kind, + ); + match (kind, origin) { ( OriginKind::Superuser, MultiLocation { parents: 1, interior: X1(Junction::Parachain(id)) }, @@ -105,7 +119,9 @@ impl, Origin: From> ConvertOrigin, kind: OriginKind, ) -> Result { - match (kind, origin.into()) { + let origin = origin.into(); + log::trace!(target: "xcm::origin_conversion", "ChildParachainAsNative origin: {:?}, kind: {:?}", origin, kind); + match (kind, origin) { ( OriginKind::Native, MultiLocation { parents: 0, interior: X1(Junction::Parachain(id)) }, @@ -125,7 +141,13 @@ impl, Origin: From> ConvertOrigin, kind: OriginKind, ) -> Result { - match (kind, origin.into()) { + let origin = origin.into(); + log::trace!( + target: "xcm::origin_conversion", + "SiblingParachainAsNative origin: {:?}, kind: {:?}", + origin, kind, + ); + match (kind, origin) { ( OriginKind::Native, MultiLocation { parents: 1, interior: X1(Junction::Parachain(id)) }, @@ -145,6 +167,7 @@ impl, Origin> ConvertOrigin kind: OriginKind, ) -> Result { let origin = origin.into(); + log::trace!(target: "xcm::origin_conversion", "RelayChainAsNative origin: {:?}, kind: {:?}", origin, kind); if kind == OriginKind::Native && origin.contains_parents_only(1) { Ok(RelayOrigin::get()) } else { @@ -163,7 +186,13 @@ where origin: impl Into, kind: OriginKind, ) -> Result { - match (kind, origin.into()) { + let origin = origin.into(); + log::trace!( + target: "xcm::origin_conversion", + "SignedAccountId32AsNative origin: {:?}, kind: {:?}", + origin, kind, + ); + match (kind, origin) { ( OriginKind::Native, MultiLocation { parents: 0, interior: X1(Junction::AccountId32 { id, network }) }, @@ -184,7 +213,13 @@ where origin: impl Into, kind: OriginKind, ) -> Result { - match (kind, origin.into()) { + let origin = origin.into(); + log::trace!( + target: "xcm::origin_conversion", + "SignedAccountKey20AsNative origin: {:?}, kind: {:?}", + origin, kind, + ); + match (kind, origin) { ( OriginKind::Native, MultiLocation { parents: 0, interior: X1(Junction::AccountKey20 { key, network }) }, diff --git a/xcm/xcm-builder/src/weight.rs b/xcm/xcm-builder/src/weight.rs index 92d26ebef157..755b6acf2844 100644 --- a/xcm/xcm-builder/src/weight.rs +++ b/xcm/xcm-builder/src/weight.rs @@ -32,6 +32,7 @@ impl, C: Decode + GetDispatchInfo, M: Get> WeightBounds for FixedWeightBounds { fn weight(message: &mut Xcm) -> Result { + log::trace!(target: "xcm::weight", "FixedWeightBounds message: {:?}", message); let mut instructions_left = M::get(); Self::weight_with_limit(message, &mut instructions_left) } @@ -73,6 +74,7 @@ where Instruction: xcm::GetWeight, { fn weight(message: &mut Xcm) -> Result { + log::trace!(target: "xcm::weight", "WeightInfoBounds message: {:?}", message); let mut instructions_left = M::get(); Self::weight_with_limit(message, &mut instructions_left) } @@ -144,6 +146,11 @@ impl, R: TakeRevenue> WeightTrader } fn buy_weight(&mut self, weight: Weight, payment: Assets) -> Result { + log::trace!( + target: "xcm::weight", + "FixedRateOfConcreteFungible::buy_weight weight: {:?}, payment: {:?}", + weight, payment, + ); let (id, units_per_second) = T::get(); let amount = units_per_second * (weight as u128) / (WEIGHT_PER_SECOND as u128); let unused = @@ -154,6 +161,7 @@ impl, R: TakeRevenue> WeightTrader } fn refund_weight(&mut self, weight: Weight) -> Option { + log::trace!(target: "xcm::weight", "FixedRateOfConcreteFungible::refund_weight weight: {:?}", weight); let (id, units_per_second) = T::get(); let weight = weight.min(self.0); let amount = units_per_second * (weight as u128) / (WEIGHT_PER_SECOND as u128); @@ -190,6 +198,11 @@ impl, R: TakeRevenue> WeightTrader for FixedRateOfFungib } fn buy_weight(&mut self, weight: Weight, payment: Assets) -> Result { + log::trace!( + target: "xcm::weight", + "FixedRateOfFungible::buy_weight weight: {:?}, payment: {:?}", + weight, payment, + ); let (id, units_per_second) = T::get(); let amount = units_per_second * (weight as u128) / (WEIGHT_PER_SECOND as u128); if amount == 0 { @@ -203,6 +216,7 @@ impl, R: TakeRevenue> WeightTrader for FixedRateOfFungib } fn refund_weight(&mut self, weight: Weight) -> Option { + log::trace!(target: "xcm::weight", "FixedRateOfFungible::refund_weight weight: {:?}", weight); let (id, units_per_second) = T::get(); let weight = weight.min(self.0); let amount = units_per_second * (weight as u128) / (WEIGHT_PER_SECOND as u128); @@ -250,6 +264,7 @@ impl< } fn buy_weight(&mut self, weight: Weight, payment: Assets) -> Result { + log::trace!(target: "xcm::weight", "UsingComponents::buy_weight weight: {:?}, payment: {:?}", weight, payment); let amount = WeightToFee::calc(&weight); let u128_amount: u128 = amount.try_into().map_err(|_| XcmError::Overflow)?; let required = (Concrete(AssetId::get()), u128_amount).into(); @@ -260,6 +275,7 @@ impl< } fn refund_weight(&mut self, weight: Weight) -> Option { + log::trace!(target: "xcm::weight", "UsingComponents::refund_weight weight: {:?}", weight); let weight = weight.min(self.0); let amount = WeightToFee::calc(&weight); self.0 -= weight; diff --git a/xcm/xcm-executor/src/lib.rs b/xcm/xcm-executor/src/lib.rs index f252b2e7e3a3..bc6bb3246cd0 100644 --- a/xcm/xcm-executor/src/lib.rs +++ b/xcm/xcm-executor/src/lib.rs @@ -83,15 +83,44 @@ impl ExecuteXcm for XcmExecutor { ); let xcm_weight = match Config::Weigher::weight(&mut message) { Ok(x) => x, - Err(()) => return Outcome::Error(XcmError::WeightNotComputable), + Err(()) => { + log::debug!( + target: "xcm::execute_xcm_in_credit", + "Weight not computable! (origin: {:?}, message: {:?}, weight_limit: {:?}, weight_credit: {:?})", + origin, + message, + weight_limit, + weight_credit, + ); + return Outcome::Error(XcmError::WeightNotComputable) + }, }; if xcm_weight > weight_limit { + log::debug!( + target: "xcm::execute_xcm_in_credit", + "Weight limit reached! weight > weight_limit: {:?} > {:?}. (origin: {:?}, message: {:?}, weight_limit: {:?}, weight_credit: {:?})", + xcm_weight, + weight_limit, + origin, + message, + weight_limit, + weight_credit, + ); return Outcome::Error(XcmError::WeightLimitReached(xcm_weight)) } - if let Err(_) = + if let Err(e) = Config::Barrier::should_execute(&origin, &mut message, xcm_weight, &mut weight_credit) { + log::debug!( + target: "xcm::execute_xcm_in_credit", + "Barrier blocked execution! Error: {:?}. (origin: {:?}, message: {:?}, weight_limit: {:?}, weight_credit: {:?})", + e, + origin, + message, + weight_limit, + weight_credit, + ); return Outcome::Error(XcmError::Barrier) } @@ -116,6 +145,7 @@ impl ExecuteXcm for XcmExecutor { let mut weight_used = xcm_weight.saturating_sub(vm.total_surplus); if !vm.holding.is_empty() { + log::trace!(target: "xcm::execute_xcm_in_credit", "Trapping assets in holding register: {:?} (original_origin: {:?})", vm.holding, vm.original_origin); let trap_weight = Config::AssetTrap::drop_assets(&vm.original_origin, vm.holding); weight_used.saturating_accrue(trap_weight); }; @@ -124,7 +154,10 @@ impl ExecuteXcm for XcmExecutor { None => Outcome::Complete(weight_used), // TODO: #2841 #REALWEIGHT We should deduct the cost of any instructions following // the error which didn't end up being executed. - Some((_, e)) => Outcome::Incomplete(weight_used, e), + Some((_i, e)) => { + log::debug!(target: "xcm::execute_xcm_in_credit", "Execution errored at {:?}: {:?} (original_origin: {:?})", _i, e, vm.original_origin); + Outcome::Incomplete(weight_used, e) + }, } } }