executor: log host alloc/dealloc

substrate/client/executor/common/Cargo.toml

@@ -18,6 +18,7 @@ targets = ["x86_64-unknown-linux-gnu"]
 
 [dependencies]
 polkavm = { workspace = true }
+sp-crypto-hashing = { workspace = true }
 sc-allocator = { workspace = true, default-features = true }
 sp-maybe-compressed-blob = { workspace = true, default-features = true }
 sp-wasm-interface = { workspace = true, default-features = true }

substrate/client/executor/common/src/runtime_blob/runtime_blob.rs

@@ -25,7 +25,12 @@ use wasm_instrument::parity_wasm::elements::{
 
 /// A program blob containing a Substrate runtime.
 #[derive(Clone)]
-pub struct RuntimeBlob(BlobKind);
+pub struct RuntimeBlob {
+	// Note that the hash can be different than the hash of the blob if the runtime code is
+	// compressed.
+	runtime_code_hash: Option<Vec<u8>>,
+	blob_kind: BlobKind,
+}
 
 #[derive(Clone)]
 enum BlobKind {
@@ -39,9 +44,10 @@ impl RuntimeBlob {
 	/// See [`sp_maybe_compressed_blob`] for details about decompression.
 	pub fn uncompress_if_needed(wasm_code: &[u8]) -> Result<Self, WasmError> {
 		use sp_maybe_compressed_blob::CODE_BLOB_BOMB_LIMIT;
+		let runtime_code_hash = sp_crypto_hashing::blake2_256(wasm_code);
 		let wasm_code = sp_maybe_compressed_blob::decompress(wasm_code, CODE_BLOB_BOMB_LIMIT)
 			.map_err(|e| WasmError::Other(format!("Decompression error: {:?}", e)))?;
-		Self::new(&wasm_code)
+		Self::new_with_runtime_code_hash(&wasm_code, Some(runtime_code_hash.to_vec()))
 	}
 
 	/// Create `RuntimeBlob` from the given WASM or PolkaVM program blob.
@@ -51,19 +57,28 @@ impl RuntimeBlob {
 	/// Will only accept a PolkaVM program if the `SUBSTRATE_ENABLE_POLKAVM` environment
 	/// variable is set to `1`.
 	pub fn new(raw_blob: &[u8]) -> Result<Self, WasmError> {
+		Self::new_with_runtime_code_hash(raw_blob, None)
+	}
+
+	/// Create `RuntimeBlob` from the given WASM or PolkaVM program blob,
+	/// but initialize the runtime code hash too.
+	fn new_with_runtime_code_hash(
+		raw_blob: &[u8],
+		runtime_code_hash: Option<Vec<u8>>,
+	) -> Result<Self, WasmError> {
 		if raw_blob.starts_with(b"PVM\0") {
 			if crate::is_polkavm_enabled() {
 				let raw = ArcBytes::from(raw_blob);
 				let blob = polkavm::ProgramBlob::parse(raw.clone())?;
-				return Ok(Self(BlobKind::PolkaVM((blob, raw))));
+				return Ok(Self { blob_kind: BlobKind::PolkaVM((blob, raw)), runtime_code_hash });
 			} else {
 				return Err(WasmError::Other("expected a WASM runtime blob, found a PolkaVM runtime blob; set the 'SUBSTRATE_ENABLE_POLKAVM' environment variable to enable the experimental PolkaVM-based executor".to_string()));
 			}
 		}
 
 		let raw_module: Module = deserialize_buffer(raw_blob)
 			.map_err(|e| WasmError::Other(format!("cannot deserialize module: {:?}", e)))?;
-		Ok(Self(BlobKind::WebAssembly(raw_module)))
+		Ok(Self { blob_kind: BlobKind::WebAssembly(raw_module), runtime_code_hash })
 	}
 
 	/// Run a pass that instrument this module so as to introduce a deterministic stack height
@@ -79,13 +94,14 @@ impl RuntimeBlob {
 	///
 	/// Only valid for WASM programs; will return an error if the blob is a PolkaVM program.
 	pub fn inject_stack_depth_metering(self, stack_depth_limit: u32) -> Result<Self, WasmError> {
+		let runtime_code_hash = self.runtime_code_hash.clone();
 		let injected_module =
 			wasm_instrument::inject_stack_limiter(self.into_webassembly_blob()?, stack_depth_limit)
 				.map_err(|e| {
 					WasmError::Other(format!("cannot inject the stack limiter: {:?}", e))
 				})?;
 
-		Ok(Self(BlobKind::WebAssembly(injected_module)))
+		Ok(Self { blob_kind: BlobKind::WebAssembly(injected_module), runtime_code_hash })
 	}
 
 	/// Converts a WASM memory import into a memory section and exports it.
@@ -190,15 +206,15 @@ impl RuntimeBlob {
 
 	/// Consumes this runtime blob and serializes it.
 	pub fn serialize(self) -> Vec<u8> {
-		match self.0 {
+		match self.blob_kind {
 			BlobKind::WebAssembly(raw_module) =>
 				serialize(raw_module).expect("serializing into a vec should succeed; qed"),
 			BlobKind::PolkaVM(ref blob) => blob.1.to_vec(),
 		}
 	}
 
 	fn as_webassembly_blob(&self) -> Result<&Module, WasmError> {
-		match self.0 {
+		match self.blob_kind {
 			BlobKind::WebAssembly(ref raw_module) => Ok(raw_module),
 			BlobKind::PolkaVM(..) => Err(WasmError::Other(
 				"expected a WebAssembly program; found a PolkaVM program blob".into(),
@@ -207,7 +223,7 @@ impl RuntimeBlob {
 	}
 
 	fn as_webassembly_blob_mut(&mut self) -> Result<&mut Module, WasmError> {
-		match self.0 {
+		match self.blob_kind {
 			BlobKind::WebAssembly(ref mut raw_module) => Ok(raw_module),
 			BlobKind::PolkaVM(..) => Err(WasmError::Other(
 				"expected a WebAssembly program; found a PolkaVM program blob".into(),
@@ -216,7 +232,7 @@ impl RuntimeBlob {
 	}
 
 	fn into_webassembly_blob(self) -> Result<Module, WasmError> {
-		match self.0 {
+		match self.blob_kind {
 			BlobKind::WebAssembly(raw_module) => Ok(raw_module),
 			BlobKind::PolkaVM(..) => Err(WasmError::Other(
 				"expected a WebAssembly program; found a PolkaVM program blob".into(),
@@ -226,9 +242,17 @@ impl RuntimeBlob {
 
 	/// Gets a reference to the inner PolkaVM program blob, if this is a PolkaVM program.
 	pub fn as_polkavm_blob(&self) -> Option<&polkavm::ProgramBlob> {
-		match self.0 {
+		match self.blob_kind {
 			BlobKind::WebAssembly(..) => None,
 			BlobKind::PolkaVM((ref blob, _)) => Some(blob),
 		}
 	}
+
+	/// Return the runtime code hash associated to the blob.
+	///
+	/// Note: the runtime code hash can be different from the blob
+	/// hash if the blob was built via `uncompress_if_needed`.
+	pub fn runtime_code_hash(&self) -> Option<&Vec<u8>> {
+		self.runtime_code_hash.as_ref()
+	}
 }

substrate/client/executor/wasmtime/src/host.rs

@@ -19,6 +19,8 @@
 //! This module defines `HostState` and `HostContext` structs which provide logic and state
 //! required for execution of host.
 
+use std::sync::atomic::{AtomicU64, Ordering};
+
 use wasmtime::Caller;
 
 use sc_allocator::{AllocationStats, FreeingBumpHeapAllocator};
@@ -37,12 +39,25 @@ pub struct HostState {
 	/// once.
 	allocator: Option<FreeingBumpHeapAllocator>,
 	panic_message: Option<String>,
+	instance_id: u64,
+	runtime_code_hash: Option<Vec<u8>>,
+	allocator_call_id: AtomicU64,
 }
 
 impl HostState {
 	/// Constructs a new `HostState`.
-	pub fn new(allocator: FreeingBumpHeapAllocator) -> Self {
-		HostState { allocator: Some(allocator), panic_message: None }
+	pub fn new(
+		allocator: FreeingBumpHeapAllocator,
+		instance_id: u64,
+		runtime_code_hash: Option<Vec<u8>>,
+	) -> Self {
+		HostState {
+			allocator: Some(allocator),
+			panic_message: None,
+			instance_id,
+			runtime_code_hash,
+			allocator_call_id: AtomicU64::new(1),
+		}
 	}
 
 	/// Takes the error message out of the host state, leaving a `None` in its place.
@@ -55,6 +70,11 @@ impl HostState {
 			.expect("Allocator is always set and only unavailable when doing an allocation/deallocation; qed")
 			.stats()
 	}
+
+	/// Increment the call id atomically and return the previous value before incrementing.
+	pub(crate) fn increment_call_id(&mut self) -> u64 {
+		self.allocator_call_id.fetch_add(1, Ordering::Relaxed)
+	}
 }
 
 /// A `HostContext` implements `FunctionContext` for making host calls from a Wasmtime
@@ -97,10 +117,18 @@ impl<'a> sp_wasm_interface::FunctionContext for HostContext<'a> {
 		// We can not return on error early, as we need to store back allocator.
 		let res = allocator
 			.allocate(&mut MemoryWrapper(&memory, &mut self.caller), size)
+			.inspect(|ptr| {
+				let instance_id = self.host_state_mut().instance_id;
+				let runtime_code_hash = self.host_state_mut().runtime_code_hash.clone();
+				let call_id = self.host_state_mut().increment_call_id();
+				runtime_code_hash.inspect(|code_hash| {
+					let display_ptr = u64::from(*ptr);
+					log::debug!(target: "runtime_host_allocator", "allocation: code_hash={code_hash:x?}, instance_id={instance_id}, call_id={call_id} size={size}, ptr=0x{display_ptr:x?}")
+				});
+			})
 			.map_err(|e| e.to_string());
 
 		self.host_state_mut().allocator = Some(allocator);
-
 		res
 	}
 
@@ -115,10 +143,18 @@ impl<'a> sp_wasm_interface::FunctionContext for HostContext<'a> {
 		// We can not return on error early, as we need to store back allocator.
 		let res = allocator
 			.deallocate(&mut MemoryWrapper(&memory, &mut self.caller), ptr)
+			.inspect(|_| {
+				let instance_id = self.host_state_mut().instance_id;
+				let runtime_code_hash = self.host_state_mut().runtime_code_hash.clone();
+				let call_id = self.host_state_mut().increment_call_id();
+				runtime_code_hash.inspect(|code_hash| {
+					let display_ptr = u64::from(ptr);
+					log::debug!(target: "runtime_host_allocator", "deallocation: code_hash={code_hash:x?}, instance_id={instance_id}, call_id={call_id} ptr=0x{display_ptr:x?}");
+				});
+			})
 			.map_err(|e| e.to_string());
 
 		self.host_state_mut().allocator = Some(allocator);
-
 		res
 	}
 

substrate/client/executor/wasmtime/src/instance_wrapper.rs

@@ -118,7 +118,7 @@ pub struct InstanceWrapper {
 	// NOTE: We want to decrement the instance counter *after* the store has been dropped
 	// to avoid a potential race condition, so this field must always be kept
 	// as the last field in the struct!
-	_release_instance_handle: ReleaseInstanceHandle,
+	release_instance_handle: ReleaseInstanceHandle,
 }
 
 impl InstanceWrapper {
@@ -127,7 +127,7 @@ impl InstanceWrapper {
 		instance_pre: &InstancePre<StoreData>,
 		instance_counter: Arc<InstanceCounter>,
 	) -> Result<Self> {
-		let _release_instance_handle = instance_counter.acquire_instance();
+		let release_instance_handle = instance_counter.acquire_instance();
 		let mut store = Store::new(engine, Default::default());
 		let instance = instance_pre.instantiate(&mut store).map_err(|error| {
 			WasmError::Other(format!(
@@ -140,7 +140,7 @@ impl InstanceWrapper {
 
 		store.data_mut().memory = Some(memory);
 
-		Ok(InstanceWrapper { instance, store, _release_instance_handle })
+		Ok(InstanceWrapper { instance, store, release_instance_handle })
 	}
 
 	/// Resolves a substrate entrypoint by the given name.
@@ -181,6 +181,18 @@ impl InstanceWrapper {
 
 		Ok(heap_base as u32)
 	}
+
+	/// Return the runtime code hash of the underlying instance.
+	///
+	/// Note: the runtime code hash might correspond to a compressed runtime.
+	pub fn runtime_code_hash(&self) -> Option<&Vec<u8>> {
+		self.release_instance_handle.runtime_code_hash()
+	}
+
+	/// Return the instance id.
+	pub fn id(&self) -> u64 {
+		self.release_instance_handle.id()
+	}
 }
 
 /// Extract linear memory instance from the given instance.