From deddbcc46f0507993fc5da0f66e82ffffa5f7730 Mon Sep 17 00:00:00 2001
From: Aleksey Kladov <aleksey.kladov@gmail.com>
Date: Tue, 9 Mar 2021 12:47:03 +0300
Subject: [PATCH] feat: time wasmer deserialization costs

As that's where we spend the bulk of our time
---
 runtime/near-vm-runner/src/cache.rs         | 8 ++++++++
 runtime/near-vm-runner/src/wasmer_runner.rs | 6 +++++-
 2 files changed, 13 insertions(+), 1 deletion(-)

diff --git a/runtime/near-vm-runner/src/cache.rs b/runtime/near-vm-runner/src/cache.rs
index 6cbc1b77dc3..42b9dfa42e7 100644
--- a/runtime/near-vm-runner/src/cache.rs
+++ b/runtime/near-vm-runner/src/cache.rs
@@ -99,6 +99,8 @@ pub mod wasmer0_cache {
         key: &CryptoHash,
         cache: &dyn CompiledContractCache,
     ) -> Result<wasmer_runtime::Module, VMError> {
+        let _span = tracing::info_span!("compile_and_serialize_wasmer");
+
         let module = compile_module(wasm_code, config).map_err(|e| cache_error(e, &key, cache))?;
         let artifact = module
             .cache()
@@ -117,6 +119,8 @@ pub mod wasmer0_cache {
     fn deserialize_wasmer(
         serialized: &[u8],
     ) -> Result<Result<wasmer_runtime::Module, VMError>, CacheError> {
+        let _span = tracing::info_span!("deserialize_wasmer");
+
         let record = CacheRecord::try_from_slice(serialized).map_err(|_e| DeserializationError)?;
         let serialized_artifact = match record {
             CacheRecord::Error(err) => return Ok(Err(err)),
@@ -220,6 +224,8 @@ pub mod wasmer1_cache {
         cache: &dyn CompiledContractCache,
         store: &wasmer::Store,
     ) -> Result<wasmer::Module, VMError> {
+        let _span = tracing::info_span!("compile_and_serialize_wasmer1");
+
         let module = compile_module_wasmer1(wasm_code, config, store)
             .map_err(|e| cache_error(e, &key, cache))?;
         let code = module
@@ -234,6 +240,8 @@ pub mod wasmer1_cache {
         serialized: &[u8],
         store: &wasmer::Store,
     ) -> Result<Result<wasmer::Module, VMError>, CacheError> {
+        let _span = tracing::info_span!("deserialize_wasmer1");
+
         let record = CacheRecord::try_from_slice(serialized).map_err(|_e| DeserializationError)?;
         let serialized_module = match record {
             CacheRecord::Error(err) => return Ok(Err(err)),
diff --git a/runtime/near-vm-runner/src/wasmer_runner.rs b/runtime/near-vm-runner/src/wasmer_runner.rs
index 35f4c24bab2..845d3c926bf 100644
--- a/runtime/near-vm-runner/src/wasmer_runner.rs
+++ b/runtime/near-vm-runner/src/wasmer_runner.rs
@@ -246,7 +246,11 @@ pub fn run_wasmer<'a>(
         return (None, Some(e));
     }
 
-    match module.instantiate(&import_object) {
+    let instantiate = {
+        let _span = tracing::info_span!("run_wasmer/instantiate").entered();
+        module.instantiate(&import_object)
+    };
+    match instantiate {
         Ok(instance) => {
             let _span = tracing::info_span!("run_wasmer/call").entered();