Unverified Commit 55872676 authored by Alexander Popiak's avatar Alexander Popiak Committed by GitHub
Browse files

Add more XCM tracing (#4211)

* add more logging to currency adapter

* add more logging to barriers

* reformat currency adapter trace logs

* add tracing logs for filter asset location

* add tracing logs to fungibles adapter

* add tracing to origin conversion

* add tracing logs for xcm weight trading

* fix compile errors

* add more tracing logs to xcm executor

* formatting and compile fixes

* add some tracing logs to pallet-xcm

* adjust log target in executor to debug

* fix closure args
parent 2d583c1e
Pipeline #165515 passed with stages
in 38 minutes and 52 seconds
......@@ -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::<T>::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::<T>::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)))
}
}
......
......@@ -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<T: Contains<MultiLocation>> 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<T: Contains<MultiLocation>> ShouldExecute for AllowUnpaidExecutionFrom<T> {
_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<ResponseHandler: OnResponse> ShouldExecute for AllowKnownQueryResponses<Res
_max_weight: Weight,
_weight_credit: &mut Weight,
) -> 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<T: Contains<MultiLocation>> ShouldExecute for AllowSubscriptionsFrom<T> {
_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(()),
......
......@@ -97,6 +97,7 @@ impl<
for CurrencyAdapter<Currency, Matcher, AccountIdConverter, AccountId, CheckedAccount>
{
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<Assets, XcmError> {
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();
......
......@@ -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<T>(PhantomData<T>);
impl<T: Get<(MultiAssetFilter, MultiLocation)>> FilterAssetLocation for Case<T> {
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
}
......
......@@ -123,6 +123,11 @@ impl<
from: &MultiLocation,
to: &MultiLocation,
) -> result::Result<xcm_executor::Assets, XcmError> {
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<xcm_executor::Assets, XcmError> {
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)
......
......@@ -37,6 +37,11 @@ where
kind: OriginKind,
) -> Result<Origin, MultiLocation> {
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<Origin: OriginTrait> ConvertOrigin<Origin> for ParentAsSuperuser<Origin> {
kind: OriginKind,
) -> Result<Origin, MultiLocation> {
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<ParaId: IsSystem + From<u32>, Origin: OriginTrait> ConvertOrigin<Origin>
origin: impl Into<MultiLocation>,
kind: OriginKind,
) -> Result<Origin, MultiLocation> {
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<ParaId: IsSystem + From<u32>, Origin: OriginTrait> ConvertOrigin<Origin>
origin: impl Into<MultiLocation>,
kind: OriginKind,
) -> Result<Origin, MultiLocation> {
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<ParachainOrigin: From<u32>, Origin: From<ParachainOrigin>> ConvertOrigin<Or
origin: impl Into<MultiLocation>,
kind: OriginKind,
) -> Result<Origin, MultiLocation> {
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<ParachainOrigin: From<u32>, Origin: From<ParachainOrigin>> ConvertOrigin<Or
origin: impl Into<MultiLocation>,
kind: OriginKind,
) -> Result<Origin, MultiLocation> {
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<RelayOrigin: Get<Origin>, Origin> ConvertOrigin<Origin>
kind: OriginKind,
) -> Result<Origin, MultiLocation> {
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<MultiLocation>,
kind: OriginKind,
) -> Result<Origin, MultiLocation> {
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<MultiLocation>,
kind: OriginKind,
) -> Result<Origin, MultiLocation> {
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 }) },
......
......@@ -32,6 +32,7 @@ impl<T: Get<Weight>, C: Decode + GetDispatchInfo, M: Get<u32>> WeightBounds<C>
for FixedWeightBounds<T, C, M>
{
fn weight(message: &mut Xcm<C>) -> Result<Weight, ()> {
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<C>: xcm::GetWeight<W>,
{
fn weight(message: &mut Xcm<C>) -> Result<Weight, ()> {
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<T: Get<(MultiLocation, u128)>, R: TakeRevenue> WeightTrader
}
fn buy_weight(&mut self, weight: Weight, payment: Assets) -> Result<Assets, XcmError> {
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<T: Get<(MultiLocation, u128)>, R: TakeRevenue> WeightTrader
}
fn refund_weight(&mut self, weight: Weight) -> Option<MultiAsset> {
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<T: Get<(AssetId, u128)>, R: TakeRevenue> WeightTrader for FixedRateOfFungib
}
fn buy_weight(&mut self, weight: Weight, payment: Assets) -> Result<Assets, XcmError> {
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<T: Get<(AssetId, u128)>, R: TakeRevenue> WeightTrader for FixedRateOfFungib
}
fn refund_weight(&mut self, weight: Weight) -> Option<MultiAsset> {
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<Assets, XcmError> {
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<MultiAsset> {
log::trace!(target: "xcm::weight", "UsingComponents::refund_weight weight: {:?}", weight);
let weight = weight.min(self.0);
let amount = WeightToFee::calc(&weight);
self.0 -= weight;
......
......@@ -83,15 +83,44 @@ impl<Config: config::Config> ExecuteXcm<Config::Call> for XcmExecutor<Config> {
);
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<Config: config::Config> ExecuteXcm<Config::Call> for XcmExecutor<Config> {
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<Config: config::Config> ExecuteXcm<Config::Call> for XcmExecutor<Config> {
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)
},
}
}
}
......
Supports Markdown
0% or .
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment