Cross-contract call tracing (#45)

Cargo.toml

@@ -9,6 +9,7 @@ members = [
 exclude = [
     "examples/counter",
     "examples/flipper",
+    "examples/cross-contract-call-tracing",
 ]
 
 [workspace.package]
@@ -37,10 +38,12 @@ wat = { version = "1.0.71" }
 frame-support = { version = "22.0.0" }
 frame-system = { version = "22.0.0" }
 pallet-balances = { version = "22.0.0" }
-pallet-contracts = { package = "pallet-contracts-for-drink", version = "21.0.1" }
+pallet-contracts = { package = "pallet-contracts-for-drink", version = "21.0.3" }
 pallet-contracts-primitives = { version = "25.0.0" }
 pallet-timestamp = { version = "21.0.0" }
 sp-core = { version = "22.0.0" }
+sp-externalities = { version = "0.20.0" }
+sp-runtime-interface = { version = "18.0.0" }
 
 # Local dependencies
 

drink/Cargo.toml

@@ -18,11 +18,17 @@ pallet-contracts = { workspace = true }
 pallet-contracts-primitives = { workspace = true }
 pallet-timestamp = { workspace = true }
 parity-scale-codec = { workspace = true }
+sp-externalities = { workspace = true }
+sp-runtime-interface = { workspace = true }
+
 scale-info = { workspace = true }
 thiserror = { workspace = true }
 
 [dev-dependencies]
 wat = { workspace = true }
 
 [features]
+# This is required for the runtime-interface to work properly in the std env.
+default = ["std"]
 session = ["contract-transcode"]
+std = []

drink/src/lib.rs

@@ -16,6 +16,8 @@ use frame_support::{sp_io::TestExternalities, sp_runtime::BuildStorage};
 pub use frame_support::{sp_runtime::AccountId32, weights::Weight};
 use frame_system::{EventRecord, GenesisConfig};
 
+use crate::pallet_contracts_debugging::DebugExt;
+use crate::runtime::pallet_contracts_debugging::NoopDebugExt;
 use crate::runtime::*;
 
 /// Main result type for the drink crate.
@@ -62,6 +64,17 @@ impl<R: Runtime> Sandbox<R> {
             .execute_with(|| R::initialize_block(1, Default::default()))
             .map_err(Error::BlockInitialize)?;
 
+        // We register a noop debug extension by default.
+        sandbox.override_debug_handle(DebugExt(Box::new(NoopDebugExt {})));
+
         Ok(sandbox)
     }
+
+    /// Overrides the debug extension.
+    ///
+    /// By default, a new `Sandbox` instance is created with a noop debug extension. This method
+    /// allows to override it with a custom debug extension.
+    pub fn override_debug_handle(&mut self, d: DebugExt) {
+        self.externalities.register_extension(d);
+    }
 }

drink/src/runtime/minimal.rs

@@ -1,23 +1,26 @@
 #![allow(missing_docs)] // `construct_macro` doesn't allow doc comments for the runtime type.
 
+use std::time::SystemTime;
+
 use frame_support::{
     parameter_types,
     sp_runtime::{
         testing::H256,
         traits::{BlakeTwo256, Convert, IdentityLookup},
-        AccountId32, BuildStorage,
+        AccountId32, BuildStorage, Storage,
     },
-    traits::{ConstBool, ConstU128, ConstU32, ConstU64, Currency, Randomness},
+    traits::{ConstBool, ConstU128, ConstU32, ConstU64, Currency, Hooks, Randomness},
     weights::Weight,
 };
-use pallet_contracts::{DefaultAddressGenerator, Frame, Schedule};
-
 // Re-export all pallets.
 pub use frame_system;
 pub use pallet_balances;
 pub use pallet_contracts;
+use pallet_contracts::{DefaultAddressGenerator, Frame, Schedule};
 pub use pallet_timestamp;
 
+use crate::{runtime::pallet_contracts_debugging::DrinkDebug, Runtime, DEFAULT_ACTOR};
+
 type Block = frame_system::mocking::MockBlock<MinimalRuntime>;
 
 frame_support::construct_runtime!(
@@ -121,15 +124,9 @@ impl pallet_contracts::Config for MinimalRuntime {
     type MaxDebugBufferLen = ConstU32<{ 2 * 1024 * 1024 }>;
     type Migrations = ();
     type DefaultDepositLimit = DefaultDepositLimit;
-    type Debug = ();
+    type Debug = DrinkDebug;
 }
 
-use std::time::SystemTime;
-
-use frame_support::{sp_runtime::Storage, traits::Hooks};
-
-use crate::{Runtime, DEFAULT_ACTOR};
-
 /// Default initial balance for the default account.
 pub const INITIAL_BALANCE: u128 = 1_000_000_000_000_000;
 

drink/src/runtime/mod.rs

@@ -2,6 +2,7 @@
 //! `drink` with any runtime that implements the `Runtime` trait.
 
 pub mod minimal;
+pub mod pallet_contracts_debugging;
 
 use frame_support::sp_runtime::{AccountId32, Storage};
 pub use minimal::MinimalRuntime;

drink/src/runtime/pallet_contracts_debugging.rs

@@ -0,0 +1,114 @@
+//! This module provides all the necessary elements for supporting contract debugging directly in
+//! the contracts pallet.
+//!
+//! # Smart-contract developer <-> pallet-contracts interaction flow
+//!
+//! The interaction between end-user and runtime is as follows:
+//! 1. At some points during execution, the pallet invokes some callback through its configuration
+//! parameter `Debug`.
+//! 2. In order to forward the callback outside the runtime, `Debug` will call a runtime interface,
+//! that will then forward the call further to the proper runtime extension.
+//! 3. The runtime extension can be fully controlled by the end-user. It just has to be registered
+//! in the runtime.
+//!
+//! So, in brief: pallet-contracts -> runtime interface -> runtime extension
+//!              |<-----------runtime side-------------->|<---user side--->|
+//!
+//! # Passing objects between runtime and runtime extension
+//!
+//! Unfortunately, runtime interface that lies between runtime and the end-user accepts only
+//! very simple argument types and those that implement some specific traits. This means that
+//! usually, complex objects will be passed in their encoded form (`Vec<u8>` obtained with scale
+//! encoding).
+
+use pallet_contracts::debug::{CallSpan, ExportedFunction, Tracing};
+use pallet_contracts_primitives::ExecReturnValue;
+use sp_externalities::{decl_extension, ExternalitiesExt};
+use sp_runtime_interface::runtime_interface;
+
+use crate::runtime::Runtime;
+
+type AccountIdOf<R> = <R as frame_system::Config>::AccountId;
+
+/// The trait that allows injecting custom logic to handle contract debugging directly in the
+/// contracts pallet.
+pub trait DebugExtT {
+    /// Called after a contract call is made.
+    fn after_call(
+        &self,
+        _contract_address: Vec<u8>,
+        _is_call: bool,
+        _input_data: Vec<u8>,
+        _result: Vec<u8>,
+    ) {
+    }
+}
+
+decl_extension! {
+    /// A wrapper type for the `DebugExtT` debug extension.
+    pub struct DebugExt(Box<dyn DebugExtT + Send>);
+}
+
+/// The simplest debug extension - does nothing.
+pub struct NoopDebugExt {}
+impl DebugExtT for NoopDebugExt {}
+
+#[runtime_interface]
+trait ContractCallDebugger {
+    fn after_call(
+        &mut self,
+        contract_address: Vec<u8>,
+        is_call: bool,
+        input_data: Vec<u8>,
+        result: Vec<u8>,
+    ) {
+        self.extension::<DebugExt>()
+            .expect("Failed to find `DebugExt` extension")
+            .after_call(contract_address, is_call, input_data, result);
+    }
+}
+
+/// Configuration parameter for the contracts pallet. Provides all the necessary trait
+/// implementations.
+pub enum DrinkDebug {}
+
+impl<R: Runtime> Tracing<R> for DrinkDebug {
+    type CallSpan = DrinkCallSpan<AccountIdOf<R>>;
+
+    fn new_call_span(
+        contract_address: &AccountIdOf<R>,
+        entry_point: ExportedFunction,
+        input_data: &[u8],
+    ) -> Self::CallSpan {
+        DrinkCallSpan {
+            contract_address: contract_address.clone(),
+            entry_point,
+            input_data: input_data.to_vec(),
+        }
+    }
+}
+
+/// A contract's call span.
+///
+/// It is created just before the call is made and `Self::after_call` is called after the call is
+/// done.
+pub struct DrinkCallSpan<AccountId> {
+    /// The address of the contract that has been called.
+    pub contract_address: AccountId,
+    /// The entry point that has been called (either constructor or call).
+    pub entry_point: ExportedFunction,
+    /// The input data of the call.
+    pub input_data: Vec<u8>,
+}
+
+impl<AccountId: AsRef<[u8]>> CallSpan for DrinkCallSpan<AccountId> {
+    fn after_call(self, output: &ExecReturnValue) {
+        let raw_contract_address: &[u8] = self.contract_address.as_ref();
+        contract_call_debugger::after_call(
+            raw_contract_address.to_vec(),
+            matches!(self.entry_point, ExportedFunction::Call),
+            self.input_data.to_vec(),
+            output.data.clone(),
+        );
+    }
+}

drink/src/session.rs

@@ -9,8 +9,8 @@ use pallet_contracts_primitives::{ContractExecResult, ContractInstantiateResult}
 use thiserror::Error;
 
 use crate::{
-    chain_api::ChainApi, contract_api::ContractApi, runtime::Runtime, AccountId32, EventRecordOf,
-    Sandbox, DEFAULT_ACTOR, DEFAULT_GAS_LIMIT,
+    chain_api::ChainApi, contract_api::ContractApi, pallet_contracts_debugging::DebugExt,
+    runtime::Runtime, AccountId32, EventRecordOf, Sandbox, DEFAULT_ACTOR, DEFAULT_GAS_LIMIT,
 };
 
 const ZERO_TRANSFER: u128 = 0;
@@ -332,4 +332,12 @@ impl<R: Runtime> Session<R> {
     pub fn last_call_return(&self) -> Option<Value> {
         self.call_returns.last().cloned()
     }
+
+    /// Overrides the debug extension.
+    ///
+    /// By default, a new `Session` instance will use a noop debug extension. This method allows to
+    /// override it with a custom debug extension.
+    pub fn override_debug_handle(&mut self, d: DebugExt) {
+        self.sandbox.override_debug_handle(d);
+    }
 }

examples/cross-contract-call-tracing/Cargo.toml

@@ -0,0 +1,28 @@
+[package]
+name = "cross-contract-call-tracing"
+authors = ["Cardinal"]
+edition = "2021"
+homepage = "https://alephzero.org"
+repository = "https://github.com/Cardinal-Cryptography/drink"
+version = "0.1.0"
+
+[dependencies]
+ink = { version = "=4.2.1", default-features = false }
+
+scale = { package = "parity-scale-codec", version = "3", default-features = false, features = ["derive"] }
+scale-info = { version = "2.6", default-features = false, features = ["derive"], optional = true }
+
+[dev-dependencies]
+drink = { path = "../../drink", features = ["session"] }
+
+[lib]
+path = "lib.rs"
+
+[features]
+default = ["std"]
+std = [
+    "ink/std",
+    "scale/std",
+    "scale-info/std",
+]
+ink-as-dependency = []

examples/cross-contract-call-tracing/README.md

@@ -0,0 +1,60 @@
+# Cross contract call tracing
+
+This example shows how you can trace and debug cross contract calls.
+
+## Scenario
+
+Here we have a single contract with 3 methods:
+ - `call_inner(arg: u32)`: returns the result of some simple computation on `arg`
+ - `call_middle(next_callee: AccountId, arg: u32)`: calls `call_inner(arg)` at `next_callee` and forwards the result
+ - `call_outer(next_callee: AccountId, next_next_callee: AccountId, arg: u32)`: calls `call_middle(next_next_callee, arg)` at `next_callee` and forwards the result
+
+We deploy three instances of this contract, `inner`, `middle` and `outer`, and call `call_outer` on `outer` with `inner` and `middle` and some integer as arguments.
+
+If we were using just `cargo-contract` or some other tooling, we would be able to see only the final result of the call.
+However, it wouldn't be possible to trace the intermediate steps.
+With `drink`, we can provide handlers for (synchronous) observing every level of the call stack.
+
+## Running
+
+```bash
+cargo contract build --release
+cargo test --release -- --show-output
+```
+
+You should be able to see similar output:
+```
+Contract at address `5CmHh6aBH6YZLjHGHjVtDDU4PfvDvk9s8n5xAcZQajxikksr` has been called with data: 
+    new
+and returned:
+    ()
+
+Contract at address `5FNvS4rLX8Y5NotoRzyBpmeNq2cfcSRpBWbHvgNrEiY3ero7` has been called with data: 
+    new
+and returned:
+    ()
+
+Contract at address `5DhNNsxhPMhg8R7StY3LbHraQWTDRFEbK2C1CaAD2AGvDCAf` has been called with data: 
+    new
+and returned:
+    ()
+
+Contract at address `5DhNNsxhPMhg8R7StY3LbHraQWTDRFEbK2C1CaAD2AGvDCAf` has been called with data: 
+    inner_call { arg: 7 }
+and returned:
+    Ok(22)
+
+Contract at address `5FNvS4rLX8Y5NotoRzyBpmeNq2cfcSRpBWbHvgNrEiY3ero7` has been called with data: 
+    middle_call { next_callee: 5DhNNsxhPMhg8R7StY3LbHraQWTDRFEbK2C1CaAD2AGvDCAf, arg: 7 }
+and returned:
+    Ok(22)
+
+Contract at address `5CmHh6aBH6YZLjHGHjVtDDU4PfvDvk9s8n5xAcZQajxikksr` has been called with data: 
+    outer_call { next_callee: 5FNvS4rLX8Y5NotoRzyBpmeNq2cfcSRpBWbHvgNrEiY3ero7, next_next_callee: 5DhNNsxhPMhg8R7StY3LbHraQWTDRFEbK2C1CaAD2AGvDCAf, arg: 7 }
+and returned:
+    Ok(22)
+
+
+successes:
+    tests::test
+```