Six weeks ago, Patract Hub (https://patract.io) applied a [Treasury Proposal #27](https://polkadot.polkassembly.io/treasury/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](https://github.com/paritytech/substrate/tree/master/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 plan * v0.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.Design In 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 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. * Modification on the `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. * Contract logging function: Use the function of `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](https://webassembly.github.io/spec/core/exec/runtime.html#function-instances) 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. ### 1.1 on `Pallet Contracts` layer During the contract debugging process, Europa believes that developers need: 1. 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. 2. 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 information **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` ```rust 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 in`wasmi`. **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 debugging The Europa forked version of `Pallet Contracts` has designed an object to record any information that can help debugging during contract execution: ```rust /// 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, /// Who call the current contract caller: AccountId32, /// The account of the current contract self_account: Option, /// The input selector selector: Option, /// The input arguments args: Option, /// 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, /// The trap in host function execution trap_reason: Option, /// Nested contract execution context nest: Vec, } ``` 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: 1. help to locate where the error occurs, including the following situations: 1. `Pallet Contracts` layer 2. `ink!` layer 3. The specific position in the contract layer 4. Locate which level of the contract is when a contract calling another contract 2. Analyze the information during the execution of the contract at this timing: 1. Analyze the consumption of gas execution 2. Analyze the call of `get_storage` and `set_storage`, help reconstruct the contract code and analyze the demand of `rent` 3. According to `selector`, `args` and `value`, analyze and locate whether the transaction parameters of the third-party SDK are legal. 4. Analyze the execution path of the contract and adjust the contract based on the `nest` information and combined with the `seal_call` information. 5. 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: ```rust pub struct SealCall { callee: Option, gas: u64, value: Option, input: Option, output: Option, } ``` 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. ### 1.2 on `wasmi` layer 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: 1. The "name section" section is required in the WASM source file (see [the specification of name section)](https://webassembly.github.io/spec/core/appendix/custom.html#name-section)) 2. 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. 3. 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 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`. #### 1.2.1 Submitted WASM files contains debug info from "name section" - PR: [paritytech/cargo-contract#131](https://github.com/paritytech/cargo-contract/pull/131) - Source: [patractlabs/cargo-contract](https://github.com/patractlabs/cargo-contract) 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](https://github.com/patractlabs/cargo-contract) trims debug info while building contracts, we can get them back with the following steps. ##### 1. Keep name section from striping The name section has been striped at [cargo-contract/cmd/build.rs#L247](https://github.com/paritytech/cargo-contract/blob/71525f9ec5f21e6113a614c2fb4d1eb5e62ebf8b/src/cmd/build.rs#L247). ##### 2. Keep debug info from `wasm-opt` `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](https://github.com/paritytech/cargo-contract/blob/71525f9ec5f21e6113a614c2fb4d1eb5e62ebf8b/src/cmd/build.rs#L267). ##### 3. Keep debug info from `rustc` `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](https://github.com/paritytech/cargo-contract/blob/71525f9ec5f21e6113a614c2fb4d1eb5e62ebf8b/src/cmd/build.rs#L137). #### 1.2.2 Save debug info from the scraper of `Pallet Contracts` 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 module - PR: https://github.com/paritytech/parity-wasm/pull/300 `Pallet 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 meter - PR: [paritytech/wasm-utils#146](https://github.com/paritytech/wasm-utils/pull/146) - Source: [patractlabs/wasm-utils#146](https://github.com/patractlabs/wasm-utils) `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](https://github.com/paritytech/wasm-utils/blob/d9432bafa9321f8e0e5b8a143f1ed858dbbbe272/src/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](https://github.com/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. ##### Add function info field to `FuncRef` `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](https://github.com/patractlabs/wasmi/blob/v0.6.2/src/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 modules 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](https://github.com/patractlabs/wasmi/blob/7a6feaea70f47aa6e62f097fb0d9a4ea0ce7d1fc/src/runner.rs#L1491). ``` //! 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, "".to_string()); } } // ... ``` ##### Make the interpreter support `trace` 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](https://github.com/patractlabs/wasmi/blob/7a6feaea70f47aa6e62f097fb0d9a4ea0ce7d1fc/src/runner.rs#L1491). ``` //! wasmi/src/runner.rs#L1491 /// Get the functions of current the stack pub fn trace(&self) -> Vec> { self.buf.iter().map(|f| f.info()).collect::>() } ``` ##### Gather debug infos when program breaks Just gather backtraces when we invoke function failed, source at [wasmi/func.rs#L170](https://github.com/patractlabs/wasmi/blob/7a6feaea70f47aa6e62f097fb0d9a4ea0ce7d1fc/src/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 { "".to_string() } }) .collect::>(); // 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)) // ... ``` ### 1.3 Contract Log functions 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 : 1. All the logs of `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. 2. The contract developer wrote `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](https://github.com/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: 1. `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`: ```cargo [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: ```rust 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`： ```rust [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： ```rust pub struct CustomExt; impl ChainExtension for CustomExt { fn call(func_id: u32, env: Environment) -> Result where ::AccountId: UncheckedFrom<::Hash> + AsRef<[u8]>, { match func_id { ... => {/* other ChainExtension */ } 0xfeffff00 => { // TODO add other libs runtime_log::logger_ext!(func_id, env); // or use // LoggerExt::call::(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 Build For contract developers, it is necessary to prepare `Europa` and `cargo-contract` tools. #### 2.1.1 Europa The building process for this project is as same as [Substrate](https://github.com/paritytech/substrate/). When building finished, current executable file in `target` directory is named `Europa`. ```bash git clone --recurse-submodules https://github.com/patractlabs/Europa.git ``` #### 2.1.2 Cargo-contract 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](https://github.com/paritytech/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]](https://github.com/paritytech/cargo-contract/pull/131) provides this feature. Before this PR is merged, currently only the `cargo-contract` version provided by us (Patract Labs) can be used: ```bash 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: ```bash git clone https://github.com/patractlabs/cargo-contract --branch cmd/debug cd cargo-contract cargo build --release ``` > Note: Executing the `cargo-contract build` command requires the `default toolchain` of the rust build chain to be `nightly`, otherwise you can only use `cargo +nightly contract build`, but using `cargo` to call `cargo-contract` needs to be executed `cargo install` installs or overwrites the compiled product to the `~/.cargo/bin` directory, and cannot coexist with paritytech's `cargo-contract` Execute: ```bash cargo-contract build --help # or cargo +nightly contract build --help ``` If you can see: ```bash 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. ** ### 2.2 Example 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: ```bash $ 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](https://github.com/patractlabs/europa) or Europa v0.1's [Report](https://polkadot.polkassembly.io/post/ 166), you can get more command introduction. #### 2.2.1 Case 1：Simple case For example, we modify the example contract `ink/example/erc20` in the [ink!](https://github.com/paritytech/ink) project as follows: ```rust #[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: ```bash 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: ```bash fn call() -> u32 -> ::dispatch_using_mode(...) -> <::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: ```bash $ Europa --tmp -lruntime=debug ``` Then we deploy this erc20 and call transfer to execute. We can use [`Polkadot/Substrate Portal`](https://polkadot.js.org/apps) or use [RedSpot](https://redspot.patract.io/en/tutorial/) 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: ```bash $ 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: ```bash 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::_::::transfer[1697] | as ink_lang::traits::MessageMut>::CALLABLE::{{closure}}[611] | core::ops::function::FnOnce::call_once[610] | ::execute::{{closure}}[1675] | ink_lang::dispatcher::execute_message_mut[1674] | ::execute[1692] | erc20::erc20::_::::dispatch_using_mode[1690] | call[1691] ╰─>[2387] , nest: [], } ``` Let us explain the information printed above: 1. `ext_result`: indicates that this contract call is displayed as successful or failed: 1. `[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. 2. `[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`. 2. `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: 1. After A calls B, it returns to A to continue execution, and then calls contract C ```text |A| | |->|B| | |<- | |->|C| | |<- ``` Then it will produce a log print similar to the following: ```text 1: NestedRuntime { self_account: A, nest:[ 2: NestedRuntime { self_account: B, nest:[], }, 2: NestedRuntime { self_account: C, nest:[], } ] } ``` 2. After A calls B, B calls contract C again, and finally returns to A ```text |A| | |->|B| | | | |->|C| | | | |<- | |<- ``` Then it will produce a log print similar to the following: ```text 1: NestedRuntime { self_account: A, nest:[ 2: NestedRuntime { self_account: B, nest:[ 3: NestedRuntime { self_account: C, nest:[], } ], } ] } ``` 3. `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. 4. `self_account`: represents the address of the current contract itself. 5. `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**. 6. `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. 7. `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](https://github.com/paritytech/substrate/blob/master/frame/contracts/src/wasm/runtime.rs#L610 ) 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. 8. `trap_reason`: According to the definition of `TrapReason` in `Pallet Contracts`, `trap_reason` can be divided into 2 categories: 1. `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. 2. `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`. ** 9. `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`](https://github.com/paritytech/substrate/blob/712085115cdef4a79a66747338c920d6ba4e479f/frame/contracts/src/wasm/mod.rs#L155-L156) 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: 1. An error occurred in `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`](https://github.com/paritytech/ink/blob/abd5cf14c0883cb2d5acf81f2277aeec330aa843/crates/lang/src/error.rs#L22). 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. ** 2. The return value of `#[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`](https://github.com/paritytech/substrate/blob/712085115cdef4a79a66747338c920d6ba4e479f/primitives/wasm-interface/src/lib.rs#L462-L467). Among them, if the `` part of `ReturnValue::Value()` 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](https://github.com/paritytech/ink/blob/abd5cf14c0883cb2d5acf81f2277aeec330aa843/crates/lang/src/error.rs#L66-L80) determines the error. 10. `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. ```text call -> dispatch_using_mode -> ... -> transfer -> panic ``` This process is consistent with the original information of the contract. #### 2.2.2 Case 2：`ContractTrap` caused by locating duplicate topics 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" ](https://github.com/paritytech/ink/issues/589). It is very difficult to locate this error before Europa has developed the relevant function. Thank you @athei [located the error](https://github.com/paritytech/ink/issues/589#issuecomment-731571918). Here we reproduce this error and use Europa's log to quickly analyze and locate the place where the bug appears: 1. checkout `ink!` to commit `8e8fe09565ca6d2fad7701d68ff13f12deda7eed` ```bash cd ink git checkout 8e8fe09565ca6d2fad7701d68ff13f12deda7eed -b tmp ``` 2. Go in `ink/examples/erc20/lib.rs:L90` to change `value` to `0_u128` in `Transfer` ```rust #[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 } ``` 3. Execute `cargo +nightly contract build --debug` to compile the contract 4. Use [RedSpot](https://redspot.patract.io/en/tutorial/) or [`Polkadot/Substrate Portal`](https://polkadot.js.org/apps) 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](https://github.com/paritytech/substrate/pull/7762) is corrected, the reported error is `ContractTrap`), and in the Europa log Will show: ```bash 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::::emit_event[1564] | ink_env::api::emit_event::{{closure}}[1563] | ::on_instance[1562] | ink_env::api::emit_event[1561] | erc20::erc20::_:: for ink_lang::env_access::EnvAccess<::Env>>::emit_event[1685] # ... # ... | deploy[1691] ╰─>[2385] , nest: [], } ``` You can see from the above log: 1. The last record of `env_trace` is `seal_deposit_event` instead of `seal_return` (when the contract is executed correctly, the last record must be `seal_return`) 2. The second parameter of `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`. 3. 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](https://github.com/paritytech/substrate/pull/7762), we recorded the error message in host_function. After the merge, we used `trap_reason` unified error message.) #### 2.2.3 Case 3: When error is caused by the chain using `type Balance=u64` instead of `type Balance=u128` 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 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. * In the call of `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: 1. `instantiate` stage： ```bash 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: 1. 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`. 2. `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` ```rust DispatchError::CouldNotReadInput => Self(0x07), ``` 3. 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`. ```rust // this part code is expanded by erc20 example. ::ink_env::decode_input::<::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. 2. The `call` stage, such as calling `transfer`: Calling `transfer` to the above successfully instantiated function, `ContractTrap` will appear, Europa's log shows as follows: ```bash 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::expect[915] | ink_lang::dispatcher::deny_payment[1664] | call[1691] ╰─>[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 ```bash call -> deny_payment -> expect ``` According to the code expanded macro (`cd ink/examples/erc20; cargo expand> tmp.rs`), we can see: ```bash #[no_mangle] fn call() -> u32 { if true { ::ink_lang::deny_payment::<::Env>() .expect("caller transferred value even though all ink! message deny payments") } ::ink_lang::DispatchRetCode::from( ::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-L150 > > ```rust > pub fn deny_payment() -> Result<()> > where > E: Environment, > { > let transferred = ink_env::transferred_balance::() > .expect("encountered error while querying transferred balance"); > if transferred != ::Balance::from(0u32) { > return Err(DispatchError::PaidUnpayableMessage) > } > Ok(()) > } > ``` > > **There will be a difference between the `off_chain` part and the `on_chain` part in the ink**, `off_chain` will think that an error is returned at the stage of `ink_env::transferred_balance::()`, so it is executing` After transferred_balance`, you will encounter `expect` which leads to `panic`, and part of `on_chain` is taken from the memory of wasm, it will normally get the characters corresponding to u128 length and decode to get `transferred`, which is just decoded The result will not meet expectations, causing `transferred!=0` to make `deny_payment` return an Error, and the part where `deny_payment` is called in the macro expansion of the contract triggers `expect` > > ```rust > if true { > ::ink_lang::deny_payment::<::Env>() > .expect("caller transferred value even though all ink! message deny payments") > } > ``` > > Therefore, for wasm backtrace, `expect` appears when `deny_payment` is called in `call`, not when `transferred_balance` is called in `deny_payment`. > > **This example side shows that `ink!` currently does not completely correspond to the processing of `off_chain` and `on_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 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](https://github.com/patractlabs/substrate/blob/europa-contracts/frame/contracts/src/tests.rs) ```bash $ 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](https://github.com/patractlabs/substrate/blob/europa-contracts/frame/contracts/src/tests.rs) ```bash $ 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`](https://github.com/patractlabs/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](https://github.com/patractlabs/europa\_contracts\_test\_templates). Any one could using Polkadot/Substrate Portal or RedSpot to deploy and call this test contract to verify this. ## 3. Recap of verification of v0.2 * 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](https://github.com/patractlabs/substrate/blob/europa-contracts/frame/contracts/src/tests.rs) ```bash $ 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](https://github.com/patractlabs/substrate/blob/europa-contracts/frame/contracts/src/tests.rs) ```bash $ 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`](https://github.com/patractlabs/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](https://github.com/patractlabs/europa\_contracts\_test\_templates). Any one could using Polkadot/Substrate Portal or RedSpot to deploy and call this test contract to verify this.