diff --git a/prdoc/pr_7430.prdoc b/prdoc/pr_7430.prdoc new file mode 100644 index 0000000000000000000000000000000000000000..a3258a72c939601ca68011178645f14bbd92428c --- /dev/null +++ b/prdoc/pr_7430.prdoc @@ -0,0 +1,28 @@ +title: '[pallet-revive] fix tracing gas used' +doc: +- audience: Runtime Dev + description: |- + - Charge the nested gas meter for loading the code of the child contract, so that we can properly associate the gas cost to the child call frame. + - Move the enter_child_span and exit_child_span around the do_transaction closure to properly capture all failures + - Add missing trace capture for call transfer +crates: +- name: pallet-revive-fixtures + bump: minor +- name: pallet-revive + bump: minor +- name: pallet-revive-uapi + bump: minor +- name: asset-hub-westend-runtime + bump: minor +- name: pallet-migrations + bump: minor +- name: frame-support + bump: minor +- name: people-rococo-runtime + bump: minor +- name: people-westend-runtime + bump: minor +- name: rococo-runtime + bump: minor +- name: westend-runtime + bump: minor diff --git a/substrate/frame/revive/fixtures/contracts/caller_contract.rs b/substrate/frame/revive/fixtures/contracts/caller_contract.rs index b6a9bf2895fa6d48b3032c5b4e9b3839e93bb6ae..236aec2e863bdfb2a8822dcfb06a34c8d83d9446 100644 --- a/substrate/frame/revive/fixtures/contracts/caller_contract.rs +++ b/substrate/frame/revive/fixtures/contracts/caller_contract.rs @@ -31,7 +31,7 @@ pub extern "C" fn deploy() {} #[no_mangle] #[polkavm_derive::polkavm_export] pub extern "C" fn call() { - input!(code_hash: &[u8; 32],); + input!(code_hash: &[u8; 32], load_code_ref_time: u64,); // The value to transfer on instantiation and calls. Chosen to be greater than existential // deposit. @@ -49,8 +49,9 @@ pub extern "C" fn call() { // Fail to deploy the contract since it returns a non-zero exit status. let res = api::instantiate( - u64::MAX, // How much ref_time weight to devote for the execution. u64::MAX = use all. - u64::MAX, // How much proof_size weight to devote for the execution. u64::MAX = use all. + u64::MAX, /* How much ref_time weight to devote for the execution. u64::MAX = use + * all. */ + u64::MAX, // How much proof_size weight to devote for the execution. u64::MAX = use all. &[u8::MAX; 32], // No deposit limit. &value, &reverted_input_deploy, @@ -62,8 +63,9 @@ pub extern "C" fn call() { // Fail to deploy the contract due to insufficient ref_time weight. let res = api::instantiate( - 1u64, // too little ref_time weight - u64::MAX, // How much proof_size weight to devote for the execution. u64::MAX = use all. + 1u64, // too little ref_time weight + u64::MAX, /* How much proof_size weight to devote for the execution. u64::MAX = + * use all. */ &[u8::MAX; 32], // No deposit limit. &value, &input_deploy, @@ -75,7 +77,8 @@ pub extern "C" fn call() { // Fail to deploy the contract due to insufficient proof_size weight. let res = api::instantiate( - u64::MAX, // How much ref_time weight to devote for the execution. u64::MAX = use all. + u64::MAX, /* How much ref_time weight to devote for the execution. u64::MAX = use + * all. */ 1u64, // Too little proof_size weight &[u8::MAX; 32], // No deposit limit. &value, @@ -90,8 +93,9 @@ pub extern "C" fn call() { let mut callee = [0u8; 20]; api::instantiate( - u64::MAX, // How much ref_time weight to devote for the execution. u64::MAX = use all. - u64::MAX, // How much proof_size weight to devote for the execution. u64::MAX = use all. + u64::MAX, /* How much ref_time weight to devote for the execution. u64::MAX = use + * all. */ + u64::MAX, // How much proof_size weight to devote for the execution. u64::MAX = use all. &[u8::MAX; 32], // No deposit limit. &value, &input_deploy, @@ -118,8 +122,9 @@ pub extern "C" fn call() { let res = api::call( uapi::CallFlags::empty(), &callee, - 1u64, // Too little ref_time weight. - u64::MAX, // How much proof_size weight to devote for the execution. u64::MAX = use all. + load_code_ref_time, // Too little ref_time weight. + u64::MAX, /* How much proof_size weight to devote for the execution. u64::MAX + * = use all. */ &[u8::MAX; 32], // No deposit limit. &value, &INPUT, diff --git a/substrate/frame/revive/fixtures/contracts/tracing.rs b/substrate/frame/revive/fixtures/contracts/tracing.rs index 9cbef3bbc84355dc89968347248d4daed68aedad..451769b87cefd479fd2b4f3ab4c882c71bf39585 100644 --- a/substrate/frame/revive/fixtures/contracts/tracing.rs +++ b/substrate/frame/revive/fixtures/contracts/tracing.rs @@ -20,7 +20,7 @@ #![no_std] #![no_main] -use common::input; +use common::{input, u256_bytes}; use uapi::{HostFn, HostFnImpl as api}; #[no_mangle] @@ -32,6 +32,18 @@ pub extern "C" fn deploy() {} pub extern "C" fn call() { input!(calls_left: u32, callee_addr: &[u8; 20],); if calls_left == 0 { + // transfer some value to BOB + let _ = api::call( + uapi::CallFlags::empty(), + &[2u8; 20], + u64::MAX, // How much ref_time to devote for the execution. u64::MAX = use all. + u64::MAX, /* How much proof_size to devote for the execution. u64::MAX = use + * all. */ + &[u8::MAX; 32], // No deposit limit. + &u256_bytes(100), // Value transferred + &[], + None, + ); return } diff --git a/substrate/frame/revive/src/exec.rs b/substrate/frame/revive/src/exec.rs index dc91c6f301009da44c5c07a99a1d0c4c25418df8..d7e16dea4564361b0dfa21ab1cea61ea08004e17 100644 --- a/substrate/frame/revive/src/exec.rs +++ b/substrate/frame/revive/src/exec.rs @@ -736,24 +736,23 @@ where )? { stack.run(executable, input_data).map(|_| stack.first_frame.last_frame_output) } else { + let result = Self::transfer_from_origin(&origin, &origin, &dest, value); if_tracing(|t| { - let address = - origin.account_id().map(T::AddressMapper::to_address).unwrap_or_default(); - let dest = T::AddressMapper::to_address(&dest); - t.enter_child_span(address, dest, false, false, value, &input_data, Weight::zero()); + t.enter_child_span( + origin.account_id().map(T::AddressMapper::to_address).unwrap_or_default(), + T::AddressMapper::to_address(&dest), + false, + false, + value, + &input_data, + Weight::zero(), + ); + match result { + Ok(ref output) => t.exit_child_span(&output, Weight::zero()), + Err(e) => t.exit_child_span_with_error(e.error.into(), Weight::zero()), + } }); - let result = Self::transfer_from_origin(&origin, &origin, &dest, value); - match result { - Ok(ref output) => { - if_tracing(|t| { - t.exit_child_span(&output, Weight::zero()); - }); - }, - Err(e) => { - if_tracing(|t| t.exit_child_span_with_error(e.error.into(), Weight::zero())); - }, - } result } } @@ -874,61 +873,75 @@ where read_only: bool, origin_is_caller: bool, ) -> Result<Option<(Frame<T>, E)>, ExecError> { - let (account_id, contract_info, executable, delegate, entry_point) = match frame_args { - FrameArgs::Call { dest, cached_info, delegated_call } => { - let contract = if let Some(contract) = cached_info { - contract - } else { - if let Some(contract) = - <ContractInfoOf<T>>::get(T::AddressMapper::to_address(&dest)) - { + let (account_id, contract_info, executable, delegate, entry_point, nested_gas) = + match frame_args { + FrameArgs::Call { dest, cached_info, delegated_call } => { + let contract = if let Some(contract) = cached_info { contract } else { - return Ok(None); - } - }; + if let Some(contract) = + <ContractInfoOf<T>>::get(T::AddressMapper::to_address(&dest)) + { + contract + } else { + return Ok(None); + } + }; - let (executable, delegate_caller) = - if let Some(DelegatedCall { executable, caller, callee }) = delegated_call { + let mut nested_gas = gas_meter.nested(gas_limit); + let (executable, delegate_caller) = if let Some(DelegatedCall { + executable, + caller, + callee, + }) = delegated_call + { (executable, Some(DelegateInfo { caller, callee })) } else { - (E::from_storage(contract.code_hash, gas_meter)?, None) + (E::from_storage(contract.code_hash, &mut nested_gas)?, None) }; - (dest, contract, executable, delegate_caller, ExportedFunction::Call) - }, - FrameArgs::Instantiate { sender, executable, salt, input_data } => { - let deployer = T::AddressMapper::to_address(&sender); - let account_nonce = <System<T>>::account_nonce(&sender); - let address = if let Some(salt) = salt { - address::create2(&deployer, executable.code(), input_data, salt) - } else { - use sp_runtime::Saturating; - address::create1( - &deployer, - // the Nonce from the origin has been incremented pre-dispatch, so we - // need to subtract 1 to get the nonce at the time of the call. - if origin_is_caller { - account_nonce.saturating_sub(1u32.into()).saturated_into() - } else { - account_nonce.saturated_into() - }, + ( + dest, + contract, + executable, + delegate_caller, + ExportedFunction::Call, + nested_gas, ) - }; - let contract = ContractInfo::new( - &address, - <System<T>>::account_nonce(&sender), - *executable.code_hash(), - )?; - ( - T::AddressMapper::to_fallback_account_id(&address), - contract, - executable, - None, - ExportedFunction::Constructor, - ) - }, - }; + }, + FrameArgs::Instantiate { sender, executable, salt, input_data } => { + let deployer = T::AddressMapper::to_address(&sender); + let account_nonce = <System<T>>::account_nonce(&sender); + let address = if let Some(salt) = salt { + address::create2(&deployer, executable.code(), input_data, salt) + } else { + use sp_runtime::Saturating; + address::create1( + &deployer, + // the Nonce from the origin has been incremented pre-dispatch, so we + // need to subtract 1 to get the nonce at the time of the call. + if origin_is_caller { + account_nonce.saturating_sub(1u32.into()).saturated_into() + } else { + account_nonce.saturated_into() + }, + ) + }; + let contract = ContractInfo::new( + &address, + <System<T>>::account_nonce(&sender), + *executable.code_hash(), + )?; + ( + T::AddressMapper::to_fallback_account_id(&address), + contract, + executable, + None, + ExportedFunction::Constructor, + gas_meter.nested(gas_limit), + ) + }, + }; let frame = Frame { delegate, @@ -936,7 +949,7 @@ where contract_info: CachedContract::Cached(contract_info), account_id, entry_point, - nested_gas: gas_meter.nested(gas_limit), + nested_gas, nested_storage: storage_meter.nested(deposit_limit), allows_reentry: true, read_only, @@ -1414,13 +1427,28 @@ where )? { self.run(executable, input_data) } else { - Self::transfer_from_origin( + let result = Self::transfer_from_origin( &self.origin, &Origin::from_account_id(self.account_id().clone()), &dest, value, - )?; - Ok(()) + ); + if_tracing(|t| { + t.enter_child_span( + T::AddressMapper::to_address(self.account_id()), + T::AddressMapper::to_address(&dest), + false, + false, + value, + &input_data, + Weight::zero(), + ); + match result { + Ok(ref output) => t.exit_child_span(&output, Weight::zero()), + Err(e) => t.exit_child_span_with_error(e.error.into(), Weight::zero()), + } + }); + result.map(|_| ()) } }; diff --git a/substrate/frame/revive/src/lib.rs b/substrate/frame/revive/src/lib.rs index 69d60c5d6a9523e5727e33bd34d06fb1e489f92f..bbfaee141c6bd71c69ed4f2276f0861fcc1f9a1c 100644 --- a/substrate/frame/revive/src/lib.rs +++ b/substrate/frame/revive/src/lib.rs @@ -1018,7 +1018,7 @@ where storage_deposit = storage_meter .try_into_deposit(&origin, storage_deposit_limit.is_unchecked()) .inspect_err(|err| { - log::error!(target: LOG_TARGET, "Failed to transfer deposit: {err:?}"); + log::debug!(target: LOG_TARGET, "Failed to transfer deposit: {err:?}"); })?; Ok(result) }; diff --git a/substrate/frame/revive/src/tests.rs b/substrate/frame/revive/src/tests.rs index 319b35d1916bd21369664ce72ce74ae0ffcff37d..6a74660702fa838935431c906358ff0eca89be59 100644 --- a/substrate/frame/revive/src/tests.rs +++ b/substrate/frame/revive/src/tests.rs @@ -1005,6 +1005,7 @@ fn transient_storage_limit_in_call() { fn deploy_and_call_other_contract() { let (caller_wasm, _caller_code_hash) = compile_module("caller_contract").unwrap(); let (callee_wasm, callee_code_hash) = compile_module("return_with_data").unwrap(); + let code_load_weight = crate::wasm::code_load_weight(callee_wasm.len() as u32); ExtBuilder::default().existential_deposit(1).build().execute_with(|| { let min_balance = Contracts::min_balance(); @@ -1032,7 +1033,9 @@ fn deploy_and_call_other_contract() { // Call BOB contract, which attempts to instantiate and call the callee contract and // makes various assertions on the results from those calls. - assert_ok!(builder::call(caller_addr).data(callee_code_hash.as_ref().to_vec()).build()); + assert_ok!(builder::call(caller_addr) + .data((callee_code_hash, code_load_weight.ref_time()).encode()) + .build()); assert_eq!( System::events(), @@ -4442,20 +4445,19 @@ fn tracing_works_for_transfers() { } #[test] -#[ignore = "does not collect the gas_used properly"] fn tracing_works() { use crate::evm::*; use CallType::*; let (code, _code_hash) = compile_module("tracing").unwrap(); let (wasm_callee, _) = compile_module("tracing_callee").unwrap(); ExtBuilder::default().existential_deposit(200).build().execute_with(|| { - let _ = <Test as Config>::Currency::set_balance(&ALICE, 1_000_000); + let _ = <Test as Config>::Currency::set_balance(&ALICE, 100_000_000); let Contract { addr: addr_callee, .. } = builder::bare_instantiate(Code::Upload(wasm_callee)).build_and_unwrap_contract(); let Contract { addr, .. } = - builder::bare_instantiate(Code::Upload(code)).build_and_unwrap_contract(); + builder::bare_instantiate(Code::Upload(code)).value(10_000_000).build_and_unwrap_contract(); let tracer_options = vec![ ( false , vec![]), @@ -4553,6 +4555,15 @@ fn tracing_works() { to: addr, input: (0u32, addr_callee).encode(), call_type: Call, + calls: vec![ + CallTrace { + from: addr, + to: BOB_ADDR, + value: U256::from(100), + call_type: CallType::Call, + ..Default::default() + } + ], ..Default::default() }, ], diff --git a/substrate/frame/revive/src/wasm/mod.rs b/substrate/frame/revive/src/wasm/mod.rs index dc49fae26fdaa36509bdc1e9beffeb7188ef027e..30418cf84b24c36d60de7adfc0bf057e00ef9143 100644 --- a/substrate/frame/revive/src/wasm/mod.rs +++ b/substrate/frame/revive/src/wasm/mod.rs @@ -115,6 +115,11 @@ impl<T: Config> Token<T> for CodeLoadToken { } } +#[cfg(test)] +pub fn code_load_weight(code_len: u32) -> Weight { + Token::<crate::tests::Test>::weight(&CodeLoadToken(code_len)) +} + impl<T: Config> WasmBlob<T> where BalanceOf<T>: Into<U256> + TryFrom<U256>,