v0.2Report
#
Report for Europa v0.2Six weeks ago, Patract Hub (https://patract.io) applied a Treasury Proposal #27 for Europa v0.2 , and now we have finished all the development work in (https://github.com/patractlabs/Europa). Europa is kind of another implementation for Substrate client in our design. We know that the runtime of a blockchain is the business logic that defines its behavior, and the Substrate runtime need to run by an executor and environment. So that we design the executor and environment more like a "sandbox" to run a Substrate runtime.
In v0.2, the primary target is to modify Pallet Contracts
in runtime to provide more detailed debugging information, including contract execution process information (in Pallet Contracts
layer) and Wasm execution information (in WASMI execution layer).
#
Recap of Europa's future planv0.1: Have an independent runtime environment to facilitate more subsequent expansion directions.v0.2: Modify at FRAME Contracts pallet level to provide more information- v0.3: Improve the development experience, strengthen collaboration with other tools, and extend the sandbox to be compatible with other runtime modules。
#
Recap of verification for Europa v0.2:
- Construct incorrect contracts and execute logs printing to determine whether it meets expectations
- Display the call statistics of the
define_env!
interface during contract execution- Execute the log printing function, provide formatted printing examples of different data, and judge whether it meets expectations
- Construct a contract that crashes under different conditions and record the log after execution. Then judge whether the backtrace information of the contract execution is completely printed, and check whether it matches the actual execution of the collapsed contract.
#
1.DesignIn 0.2, the debugging information function of the upgrade contract module is divided into three parts of modification:
- Modification on the
Pallet Contracts
layer: By adding trace during the execution of the contract byPallet Contracts
, the information in the contract layer is recorded, and the calling level of the contract is recorded. On the other hand, the error message of calling Wasm execution is improved. - Modification on the
wasmi
layer: We have provided the backtrace function of recording wasm execution forwasmi
, and provided support forparity-wasm
,pwasm-utils
, andcargo-contract
during wasm processing of the contract contains the function of the name section. - Contract logging function: Use the function of
ChainExtensions
to realize the library for printing thelog
in the contract.
In the current Pallet Contracts
, when an error occurs in the execution of wasmi
, and in the host_function call of Pallet Contracts
during the execution of wasmi, it will be displayed as a ContractTrap
error externally. In this situation, it is difficult for developers to locate the cause of the error. Only from this information, it is impossible to tell whether the problem is the contract itself, ink!
, or Pallet Contracts
. Therefore, the rich information that Europa v0.2 can provide allows developers to directly locate the cause of the problem.
Pallet Contracts
layer#
1.1 on During the contract debugging process, Europa believes that developers need:
- Rich error information: Wasm records the error information during the entire execution process, including Wasm executor errors and host_function errors. The backtrace information of wasmi will be unified with the error information here.
- Execution in the debugging process: The main modification information of
Pallet Contracts
, the "contract stack" is used to record the process of contract calling contract, and any information that can assist debugging during the execution of this layer of contract, such as the situation of calling the host_function, selector, and calling contract parameters, etc.
Therefore, in response to such needs, Europa made the following designs and modifications:
#
1.1.1 rich error information1.error on the wasm executor layer:
Europa designed our own ep-sandbox
to replace the original sp-sandbox
used by Pallet Contracts
, and modified ep_sandbox::Error
use patract_wasmi::Error as WasmiError;pub enum Error {Module(WasmiError),OutOfBounds,Execution,WasmiExecution(WasmiError),}
Module(WasmiError)
carries the original error information of the Wasm layer, and the to_execution_result
in frame/contracts/src/wasm/runtime.rs
is converted to String
to throw an error message.
Europa's own ep-sandbox
only has the std
version (because Europa has removed all Wasm parts, there is no need for ep-sandbox
to support no-std
), so in the future, ep-sandbox
can be replaced with different wasm executors to support running tests of different wasm executors, and replaced with wasm executors that support debugging and other features.
Currently ep-sandbox
uses a forked version of wasmi
as the executor, so the error it throws is WasmiError
. See the next chapter for errors inwasmi
.
2.error of host_functions:
The host function execution error will cause Trap, and will record TrapReason
. No modification to the data structure, just record.
#
1.1.2 Execution during debuggingThe Europa forked version of Pallet Contracts
has designed an object to record any information that can help debugging during contract execution:
/// Record the contract execution context.pub struct NestedRuntime { /// Current depth depth: usize, /// The current contract execute result ext_result: ExecResult, /// The value in sandbox successful result sandbox_result_ok: Option<ReturnValue>, /// Who call the current contract caller: AccountId32, /// The account of the current contract self_account: Option<AccountId32>, /// The input selector selector: Option<HexVec>, /// The input arguments args: Option<HexVec>, /// The value in call or the endowment in instantiate value: u128, /// The gas limit when this contract is called gas_limit: Gas, /// The gas left when this contract return gas_left: Gas, /// The host function call stack env_trace: EnvTraceList, /// The error in wasm wasm_error: Option<WasmErrorWrapper>, /// The trap in host function execution trap_reason: Option<TrapReason>, /// Nested contract execution context nest: Vec<NestedRuntime>,}
In the model of Pallet Contracts
, a contract calling another contract is in the "contract stack" model, so NestedRuntime
will track the execution process of the entire contract stack, and use the property of nest
to store a list of NestedRuntime
to represent other contracts the the contract called.
In the process of executing a contract by Pallet Contracts
, Europa records the relevant information in the execution process in the structure of NestedRuntime
in the form of a bypass, and will print the NestedRuntime
to the log (show the case later) in a certain format after the contract call ends. Contract developers can analyze the information printed by NestedRuntime
to obtain various detailed information during the execution of the contract, which can be used in various situations:
- help to locate where the error occurs, including the following situations:
Pallet Contracts
layerink!
layer- The specific position in the contract layer
- Locate which level of the contract is when a contract calling another contract
- Analyze the information during the execution of the contract at this timing:
- Analyze the consumption of gas execution
- Analyze the call of
get_storage
andset_storage
, help reconstruct the contract code and analyze the demand ofrent
- According to
selector
,args
andvalue
, analyze and locate whether the transaction parameters of the third-party SDK are legal. - Analyze the execution path of the contract and adjust the contract based on the
nest
information and combined with theseal_call
information. - etc.
The process of recording Pallet Contracts
executing contract to NestEdRuntime
is relatively fine-grained.
The process of logging the information of the execution contract of Pallet Contracts
to NestEdRuntime
is relatively fine-grained. Take seal_call
in define_env!
as an example:
pub struct SealCall { callee: Option<HexVec>, gas: u64, value: Option<u128>, input: Option<HexVec>, output: Option<HexVec>,}
The attributes are basically Option<>
. For example, before calling the contract, the input
will be set to Some
, and the return value will be set after the calling contract is normal. If there is an error in the calling contract, then output
will remain None
. Therefore, if input
is Some
and output
is None
, it means that there is a problem with the called contract during the process of calling the contract.
The current information of NestedRuntime
is only printed in the log. In the future, NestedRuntime
will be stored locally and provide corresponding RPC for external access. Therefore, in the future, third-party applications can obtain NestedRuntime
for further processing. For example, in our Redspot
, a plug-in can be designed to generate a contract call another contract topology based on the information of NestedRuntime
, and a visual contract call path can be generated on the web wallet interface, etc.
wasmi
layer#
1.2 on We forked wasmi and integrated it into ep-sandbox
. Forked Pallet Contracts
can obtain the error information of forked wasmi
through ep-sandbox
, including the backtrace information of wasmi
.
If you need to make wasmi
can retain the backtrace information during execution, you need to have the following functions:
- The "name section" section is required in the Wasm source file (see the specification of name section))
- Keep the "name section" information in the process of checking the contract by
Pallet Contracts
and still have a corresponding relationship with the wasm source file after the process. - During the execution of
wasmi
, the execution stack needs to be preserved with the key information of the functions. At the same time, the "name section" needs to be parsed and correspond to the function information reserved by thewasmi
execution stack.
The changes to 2 involve cargo-build
and parity-wasm
, while the changes to 1 and 3 are mainly in the forked wasmi
, and a small part involves pwasm-utils
.
#
1.2.1 Submitted Wasm files contains debug info from "name section"Frist of all, we have to submit wasm files which contain the debug info that the on-chain side can parse and get the panic errors.
Currently, parity/cargo-contract trims debug info while building contracts, we can get them back with the following steps.
#
1. Keep name section from stripingThe name section has been striped at cargo-contract/cmd/build.rs#L247.
wasm-opt
#
2. Keep debug info from cargo-contract
passes debug_info: false
to wasm-opt
, so the debug-info will be always optimized when we run wasm-opt
, the code is here: cargo-contract/cmd/build.rs#L267.
rustc
#
3. Keep debug info from cargo-contract
executes realease build by default, here we can enable debug build or modify the opt-level flag of rustc
to keep debug infos at cargo-contract/cmd/build.rs#L137.
Pallet Contracts
#
1.2.2 Save debug info from the scraper of What happends to the Pallet Contracts
while we calling a contract?
- Get the Wasm binary from storage
- Inject gas meter to the contract
- Inject stack height to the contract
- Put the contract into
sp-sandbox
and execute it - Get the result from
sp-sandbox
and return the result to us
#
1. Store name section while building Wasm modulePallet Contracts
builds Wasm modules from storage and drops custom sections by default, here we should get them back.
#
2. Update function indices in name section while injecting gas meterPallet Contracts
reorders the indcies of functions in our Wasm contracts after injecting gas memter to the Wasm contracts at paritytech/wasm-utils/gas/mod.rs#L467, this will mess up the function indecies in name section that we can not get the correct backtraces.
#
3. Impelment Wasm backtrace to WASMI- Source: patractlabs/wasmi
Remember the last two steps in chapter 2, the core part of enabling Wasm backtrace to Pallet Contract
is making wasmi
support backtrace.
The process of executing a function in the interpreter of wasmi is like:
- Invoke the target function
- call and call and call over again
- Panic if the process breaks.
FuncRef
#
Add function info field to FuncRef
is the 'function' wasmi interpreter calling directly, so we need to embed the debug info into the FuncRef
as the first time, source at wasmi/func.rs#L26.
//! patractlabs/wasmi/src/func.rs#L26/// ...pub struct FuncRef { /// ... /// Function name and index for debug info: Option<(usize, String)>,}
#
Set function info using name section while parsing Wasm modulesWe alread have the info
field in FuncRef
, now we need to fill this field using name section while parsing Wasm modules, source at wasmi/module#L343.
//! wasmi/src/module.rs#L343// ...if has_name_section { if let Some(name) = function_names.get((index + import_count) as u32) { func_instance = func_instance.set_info(index, name.to_string()); } else { func_instance = func_instance.set_info(index, "<unknown>".to_string()); }}// ...
trace
#
Make the interpreter support However, we don't need to get infos of every functions but the panicked series in the stack of the interpreter, source at wasmi/runner.rs#L1491.
//! wasmi/src/runner.rs#L1491/// Get the functions of current the stackpub fn trace(&self) -> Vec<Option<&(usize, String)>> { self.buf.iter().map(|f| f.info()).collect::<Vec<_>>()}
#
Gather debug infos when program breaksJust gather backtraces when we invoke function failed, source at wasmi/func.rs#L170.
//! wasmi/src/func.rs#L170// ...
let res = interpreter.start_execution(externals);if let Err(trap) = res {let mut stack = interpreter .trace() .iter() .map(|n| { if let Some(info) = n { format!("{:#}[{}]", rustc_demangle::demangle(&info.1), info.0) } else { "<unknown>".to_string() } }) .collect::<Vec<_>>();
// Append the panicing trapstack.append(&mut trap.wasm_trace().clone());stack.reverse();
// Embed this info into the trapErr(trap.set_wasm_trace(stack))
// ...
#
1.3 Contract Log functionsIn the process of contract debugging, you need to know the internal execution of the contract and the intermediate data. In the current lack of debugging conditions (such as using gdb for debugging), log printing is the most convenient way. As mentioned in the Europa v0.2 proposal, the current Pallet Contracts
and ink!
already support format!
+seal_println
to format and print strings, but this mode has two defects :
- All the logs of
seal_println
printed on the node side aretarget: runtime
and levelDEBUG
, but when developing complex contracts, a lot of logs will be printed. If you cannot filter bytarget
and log level, then the development process will be full of interference from irrelevant information. - The contract developer wrote
seal_println
when needed during the development process, but allseal_println
must be deleted when the contract is released. Although the contract developer can encapsulate a conditionally compiled function to control it, it is more convenient if a tool library already provides such a function.
Therefore, Europa provides a log library patractlabs/ink-log that mimics Rust's log
crete to solve the above problems. Its usage is the same as that of Rust. log
is completely consistent, which reduces the learning cost of developers.
The ink-log
is generally implemented by the ChainExtension
of Pallet Contracts
, the agreed function_id
is 0xfeffff00
, and the message is transmitted in the wasm memory through the structure LoggerExt
. Therefore this library is divided into the following two parts:
ink_log
: In theink-log/contracts
directory, provideinfo!
,debug!
,warn!
,error!
,trace!
, same as Rust'slog
library in the same macro, and the call method of the macro is also the same. These macros are packaged implementations ofseal_chain_extensions
on the ink! side, and are tool library for contract developers. For example, after this library is introduced in the contractCargo.toml
, the log can be printed as follows:In
Cargo.toml
:[dependencies]ink_log = { version = "0.1", git = "https://github.com/patractlabs/ink-log", default-features = false, features = ["ink-log-chain-extensions"] } [features]default = ["std"]std = [ # ... "ink_log/std"]
In the contract, you can use the following methods to print logs in the node:
ink_log::info!(target: "flipper-contract", "latest value is: {}", self.value);
runtime_log
: In the ink-log/runtime
directory, this library is based on the contents of the function_id
and LoggerExt
structures passed from ChainExtensions
to call the corresponding logs under debug
in frame_support
to print. It is an implementation library of ink_log
prepared for developers of the chain. **For example, chain developers can use it in their own ChainExtensions
:
In Cargo.toml
:
[dependencies]runtime_log = { version = "0.1", git = "https://github.com/patractlabs/ink-log", default-features = false }
[features]default = ["std"]std = [ # ... "runtime_log/std"]
In ChainExtensions
's implementation:
pub struct CustomExt;impl ChainExtension for CustomExt { fn call<E: Ext>(func_id: u32, env: Environment<E, InitState>) -> Result<RetVal, DispatchError> where <E::T as SysConfig>::AccountId: UncheckedFrom<<E::T as SysConfig>::Hash> + AsRef<[u8]>, { match func_id { ... => {/* other ChainExtension */ } 0xfeffff00 => { // TODO add other libs runtime_log::logger_ext!(func_id, env); // or use // LoggerExt::call::<E>(func_id, env) Ok(RetVal::Converging(0)) } } }}
ink_log
corresponds to runtime_log
, so if contract developers need to use ink_log
, they need to pay attention to the chain corresponding to the debugging contract that needs to implement runtime_log
.
On the other hand, after contract developers introduce ink_log
, they need to pay attention to features = ["ink-log-chain-extensions"]
, ink_log
will call seal_chain_extensions
to interact with the chain only when this feature is enabled. Without this feature, noop
will be used to skip the process of contract printing.
Therefore, contract developers can control the contract to print logs in the debugging environment and the production environment through features. The contract compiled in the debugging environment opens the "ink-log-chain-extensions"
feature, and the contract compiled in the production environment removes this feature.
#
2. What Europa can do in v0.2#
2.1 BuildFor contract developers, it is necessary to prepare Europa
and cargo-contract
tools.
#
2.1.1 EuropaThe building process for this project is as same as Substrate.
When building finished, current executable file in target
directory is named Europa
.
git clone --recurse-submodules https://github.com/patractlabs/Europa.git
#
2.1.2 cargo-contractIf you want to see the backtrace executed by Wasm during the operation of Europa, you must use the cargo-contract
version we provide. Because the current paritytech repo cargo-contract uses the highest optimization level when compiling the contract, and discards the "name section" part in Wasm. As mentioned above, if you need to print the call stack information in the wasmi execution contract, the contract file must have the "name section" part, so the use of the cargo-contract
provided by paritytech cannot meet the requirements. We completed this function in our forked repo. On the other hand, we think that the function of "name section" in Wasm may not only be needed by Europa, so we submitted pr#131[Enable debug info to the source warehouse with flag in command build] provides this feature.
Before this PR is merged, currently only the cargo-contract
version provided by us (Patract Labs) can be used:
cargo install --git https://github.com/patractlabs/cargo-contract --branch cmd/debug --force
If you do not want this version of cargo-contract
to override the version released by paritytech, then it is recommended to compile locally and use the compiled cargo-contract
directly:
git clone https://github.com/patractlabs/cargo-contract --branch cmd/debugcd cargo-contractcargo build --release
Note: Executing the
cargo-contract build
command requires thedefault toolchain
of the rust tool-chain to benightly
, otherwise you can only usecargo +nightly contract build
, but usingcargo
to callcargo-contract
needs to be executedcargo install
installs or overwrites the compiled product in the~/.cargo/bin
directory, and cannot co-exist with paritytech'scargo-contract
Execute:
cargo-contract build --help# orcargo +nightly contract build --help
If you can see:
FLAGS: -d, --debug Emits debug info into wasm file
It means that you are using the cargo-contract
provided by Patract Labs. If you want to see the backtrace of the Wasm contract execution crash while using Europa, you need to add the --debug
command when compiling the contract.
Using the --debug
command will generate another file besides the normal file in the target/ink
directory of the originally compiled contract, ending with *.src.wasm
. This *.src.wasm
file is the Wasm contract file containing the "name section" part.
If you need to use Europa for testing, the contract deployed to Europa needs to use this *.src.wasm
file instead of the originally generated *.wasm
file.
#
exampleWe can use one simple case and other cases we have encountered to verify the reliability of Europa's positioning problems.
In the following context, the methods of starting Europa are all used by:
$ Europa --tmp -lruntime=debug
Every time Europa is started in this way, new data is created. If you want to keep Europa's execution data, please refer to Europa's README or Europa v0.1's [Report](https://polkadot.polkassembly.io/post/ 166), you can get more command introduction.
#
Case 1:Simple caseFor example, we modify the example contract ink/example/erc20
in the ink! project as follows:
#[ink(message)]pub fn transfer(&mut self, to: AccountId, value: Balance) -> Result<()> { let from = self.env().caller(); self.transfer_from_to(from, to, value)?; panic!("123"); Ok(())}
Wasm, it corresponds to the code after the macro expansion of the original file, so if you want to compare the errors of the call stack, you need to expand the macro of the original contract:
cargo install expandcd ink/example/erc20cargo expand > tmp.rs
After reading the tmp.rs
file, we can know that Wasm needs to go through when it executes the transfer
function:
fn call() -> u32 -> <Erc20 as ::ink_lang::DispatchUsingMode>::dispatch_using_mode(...)-> <<Erc20 as ::ink_lang::ConstructorDispatcher>::Type as ::ink_lang::Execute>::execute(..) # compile selector at here-> ::ink_lang::execute_message_mut-> move |state: &mut Erc20| { ... } # a closure-> <__ink_Msg<[(); 2644567034usize]> as ::ink_lang::MessageMut>::CALLABLE-> transfer
Therefore, if the panic
in transfer
is encountered during the contract call, the backtrace of Wasm should be similar to this.
First we start Europa:
$ Europa --tmp -lruntime=debug
Then we deploy this erc20 and call transfer to execute.
We can use Polkadot/Substrate Portal
or use RedSpot to verify this process. Suppose we use RedSpot
to execute a transfer
call of this wrong ERC20 contract. Please note that the --debug
subcommand must be added in the process of compiling the contract:
$ npx redspot-new erc20$ cd erc20/contracts# add panic in `transfer` function as abrove$ vim lib.rs # notice must add --debug when compile contract# due current cargo-contract is not paritytech, we need to copy compile product into `artifacts` directory. RedSpot would support Europa and PatractLabs's cargo-contract in next version.$ cargo +nightly contract build --debug $ mkdir ../artifacts# notice must cp erc20.src.wasm, not erc20.wasm$ cp ./target/ink/erc20.src.wasm ../artifacts # notice must rename metadata.json to erc20.json$ cp ./target/ink/metadata.json ../artifacts/erc20.json $ cd ../# enter redspot console, use `--no-compile` to deny recompile contract$ npx redspot console --no-compile # in redspot consoleWelcome to Node.js v12.16.1.Type ".help" for more information.> > var factory = await patract.getContractFactory('erc20')# do following command could deploy the erc20 contract> var contract = await factory.deployed('new', '1000000', {value: 20000000000, salt:1})# do a transfer call directly> await contract.transfer("5GcTYx4dPTQfi4udKPvE4VKmbooV7zY6hNYVF9JXHJL4knNF", 100)
Then in Europa's log, you can see:
1: NestedRuntime { ext_result: [failed] ExecError { error: DispatchError::Module {index:5, error:17, message: Some("ContractTrapped"), orign: ErrorOrigin::Caller }} caller: d43593c715fdd31c61141abd04a99fd6822...(5GrwvaEF...), self_account: b6484f58b7b939e93fff7dc10a654af7e.... (5GBi41bY...), selector: 0xfae3a09d, args: 0x1cbd2d43530a44705ad088af313e18f80b5...., value: 0, gas_limit: 409568000000, gas_left: 369902872067, env_trace: [ seal_value_transferred(Some(0x00000000000000000000000000000000)), seal_input(Some(0xfae3a09d1cbd.....)), seal_get_storage((Some(0x0100000000000....), Some(0x010000000100000001000000))), # ... seal_caller(Some(0xd43593c715fdd31c61141abd...)), seal_hash_blake256((Some(0x696e6b20686173....), Some(0x0873b31b7a3cf....))), # ... seal_deposit_event((Some([0x45726332303a....00000000000]), Some(0x000..))), ], trap_reason: TrapReason::SupervisorError(DispatchError::Module { index: 5, error: 17, message: Some("ContractTrapped") }), wasm_error: Error::WasmiExecution(Trap(Trap { kind: Unreachable })) wasm backtrace: | core::panicking::panic[28] | erc20::erc20::_::<impl erc20::erc20::Erc20>::transfer[1697] | <erc20::erc20::_::__ink_Msg<[(); 2644567034]> as ink_lang::traits::MessageMut>::CALLABLE::{{closure}}[611] | core::ops::function::FnOnce::call_once[610] | <erc20::erc20::_::_::__ink_MessageDispatchEnum as ink_lang::dispatcher::Execute>::execute::{{closure}}[1675] | ink_lang::dispatcher::execute_message_mut[1674] | <erc20::erc20::_::_::__ink_MessageDispatchEnum as ink_lang::dispatcher::Execute>::execute[1692] | erc20::erc20::_::<impl ink_lang::contract::DispatchUsingMode for erc20::erc20::Erc20>::dispatch_using_mode[1690] | call[1691] ╰─><unknown>[2387] , nest: [],}
Let us explain the information printed above:
ext_result
: indicates that this contract call is displayed as successful or failed:[success]
: indicates the successful execution of this contract (Note: the successful execution of the contract does not mean the successful execution of the business logic of the contract itself. There may be an error return inink!
or the business logic of the contract itself, as in case 3 in the following text.) And theExecResultValue {flag:0, data: 0x...}
followed by[success]
indicates the return value after this contract is executed.[failed]
: indicates that the execution of this contract failed, and theExecError {.. }
followed by[failed]
indicates the cause of this error. The reason for this is the value recorded inevent
on the chain, which is the value defined indecl_error!
ofPallet Contracts
.
1: NestedRuntime
&nest
: The contract information that represents the current print information is located in the first layer of the contract call stack. If the current contract calls another contract, it will appear in the array of thenest
field.2: NestedRuntime
and1: NestedRuntime
has the same structure. Among them,2
indicates that the called contract is in the second layer of the contract call stack. If several contracts are called across contracts in the current contract, there will be severalNestedRuntime
in the array ofnest
. If there are other contract calls in the second-level contract, the same goes for.For example, if there are contracts A, B, C, if it is the following situation:
After A calls B, it returns to A to continue execution, and then calls contract C
|A|| |->|B|| |<-| |->|C|| |<-
Then it will produce a log print similar to the following:
1: NestedRuntime { self_account: A, nest:[ 2: NestedRuntime { self_account: B, nest:[], }, 2: NestedRuntime { self_account: C, nest:[], } ]}
After A calls B, B calls contract C again, and finally returns to A
|A|| |->|B|| | | |->|C|| | | |<-| |<-
Then it will produce a log print similar to the following:
1: NestedRuntime { self_account: A, nest:[ 2: NestedRuntime { self_account: B, nest:[ 3: NestedRuntime { self_account: C, nest:[], } ], } ]}
caller
: who is the caller of the current contract. If the contract calls the contract, the value of the called contract is the address of the upper-level contract.self_account
: represents the address of the current contract itself.selector
&args
&value
: Represents theselector
and parameters passed in when calling the current contract. These information can quickly locate whether the calling contract method is correct.gas_limit
&gas_left
: Represents thegas_limit
passed in when the contract is currently called and the remaining gas after executing this layer. Note here thatgas_left
refers to the remaining gas after the execution of this layer of contract, so In the contract call contract, the gas consumed by each layer of contract can be determined throughgas_left
, not only get the consumption after the execution of the entire contract.env_trace
: Indicates that during the execution of the current layer of the contract, each time host_function is called in the contract Wasm execution, a record will be added to the list here. Because all host_functions and the definitions indefine_env!
in thePallet Contracts
module are related, so tracingenv_trace
can trace the process of interacting withPallet Contracts
during the execution of the current Wasm contract.For example, if following thing appears in
env_trace
:seal_call
: It means that there is a contract call contract situation in the current contract. According to the order in whichseal_call
appears inenv_trace
, it can correspond tonest
to calculate the state before and after the contract calls the contract.seal_get_storage
&seal_set_storage
: It means that data read and write occurred in the contract. Through these two interfaces, it is possible to intercept and count the data read and write during the execution of the current contract, and the data size calculated byseal_set_storage
can also be used to infer the storage size required byrent
.seal_deposit_event
: indicates that the event is printed in the contract. Here you can intercept the content of each event separately, instead of getting a unified event at the end. And the following text will use an example to surface that Europa can quickly locate the bug in thehost_function
.
On the other hand, the statistics of
env_trace
are relatively fine-grained. For example, if there are multiple possible errors inhost_function
, when an error occurs, all the information before the error will be retained, so it can be located to the place where the problem occurred during the execution ofhost_function
.And if there is an error in
host_function
that causes the contract to end execution,env_trace
records the last errorhost_function
call, so you can directly locate whichhost_function
caused the contract execution exception.trap_reason
: According to the definition ofTrapReason
inPallet Contracts
,trap_reason
can be divided into 2 categories:Return
&Termination
&Restoration
: indicates that the contract exit is the design ofPallet Contracts
, not an internal error. This type of trap indicates that the contract is executed normally and is not an error.SupervisorError
: Indicates that an error occurred during the execution of the contract calling host_function.
Therefore, the current Europa log printing design is designed to record whenever
trap_reason
appears. On the other hand,trap_reason
may not always appear during the execution of the contract. Combining the design ofPallet Contracts
andink!
, there is a case where the successful execution of the contract or the execution failure in theink!
layer does not generatetrap_reason
. Therefore, in addition to recordingtrap_reason
, Europa also records the results returned by the Wasm executor after execution, which is recorded withsandbox_result_ok
.
sandbox_result_ok
: The value ofsandbox_result_ok
represents the result of the contract after the Wasm executor is executed. This value could have been recorded assandbox_result
, including correct and incorrect conditions. However, due to the limitations of Rust and combined with the business logic ofPallet Contracts
, only the result ofsandbox_result
is kept asOk
here. For log printing, Europa is designed to printsandbox_result_ok
only when trap_reason is the first case, as information to assist in judging contract execution.sandbox_result_ok
is the Wasm executor result after callinginvoke
After the processing ofto_execution_result
, if there is notrap_reason
, the result ofOk(..)
is [discarded](https://github.com/paritytech/substrate/blob/712085115cdef4a79a66747338c920d6ba4e479f /frame/contracts/src/wasm/runtime.rs#L366-L368). But in fact there are two situations here:- An error occurred in
ink!
: According to the implementation ofink!
, before calling the functions wrapped by the contract#[ink(message)]
and#[ink(constructor)]
, the input The process of decoding and matchingselector
. If an error occurs during this process, the contract will return error codeDispatchError
. But for the Wasm executor, the Wasm code is executed normally, so the result will be returned, including this error code. This contract execution process is an error situation. - The return value of
#[ink(message)]
is defined as()
: According to the implementation ofink!
, if the return value type is()
,seal_reason
will not be called, so it will not Containstrap_reason
. This contract execution process is an correct situation.
Since
ink!
is only a contract implementation that runs onPallet Contracts
, other implementations may have different rules, so currentlysandbox_result_ok
is only used to assist in determining the execution of theink!
contract, the value isReturnValue
. Among them, if the<num>
part ofReturnValue::Value(<num>)
of the log is not 0, it means that there may be an error in the execution ofink!
. You can useink!
forDispatchError
The error code determines the error.- An error occurred in
wasm_error
: indicates the backtrace when Wasm executes an error. This part will be printed only whenext_result
isfailed
.In the above example, because the execution of
transfer
will triggerpanic
, you can see that the cause of the error here isWasmiExecution(Trap(Trap {kind: Unreachable }))
, indicating that this time the failure is due to execution The situation ofUnreacble
in the contract process is caused, and the backtrace information below also very accurately describes the function execution call stack when an error is encountered after the expansion of the contract macro discussed above. The following calling process can be clearly found from the backtrace.call -> dispatch_using_mode -> ... -> transfer -> panic
This process is consistent with the original information of the contract.
ContractTrap
caused by locating duplicate topics#
Case 2:Some time ago, we (Patract Labs) reported a bug to ink!
, see issue:"When set '0' value in contracts event, may cause Error::ContractTrapped
and panic in contract #589" . It is very difficult to locate this error before Europa has developed the relevant function. Thank you @athei located the error. Here we reproduce this error and use Europa's log to quickly analyze and locate the place where the bug appears:
checkout
ink!
to commit8e8fe09565ca6d2fad7701d68ff13f12deda7eed
cd inkgit checkout 8e8fe09565ca6d2fad7701d68ff13f12deda7eed -b tmp
Go in
ink/examples/erc20/lib.rs:L90
to changevalue
to0_u128
inTransfer
#[ink(constructor)]pub fn new(initial_supply: Balance) -> Self { //... Self::env().emit_event(Transfer { from: None, to: Some(caller), // change this from `initial_supply` to `0_u128` value: 0_u128.into() // initial_supply, }); instance}
Execute
cargo +nightly contract build --debug
to compile the contractUse RedSpot or
Polkadot/Substrate Portal
to deploy this contract ( Note that you must use the erc20.src.wasm file)
You should encounter DuplicateTopics
in the deployment phase (before this bug is corrected, the reported error is ContractTrap
), and in the Europa log Will show:
1: NestedRuntime { #... env_trace: [ seal_input(Some(0xd183512b0)), #... seal_deposit_event((Some([0x45726332303a3a5472616e736....]), None)), ], trap_reason: TrapReason::SupervisorError(DispatchError::Module { index: 5, error: 23, message: Some("DuplicateTopics") }), wasm_error: Error::WasmiExecution(Trap(Trap { kind: Host(DummyHostError) })) wasm backtrace: | ink_env::engine::on_chain::ext::deposit_event[1623] | ink_env::engine::on_chain::impls::<impl ink_env::backend::TypedEnvBackend for ink_env::engine::on_chain::EnvInstance>::emit_event[1564] | ink_env::api::emit_event::{{closure}}[1563] | <ink_env::engine::on_chain::EnvInstance as ink_env::engine::OnInstance>::on_instance[1562] | ink_env::api::emit_event[1561] | erc20::erc20::_::<impl ink_lang::events::EmitEvent<erc20::erc20::Erc20> for ink_lang::env_access::EnvAccess<<erc20::erc20::Erc20 as ink_lang::env_access::ContractEnv>::Env>>::emit_event[1685]# ...# ... | deploy[1691] ╰─><unknown>[2385] , nest: [],}
You can see from the above log:
- The last record of
env_trace
isseal_deposit_event
instead ofseal_return
(when the contract is executed correctly, the last record must beseal_return
) - The second parameter of
seal_deposit_event
isNone
instead of an existing value, which indicates that the host_function ofseal_deposit_event
has not been executed, but an error occurred during the execution (see the forked dependency of Europa) See the [corresponding implementation] (https://github.com/patractlabs/substrate/blob/3624deb47cabe6f6cd44ec2c49c6ae5a29fd2198/frame/contracts/src/wasm/runtime.rs#L1399) for the source code of the version ofPallet Contracts
. - Combined with the error stack of wasm backtrace, we can intuitively see that the top call stack of backtrace is
deposit_event
.
Therefore, combining the above information, we can directly infer that the host_function of seal_deposit_event
has an exception during the execution. (Before the submission of Pallet Contracts
pull#7762, we recorded the error message in host_function. After the merge, we used trap_reason
unified error message.)
type Balance=u64
instead of type Balance=u128
#
Case 3: When error is caused by the chain using If the chain uses the definition of Balance=u64
, and the definition of Balance
in the chain is unknown to ink!
(the default definition of Balance is u128
). Therefore, when using u128
to define Balance
's ink!
as a dependency compiled contract, when running on a chain where Balance
is defined as u64
, it will cause the Pallet Contracts
module to transfer values to the contract , The contract internally regards the value
of u64
as a decoding error of u128
.
Take the example contract of erc20 as an example, after expanding the macro of the contract, you can see:
- When there is an error in the
dispatch_using_mode
stage of decodinginput
, the contract returns with::ink_lang::DispatchError::CouldNotReadInput
, but the model design ofPallet Contracts
believes that the Wasm contract execution is not abnormal. - In the call of
call
, sincedeny_payment
is checked before callingdispatch_using_mode
, and if an Error is returned when checkingdeny_payment
, it will be directlypanic
.
Therefore, in this case, the contract for deploying (Instantiate
) ERC20 will execute normally, and any method of ERC20 such as transfer
will be called with ContractTrap
.
Let's look at these two situations separately:
instantiate
stage:1: NestedRuntime { ext_result: [success] ExecError { error: DispatchError::Module {index:5, error:17, message: Some("ContractTrapped"), orign: ErrorOrigin::Caller }}#... env_trace: [ seal_input(Some(0xd183512b008cb6611e0100000000000000000000)), seal_caller(Some(0xd43593c715fdd31c61141abd04a99fd682)), //... seal_set_storage((Some(0x030000000100000...), Some(0x000000000000000...))), ], sandbox_result_ok: RuntimeValue::Value(7), nest: [],}
From the above log, we can see:
The end of
env_trace
does not end withseal_return
, it means that the contract has not been executed normally. Because it can be seen from the design ofink!
that if you enter#[ink(constructor)]
normally or enter#[ink(message)]
, then must be executed to::ink_lang::execute_message
(::ink_lang::execute_message
will callseal_return
), and the absence ofseal_return
means that the execution has not reached the stage ofexecute
.sandbox_result_ok
indicates that the return value of the execution is7
. By queryingink!
for the implementation ofDispatchError
, you can see that this error code representsCouldNotReadInput
DispatchError::CouldNotReadInput => Self(0x07),
According to the expanded code of the contract macro, you can see that in the
dispatch_using_mode
function,::ink_env::decode_input
is called before callingexecute
, and this function has areturn Error
situation. Therefore, it is reasonable to guess that an exception occurred when parsinginput
. The input parameterargs:0x008cb6611e0100000000000000000000
is recorded in the log. Observing this parameter, it can be found that its length is significantly smaller than theu128
code. Therefore, it can be inferred fromargs
andenv_trace
that an error occurred when decodinginput
.// this part code is expanded by erc20 example.::ink_env::decode_input::<<Erc20 as ::ink_lang::ConstructorDispatcher>::Type>().map_err(|_| ::ink_lang::DispatchError::CouldNotReadInput)?
At this point, the contract instantiation is successful, but the constructor to execute the instantiation exists. Therefore, the contract exists on the chain but the process of #[ink(constructor)]
is not executed normally.
The
call
stage, such as callingtransfer
:Calling
transfer
to the above successfully instantiated function,ContractTrap
will appear, Europa's log shows as follows:1: NestedRuntime { ext_result: [failed] ExecError { error: DispatchError::Module {index:5, error:17, message: Some("ContractTrapped"), orign: ErrorOrigin::Caller }}# ... env_trace: [ seal_value_transferred(Some(0x0000000000000000)), ], wasm_error: Error::WasmiExecution(Trap(Trap { kind: Unreachable })) wasm backtrace: | core::panicking::panic_fmt.60[1743] | core::result::unwrap_failed[914] | core::result::Result<T,E>::expect[915] | ink_lang::dispatcher::deny_payment[1664] | call[1691] ╰─><unknown>[2387] , nest: [],}
First notice that the last record of
env_trace
is still notseal_return
, and the error cause ofwasm_error
isWasmiExecution::Unreachable
. Therefore, it can be determined thatpanic
orexpect
was encountered during the execution of the contract.From the wasm backtrace, it is very obvious that the execution process is
call -> deny_payment -> expect
According to the code expanded macro (cd ink/examples/erc20; cargo expand> tmp.rs
), we can see:
#[no_mangle]fn call() -> u32 { if true { ::ink_lang::deny_payment::<<Erc20 as ::ink_lang::ContractEnv>::Env>() .expect("caller transferred value even though all ink! message deny payments") } ::ink_lang::DispatchRetCode::from( <Erc20 as ::ink_lang::DispatchUsingMode>::dispatch_using_mode( ::ink_lang::DispatchMode::Call, ), ) .to_u32()}
Therefore, it can be judged that an error was returned in deny_payment
during the execution of the contract in the process of transfer
, and the direct processing of the error as expect
resulted in the execution result of wasmi
being Unreachable
Tracking the code of deny_payment
can find that the function returns expect
caused by Error
Note,The relevant code is as follows:
In
ink_lang
https://github.com/paritytech/ink/blob/master/crates/lang/src/dispatcher.rs#L140-L150pub fn deny_payment<E>() -> Result<()>where E: Environment,{ let transferred = ink_env::transferred_balance::<E>() .expect("encountered error while querying transferred balance"); if transferred != <E as Environment>::Balance::from(0u32) { return Err(DispatchError::PaidUnpayableMessage) } Ok(())}
There will be a difference between the
off_chain
part and theon_chain
part in the ink,off_chain
will think that an error is returned at the stage ofink_env::transferred_balance::<E>()
, so it is executingAfter transferred_balance
, you will encounterexpect
which leads topanic
, and part ofon_chain
is taken from the memory of wasm, it will normally get the characters corresponding to u128 length and decode to gettransferred
, which is just decoded The result will not meet expectations, causingtransferred!=0
to makedeny_payment
return an Error, and the part wheredeny_payment
is called in the macro expansion of the contract triggersexpect
if true { ::ink_lang::deny_payment::<<Erc20 as ::ink_lang::ContractEnv>::Env>() .expect("caller transferred value even though all ink! message deny payments")}
Therefore, for wasm backtrace,
expect
appears whendeny_payment
is called incall
, not whentransferred_balance
is called indeny_payment
.This example side shows that
ink!
currently does not completely correspond to the processing ofoff_chain
andon_chain
, and may cause difficult-to-check errors for contract users in some cases#
Verify v0.2
Construct incorrect contracts and execute logs printing to determine whether it meets expectationsDisplay the call statistics of thedefine_env!
interface during contract executionrun test case
instantiate_return_code
in patractlabs/substrate branch:europa-contracts$ cd europa/vendor/substrate/frame/contracts$ cargo test --package pallet-contracts --lib tests::instantiate_return_code -- --exact# then you could see1: NestedRuntime { caller: 0101010101010101010101010101010101010101010101010101010101010101 (5C62Ck4U...),# ...} 1: NestedRuntime {# ...} 1: NestedRuntime {# ...}# ...
run test case
run_out_of_gas
in patractlabs/substrate branch:europa-contracts$ cd europa/vendor/substrate/frame/contracts$ cargo test --package pallet-contracts --lib tests::run_out_of_gas -- --exact1: NestedRuntime {# ...} 1: NestedRuntime {#... gas(None), ], trap_reason: TrapReason::SupervisorError(DispatchError::Module { index: 0, error: 6, message: Some("OutOfGas") }), nest: [],}
Anyone can check whether the printed log matching with the test case.
Execute the log printing function, provide formatted printing examples of different data, and judge whether it meets expectationsUsing
ink-log
inink!
example could test this part.Construct a contract that crashes under different conditions and record the log after execution. Then judge whether the backtrace information of the contract execution is completely printed, and check whether it matches the actual execution of the collapsed contract.We provide a test case repo europa_contracts_test_templates. Any one could using Polkadot/Substrate Portal or RedSpot to deploy and call this test contract to verify this.