From 478fc3fcf19d2e863f025293c7b294d88f8f05bd Mon Sep 17 00:00:00 2001 From: Alexander Popiak Date: Wed, 23 Jun 2021 15:23:52 +0200 Subject: [PATCH 1/8] add missing bridges logging target --- bridges/modules/dispatch/src/lib.rs | 1 + 1 file changed, 1 insertion(+) diff --git a/bridges/modules/dispatch/src/lib.rs b/bridges/modules/dispatch/src/lib.rs index 5ac2825c8c11..9d073ee19ca8 100644 --- a/bridges/modules/dispatch/src/lib.rs +++ b/bridges/modules/dispatch/src/lib.rs @@ -142,6 +142,7 @@ impl, I: Instance> MessageDispatch for Pallet { let expected_version = ::Version::get().spec_version; if message.spec_version != expected_version { log::trace!( + target: "runtime::bridge-dispatch", "Message {:?}/{:?}: spec_version mismatch. Expected {:?}, got {:?}", bridge, id, From df57d77e757c91ab6e539468e6228a7ebf6c3250 Mon Sep 17 00:00:00 2001 From: Alexander Popiak Date: Wed, 23 Jun 2021 15:24:38 +0200 Subject: [PATCH 2/8] trace send_xcm --- xcm/pallet-xcm/Cargo.toml | 1 + xcm/pallet-xcm/src/lib.rs | 1 + 2 files changed, 2 insertions(+) diff --git a/xcm/pallet-xcm/Cargo.toml b/xcm/pallet-xcm/Cargo.toml index 75d737ed69cd..c3385626b2d1 100644 --- a/xcm/pallet-xcm/Cargo.toml +++ b/xcm/pallet-xcm/Cargo.toml @@ -7,6 +7,7 @@ version = "0.1.0" [dependencies] codec = { package = "parity-scale-codec", version = "2.0.0", default-features = false, features = ["derive"] } serde = { version = "1.0.101", optional = true, features = ["derive"] } +log = { version = "0.4.14", default-features = false } sp-std = { git = "https://github.com/paritytech/substrate", default-features = false, branch = "master" } sp-runtime = { git = "https://github.com/paritytech/substrate", default-features = false, branch = "master" } diff --git a/xcm/pallet-xcm/src/lib.rs b/xcm/pallet-xcm/src/lib.rs index d89356cc02b5..a99d630fefe3 100644 --- a/xcm/pallet-xcm/src/lib.rs +++ b/xcm/pallet-xcm/src/lib.rs @@ -254,6 +254,7 @@ pub mod pallet { MultiLocation::Null => message, who => Xcm::<()>::RelayedFrom { who, message: Box::new(message) }, }; + log::trace!(target: "xcm::send_xcm", "dest: {:?}, message: {:?}", &dest, &message); T::XcmRouter::send_xcm(dest, message) } From 6a7ee057bc023b5c20b2e7b5fe1d7482c09293cb Mon Sep 17 00:00:00 2001 From: Alexander Popiak Date: Wed, 23 Jun 2021 15:25:27 +0200 Subject: [PATCH 3/8] trace execute_xcm --- xcm/Cargo.toml | 1 + xcm/src/v0/traits.rs | 5 +++++ 2 files changed, 6 insertions(+) diff --git a/xcm/Cargo.toml b/xcm/Cargo.toml index fb176e354f33..7ceec635f885 100644 --- a/xcm/Cargo.toml +++ b/xcm/Cargo.toml @@ -9,6 +9,7 @@ edition = "2018" impl-trait-for-tuples = "0.2.0" parity-scale-codec = { version = "2.0.0", default-features = false, features = [ "derive" ] } derivative = {version = "2.2.0", default-features = false, features = [ "use_core" ] } +log = { version = "0.4.14", default-features = false } [features] default = ["std"] diff --git a/xcm/src/v0/traits.rs b/xcm/src/v0/traits.rs index 8664484c87ce..7305f57ff519 100644 --- a/xcm/src/v0/traits.rs +++ b/xcm/src/v0/traits.rs @@ -134,6 +134,11 @@ pub trait ExecuteXcm { /// a basic hard-limit and the implementation may place further restrictions or requirements on weight and /// other aspects. fn execute_xcm(origin: MultiLocation, message: Xcm, weight_limit: Weight) -> Outcome { + log::debug!( + target: "xcm::execute_xcm", + "origin: {:?}, message: {:?}, weight_limit: {:?}", + &origin, &message, weight_limit, + ); Self::execute_xcm_in_credit(origin, message, weight_limit, 0) } From 75175414bc945a66ef84ff7ceada18302765af31 Mon Sep 17 00:00:00 2001 From: Alexander Popiak Date: Wed, 23 Jun 2021 15:26:13 +0200 Subject: [PATCH 4/8] trace calls in xcm-executor --- xcm/xcm-executor/src/lib.rs | 18 +++++++++++++++++- 1 file changed, 17 insertions(+), 1 deletion(-) diff --git a/xcm/xcm-executor/src/lib.rs b/xcm/xcm-executor/src/lib.rs index e7c90f1edbd9..d007e95f7653 100644 --- a/xcm/xcm-executor/src/lib.rs +++ b/xcm/xcm-executor/src/lib.rs @@ -47,6 +47,11 @@ impl ExecuteXcm for XcmExecutor { weight_limit: Weight, mut weight_credit: Weight, ) -> Outcome { + log::trace!( + target: "xcm::execute_xcm_in_credit", + "origin: {:?}, message: {:?}, weight_limit: {:?}, weight_credit: {:?}", + &origin, &message, weight_limit, weight_credit, + ); // TODO: #2841 #HARDENXCM We should identify recursive bombs here and bail. let mut message = Xcm::::from(message); let shallow_weight = match Config::Weigher::shallow(&mut message) { @@ -67,6 +72,7 @@ impl ExecuteXcm for XcmExecutor { let mut trader = Config::Trader::new(); let result = Self::do_execute_xcm(origin, true, message, &mut weight_credit, Some(shallow_weight), &mut trader); drop(trader); + log::trace!(target: "xcm::execute_xcm", "result: {:?}", &result); match result { Ok(surplus) => Outcome::Complete(maximum_weight.saturating_sub(surplus)), // TODO: #2841 #REALWEIGHT We can do better than returning `maximum_weight` here, and we should otherwise @@ -94,6 +100,11 @@ impl XcmExecutor { maybe_shallow_weight: Option, trader: &mut Config::Trader, ) -> Result { + log::trace!( + target: "xcm::do_execute_xcm", + "origin: {:?}, top_level: {:?}, message: {:?}, weight_credit: {:?}, maybe_shallow_weight: {:?}", + &origin, top_level, &message, weight_credit, maybe_shallow_weight, + ); // This is the weight of everything that cannot be paid for. This basically means all computation // except any XCM which is behind an Order::BuyExecution. let shallow_weight = maybe_shallow_weight @@ -165,7 +176,7 @@ impl XcmExecutor { } Some((Assets::from(assets), effects)) } - (origin, Xcm::Transact { origin_type, require_weight_at_most, mut call }) => { + (origin, Xcm::Transact { origin_type, require_weight_at_most, mut call }) => { // We assume that the Relay-chain is allowed to use transact on this parachain. // TODO: #2841 #TRANSACTFILTER allow the trait to issue filters for the relay-chain @@ -225,6 +236,11 @@ impl XcmExecutor { effect: Order, trader: &mut Config::Trader, ) -> Result { + log::trace!( + target: "xcm::execute_effects", + "origin: {:?}, holding: {:?}, effect: {:?}", + origin, holding, &effect, + ); let mut total_surplus = 0; match effect { Order::DepositAsset { assets, dest } => { From 297f9ac24a94bcb5527a1e988b71a75b90dc5b50 Mon Sep 17 00:00:00 2001 From: Alexander Popiak Date: Wed, 23 Jun 2021 15:26:53 +0200 Subject: [PATCH 5/8] trace tuple implementations of xcm traits --- xcm/xcm-executor/src/traits/conversion.rs | 5 ++++ .../src/traits/filter_asset_location.rs | 5 ++++ .../src/traits/matches_fungible.rs | 1 + .../src/traits/matches_fungibles.rs | 1 + xcm/xcm-executor/src/traits/should_execute.rs | 5 ++++ xcm/xcm-executor/src/traits/transact_asset.rs | 25 +++++++++++++++++++ 6 files changed, 42 insertions(+) diff --git a/xcm/xcm-executor/src/traits/conversion.rs b/xcm/xcm-executor/src/traits/conversion.rs index da39c3cecd39..436e80760306 100644 --- a/xcm/xcm-executor/src/traits/conversion.rs +++ b/xcm/xcm-executor/src/traits/conversion.rs @@ -173,6 +173,11 @@ impl ConvertOrigin for Tuple { r => return r }; )* ); + log::trace!( + target: "xcm::convert_origin", + "could not convert: origin: {:?}, kind: {:?}", + &origin, &kind + ); Err(origin) } } diff --git a/xcm/xcm-executor/src/traits/filter_asset_location.rs b/xcm/xcm-executor/src/traits/filter_asset_location.rs index c68fcd6ff79a..508fd21243c3 100644 --- a/xcm/xcm-executor/src/traits/filter_asset_location.rs +++ b/xcm/xcm-executor/src/traits/filter_asset_location.rs @@ -30,6 +30,11 @@ impl FilterAssetLocation for Tuple { for_tuples!( #( if Tuple::filter_asset_location(what, origin) { return true } )* ); + log::trace!( + target: "xcm::filter_asset_location", + "got filtered: what: {:?}, origin: {:?}", + &what, &origin, + ); false } } diff --git a/xcm/xcm-executor/src/traits/matches_fungible.rs b/xcm/xcm-executor/src/traits/matches_fungible.rs index 70383e93966d..6634d16d0243 100644 --- a/xcm/xcm-executor/src/traits/matches_fungible.rs +++ b/xcm/xcm-executor/src/traits/matches_fungible.rs @@ -26,6 +26,7 @@ impl MatchesFungible for Tuple { for_tuples!( #( match Tuple::matches_fungible(a) { o @ Some(_) => return o, _ => () } )* ); + log::trace!(target: "xcm::matches_fungible", "did not match fungible asset: {:?}", &a); None } } diff --git a/xcm/xcm-executor/src/traits/matches_fungibles.rs b/xcm/xcm-executor/src/traits/matches_fungibles.rs index 75de0ae8be44..baa4d55a4b12 100644 --- a/xcm/xcm-executor/src/traits/matches_fungibles.rs +++ b/xcm/xcm-executor/src/traits/matches_fungibles.rs @@ -54,6 +54,7 @@ impl< for_tuples!( #( match Tuple::matches_fungibles(a) { o @ Ok(_) => return o, _ => () } )* ); + log::trace!(target: "xcm::matches_fungibles", "did not match fungibles asset: {:?}", &a); Err(Error::AssetNotFound) } } diff --git a/xcm/xcm-executor/src/traits/should_execute.rs b/xcm/xcm-executor/src/traits/should_execute.rs index 15f66d5105ee..ce0884a29e6e 100644 --- a/xcm/xcm-executor/src/traits/should_execute.rs +++ b/xcm/xcm-executor/src/traits/should_execute.rs @@ -58,6 +58,11 @@ impl ShouldExecute for Tuple { _ => (), } )* ); + log::trace!( + target: "xcm::should_execute", + "did not pass barrier: origin: {:?}, top_level: {:?}, message: {:?}, shallow_weight: {:?}, weight_credit: {:?}", + &origin, top_level, &message, shallow_weight, weight_credit + ); Err(()) } } diff --git a/xcm/xcm-executor/src/traits/transact_asset.rs b/xcm/xcm-executor/src/traits/transact_asset.rs index 795bb0f49bd4..5928e75850b7 100644 --- a/xcm/xcm-executor/src/traits/transact_asset.rs +++ b/xcm/xcm-executor/src/traits/transact_asset.rs @@ -107,34 +107,59 @@ impl TransactAsset for Tuple { r => return r, } )* ); + log::trace!( + target: "xcm::TransactAsset::can_check_in", + "asset not found: what: {:?}, origin: {:?}", + &what, &origin, + ); Err(XcmError::AssetNotFound) } + fn check_in(origin: &MultiLocation, what: &MultiAsset) { for_tuples!( #( Tuple::check_in(origin, what); )* ); } + fn check_out(dest: &MultiLocation, what: &MultiAsset) { for_tuples!( #( Tuple::check_out(dest, what); )* ); } + fn deposit_asset(what: &MultiAsset, who: &MultiLocation) -> XcmResult { for_tuples!( #( match Tuple::deposit_asset(what, who) { o @ Ok(_) => return o, _ => () } )* ); + log::trace!( + target: "xcm::TransactAsset::deposit_asset", + "did not deposit asset: what: {:?}, who: {:?}", + &what, &who, + ); Err(XcmError::Unimplemented) } + fn withdraw_asset(what: &MultiAsset, who: &MultiLocation) -> Result { for_tuples!( #( match Tuple::withdraw_asset(what, who) { o @ Ok(_) => return o, _ => () } )* ); + log::trace!( + target: "xcm::TransactAsset::withdraw_asset", + "did not withdraw asset: what: {:?}, who: {:?}", + &what, &who, + ); Err(XcmError::Unimplemented) } + fn transfer_asset(what: &MultiAsset, from: &MultiLocation, to: &MultiLocation) -> Result { for_tuples!( #( match Tuple::transfer_asset(what, from, to) { o @ Ok(_) => return o, _ => () } )* ); + log::trace!( + target: "xcm::TransactAsset::transfer_asset", + "did not transfer asset: what: {:?}, from: {:?}, to: {:?}", + &what, &from, &to, + ); Err(XcmError::Unimplemented) } } From 02270df79b2db146a1aade3ff8c415c8ea349037 Mon Sep 17 00:00:00 2001 From: Alexander Popiak Date: Wed, 23 Jun 2021 15:27:02 +0200 Subject: [PATCH 6/8] update cargo.lock --- Cargo.lock | 2 ++ 1 file changed, 2 insertions(+) diff --git a/Cargo.lock b/Cargo.lock index d49b76de1e69..d8452627a640 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -5259,6 +5259,7 @@ version = "0.1.0" dependencies = [ "frame-support", "frame-system", + "log", "parity-scale-codec", "serde", "sp-runtime", @@ -11862,6 +11863,7 @@ version = "0.9.5" dependencies = [ "derivative", "impl-trait-for-tuples", + "log", "parity-scale-codec", ] From 3b8a4109b7692f3626819a1e2543b11c2d6d9c1f Mon Sep 17 00:00:00 2001 From: Alexander Popiak Date: Mon, 5 Jul 2021 16:23:32 +0200 Subject: [PATCH 7/8] remove bridge log target MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Co-authored-by: Bastian Köcher --- bridges/modules/dispatch/src/lib.rs | 1 - 1 file changed, 1 deletion(-) diff --git a/bridges/modules/dispatch/src/lib.rs b/bridges/modules/dispatch/src/lib.rs index 9d073ee19ca8..5ac2825c8c11 100644 --- a/bridges/modules/dispatch/src/lib.rs +++ b/bridges/modules/dispatch/src/lib.rs @@ -142,7 +142,6 @@ impl, I: Instance> MessageDispatch for Pallet { let expected_version = ::Version::get().spec_version; if message.spec_version != expected_version { log::trace!( - target: "runtime::bridge-dispatch", "Message {:?}/{:?}: spec_version mismatch. Expected {:?}, got {:?}", bridge, id, From 0fd385c0b56f1d195554ba0de374667630ee123a Mon Sep 17 00:00:00 2001 From: Alexander Popiak Date: Mon, 5 Jul 2021 16:25:20 +0200 Subject: [PATCH 8/8] log argument formatting MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Co-authored-by: Bastian Köcher --- xcm/src/v0/traits.rs | 4 +++- xcm/xcm-executor/src/lib.rs | 15 ++++++++++++--- xcm/xcm-executor/src/traits/conversion.rs | 3 ++- .../src/traits/filter_asset_location.rs | 3 ++- xcm/xcm-executor/src/traits/should_execute.rs | 6 +++++- xcm/xcm-executor/src/traits/transact_asset.rs | 13 +++++++++---- 6 files changed, 33 insertions(+), 11 deletions(-) diff --git a/xcm/src/v0/traits.rs b/xcm/src/v0/traits.rs index 7305f57ff519..cbaaa3604b75 100644 --- a/xcm/src/v0/traits.rs +++ b/xcm/src/v0/traits.rs @@ -137,7 +137,9 @@ pub trait ExecuteXcm { log::debug!( target: "xcm::execute_xcm", "origin: {:?}, message: {:?}, weight_limit: {:?}", - &origin, &message, weight_limit, + origin, + message, + weight_limit, ); Self::execute_xcm_in_credit(origin, message, weight_limit, 0) } diff --git a/xcm/xcm-executor/src/lib.rs b/xcm/xcm-executor/src/lib.rs index d007e95f7653..8f8a5c9ee617 100644 --- a/xcm/xcm-executor/src/lib.rs +++ b/xcm/xcm-executor/src/lib.rs @@ -50,7 +50,10 @@ impl ExecuteXcm for XcmExecutor { log::trace!( target: "xcm::execute_xcm_in_credit", "origin: {:?}, message: {:?}, weight_limit: {:?}, weight_credit: {:?}", - &origin, &message, weight_limit, weight_credit, + origin, + message, + weight_limit, + weight_credit, ); // TODO: #2841 #HARDENXCM We should identify recursive bombs here and bail. let mut message = Xcm::::from(message); @@ -103,7 +106,11 @@ impl XcmExecutor { log::trace!( target: "xcm::do_execute_xcm", "origin: {:?}, top_level: {:?}, message: {:?}, weight_credit: {:?}, maybe_shallow_weight: {:?}", - &origin, top_level, &message, weight_credit, maybe_shallow_weight, + origin, + top_level, + message, + weight_credit, + maybe_shallow_weight, ); // This is the weight of everything that cannot be paid for. This basically means all computation // except any XCM which is behind an Order::BuyExecution. @@ -239,7 +246,9 @@ impl XcmExecutor { log::trace!( target: "xcm::execute_effects", "origin: {:?}, holding: {:?}, effect: {:?}", - origin, holding, &effect, + origin, + holding, + effect, ); let mut total_surplus = 0; match effect { diff --git a/xcm/xcm-executor/src/traits/conversion.rs b/xcm/xcm-executor/src/traits/conversion.rs index 436e80760306..971b4b9e0e98 100644 --- a/xcm/xcm-executor/src/traits/conversion.rs +++ b/xcm/xcm-executor/src/traits/conversion.rs @@ -176,7 +176,8 @@ impl ConvertOrigin for Tuple { log::trace!( target: "xcm::convert_origin", "could not convert: origin: {:?}, kind: {:?}", - &origin, &kind + origin, + kind, ); Err(origin) } diff --git a/xcm/xcm-executor/src/traits/filter_asset_location.rs b/xcm/xcm-executor/src/traits/filter_asset_location.rs index 508fd21243c3..8b1a7bd1d1dc 100644 --- a/xcm/xcm-executor/src/traits/filter_asset_location.rs +++ b/xcm/xcm-executor/src/traits/filter_asset_location.rs @@ -33,7 +33,8 @@ impl FilterAssetLocation for Tuple { log::trace!( target: "xcm::filter_asset_location", "got filtered: what: {:?}, origin: {:?}", - &what, &origin, + what, + origin, ); false } diff --git a/xcm/xcm-executor/src/traits/should_execute.rs b/xcm/xcm-executor/src/traits/should_execute.rs index ce0884a29e6e..19c8ef4a9c10 100644 --- a/xcm/xcm-executor/src/traits/should_execute.rs +++ b/xcm/xcm-executor/src/traits/should_execute.rs @@ -61,7 +61,11 @@ impl ShouldExecute for Tuple { log::trace!( target: "xcm::should_execute", "did not pass barrier: origin: {:?}, top_level: {:?}, message: {:?}, shallow_weight: {:?}, weight_credit: {:?}", - &origin, top_level, &message, shallow_weight, weight_credit + origin, + top_level, + message, + shallow_weight, + weight_credit, ); Err(()) } diff --git a/xcm/xcm-executor/src/traits/transact_asset.rs b/xcm/xcm-executor/src/traits/transact_asset.rs index 5928e75850b7..8c04bc57ae21 100644 --- a/xcm/xcm-executor/src/traits/transact_asset.rs +++ b/xcm/xcm-executor/src/traits/transact_asset.rs @@ -110,7 +110,8 @@ impl TransactAsset for Tuple { log::trace!( target: "xcm::TransactAsset::can_check_in", "asset not found: what: {:?}, origin: {:?}", - &what, &origin, + what, + origin, ); Err(XcmError::AssetNotFound) } @@ -134,7 +135,8 @@ impl TransactAsset for Tuple { log::trace!( target: "xcm::TransactAsset::deposit_asset", "did not deposit asset: what: {:?}, who: {:?}", - &what, &who, + what, + who, ); Err(XcmError::Unimplemented) } @@ -146,7 +148,8 @@ impl TransactAsset for Tuple { log::trace!( target: "xcm::TransactAsset::withdraw_asset", "did not withdraw asset: what: {:?}, who: {:?}", - &what, &who, + what, + who, ); Err(XcmError::Unimplemented) } @@ -158,7 +161,9 @@ impl TransactAsset for Tuple { log::trace!( target: "xcm::TransactAsset::transfer_asset", "did not transfer asset: what: {:?}, from: {:?}, to: {:?}", - &what, &from, &to, + what, + from, + to, ); Err(XcmError::Unimplemented) }