Six 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).
- 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.
In 0.2, the debugging information function of the upgrade contract module is divided into three parts of modification:
Pallet Contracts layer: By adding trace during the execution of the contract by Pallet 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.wasmi layer: We have provided the backtrace function of recording wasm execution for wasmi, and provided support for parity-wasm, pwasm-utils, and cargo-contract during wasm processing of the contract contains the function of the name section.ChainExtensions to realize the library for printing the log 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 layerDuring the contract debugging process, Europa believes that developers need:
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.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.
The 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 save 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:
Pallet Contracts layerink! layerget_storage and set_storage, help reconstruct the contract code and analyze the demand of rentselector, args and value, analyze and locate whether the transaction parameters of the third-party SDK are legal.nest information and combined with the seal_call information.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 layerWe 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:
Pallet Contracts and still have a corresponding relationship with the wasm source file after the process.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 the wasmi 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.
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.
The name section has been striped at cargo-contract/cmd/build.rs#L247.
wasm-optcargo-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.
rustccargo-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 ContractsWhat happends to the Pallet Contracts while we calling a contract?
sp-sandbox and execute itsp-sandbox and return the result to usPallet Contracts builds WASM modules from storage and drops custom sections by default, here we should get them back.
Pallet 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.
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:
FuncRefFuncRef 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)>,
}
We 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());
}
}
// ...
traceHowever, 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 stack
pub fn trace(&self) -> Vec<Option<&(usize, String)>> {
self.buf.iter().map(|f| f.info()).collect::<Vec<_>>()
}
Just 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 trap
stack.append(&mut trap.wasm_trace().clone());
stack.reverse();
// Embed this info into the trap
Err(trap.set_wasm_trace(stack))
// ...
In 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 :
seal_println printed on the node side are target: runtime and level DEBUG, but when developing complex contracts, a lot of logs will be printed. If you cannot filter by target and log level, then the development process will be full of interference from irrelevant information.seal_println when needed during the development process, but all seal_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 the ink-log/contracts directory, provide info!, debug!, warn!, error!, trace!, same as Rust's log library in the same macro, and the call method of the macro is also the same. These macros are packaged implementations of seal_chain_extensions on the ink! side, and are tool library for contract developers. For example, after this library is introduced in the contract Cargo.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.
For contract developers, it is necessary to prepare Europa and cargo-contract tools.
The 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
If 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 cover the version released by paritytech, then it is recommended to compile locally and use the compiled product cargo-contract directly:
git clone https://github.com/patractlabs/cargo-contract --branch cmd/debug
cd cargo-contract
cargo build --release
Note: Executing the
cargo-contract buildcommand requires thedefault toolchainof the rust build chain to benightly, otherwise you can only usecargo +nightly contract build, but usingcargoto callcargo-contractneeds to be executedcargo installinstalls or overwrites the compiled product to the~/.cargo/bindirectory, and cannot coexist with paritytech'scargo-contract
Execute:
cargo-contract build --help
# or
cargo +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. **
We 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.
For 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 expand
cd ink/example/erc20
cargo 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 console
Welcome 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 in ink! or the business logic of the contract itself, as in case 3 in the following text.) And the ExecResultValue {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 the ExecError {.. } followed by [failed] indicates the cause of this error. The reason for this is the value recorded in event on the chain, which is the value defined in decl_error! of Pallet 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 the nest field. 2: NestedRuntime and 1: 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 several NestedRuntime in the array of nest. 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 the selector 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 the gas_limit passed in when the contract is currently called and the remaining gas after executing this layer. Note here that gas_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 through gas_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 in define_env! in the Pallet Contracts module are related, so tracing env_trace can trace the process of interacting with Pallet 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 which seal_call appears in env_trace, it can correspond to nest 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 by **seal_set_storage can also be used to infer the storage size required by rent. **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 the host_function.On the other hand, the statistics of env_trace are relatively fine-grained. For example, if there are multiple possible errors in host_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 of host_function.
And if there is an error in host_function that causes the contract to end execution, env_trace records the last error host_function call, so you can directly locate which host_function caused the contract execution exception.
trap_reason: According to the definition of TrapReason in Pallet Contracts, trap_reason can be divided into 2 categories:
Return & Termination & Restoration: indicates that the contract exit is the design of Pallet 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 of Pallet Contracts and ink!, there is a case where the successful execution of the contract or the execution failure in the ink! layer does not generate trap_reason. Therefore, in addition to recording trap_reason, Europa also **records the results returned by the WASM executor after execution, which is recorded with sandbox_result_ok. **
sandbox_result_ok: The value of sandbox_result_ok represents the result of the contract after the WASM executor is executed. This value could have been recorded as sandbox_result, including correct and incorrect conditions. However, due to the limitations of Rust and combined with the business logic of Pallet Contracts, only the result of sandbox_result is kept as Ok here. **For log printing, Europa is designed to print sandbox_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 calling invoke After the processing of to_execution_result, if there is no trap_reason, the result of Ok(..) [discarded](https://github.com/paritytech/substrate/blob/712085115cdef4a79a66747338c920d6ba4e479f /frame/contracts/src/wasm/runtime.rs#L366-L368). But in fact there are two situations here:
ink!: According to the implementation of ink!, before calling the functions wrapped by the contract #[ink(message)] and #[ink(constructor)], the input The process of decoding and matching selector. If an error occurs during this process, the contract will return error code DispatchError. 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. **#[ink(message)] is defined as (): According to the implementation of ink!, if the return value type is (), seal_reason will not be called, so it will not Contains trap_reason. **This contract execution process is an correct situation. **Since ink! is only a contract implementation that runs on Pallet Contracts, other implementations may have different rules, so currently sandbox_result_ok is only used to assist in determining the execution of the ink! contract, the value is ReturnValue. Among them, if the <num> part of ReturnValue::Value(<num>) of the log is not 0, it means that there may be an error in the execution of ink!. You can use ink! for DispatchError The error code determines the error.
wasm_error: indicates the backtrace when WASM executes an error. This part will be printed only when ext_result is failed.
In the above example, because the execution of transfer will trigger panic, you can see that the cause of the error here is WasmiExecution(Trap(Trap {kind: Unreachable })), indicating that this time the failure is due to execution The situation of Unreacble 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 topicsSome 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 commit 8e8fe09565ca6d2fad7701d68ff13f12deda7eed
cd ink
git checkout 8e8fe09565ca6d2fad7701d68ff13f12deda7eed -b tmp
Go in ink/examples/erc20/lib.rs:L90 to change value to 0_u128 in Transfer
#[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 contract
Use 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:
env_trace is seal_deposit_event instead of seal_return (when the contract is executed correctly, the last record must be seal_return)seal_deposit_event is None instead of an existing value, which indicates that the host_function of seal_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 of Pallet Contracts.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 Contractspull#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=u128If 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:
dispatch_using_mode stage of decoding input, the contract returns with ::ink_lang::DispatchError::CouldNotReadInput, but the model design of Pallet Contracts believes that the WASM contract execution is not abnormal.call, since deny_payment is checked before calling dispatch_using_mode, and if an Error is returned when checking deny_payment, it will be directly panic.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 with seal_return, it means that the contract has not been executed normally. Because it can be seen from the design of ink! 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 call seal_return), and the absence of seal_return means that the execution has not reached the stage of execute.
sandbox_result_ok indicates that the return value of the execution is 7. By querying ink! for the implementation of DispatchError, you can see that this error code represents CouldNotReadInput
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 calling execute, and this function has a return Error situation. Therefore, it is reasonable to guess that an exception occurred when parsing input. The input parameter args:0x008cb6611e0100000000000000000000 is recorded in the log. Observing this parameter, it can be found that its length is significantly smaller than the u128 code. Therefore, it can be inferred from args and env_trace that an error occurred when decoding input.
// 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 calling transfer:
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 not seal_return, and the error cause of wasm_error is WasmiExecution::Unreachable. Therefore, it can be determined that panic or expect 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_langhttps://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_chainpart and theon_chainpart in the ink,off_chainwill think that an error is returned at the stage ofink_env::transferred_balance::<E>(), so it is executingAfter transferred_balance, you will encounterexpectwhich leads topanic, and part ofon_chainis 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!=0to makedeny_paymentreturn an Error, and the part wheredeny_paymentis called in the macro expansion of the contract triggersexpectif 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,
expectappears whendeny_paymentis called incall, not whentransferred_balanceis called indeny_payment.This example side shows that
ink!currently does not completely correspond to the processing ofoff_chainandon_chain, and may cause difficult-to-check errors for contract users in some cases
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
run 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 see
1: 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 -- --exact
1: 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 expectations
Using ink-log in ink! 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.
Modify at FRAME Contracts pallet level to provide more information.*
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
run 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 see
1: 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 -- --exact
1: 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 expectations
Using ink-log in ink! 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.