Gas used and execution time measurement for the Move function

crates/rooch/Cargo.toml

@@ -73,7 +73,9 @@ moveos = { workspace = true }
 moveos-verifier = { workspace = true }
 moveos-object-runtime = { workspace = true }
 moveos-compiler = { workspace = true }
-moveos-config = { workspace = true }
+moveos-config ={ workspace = true }
+move-ir-types = { workspace = true }
+move-symbol-pool = { workspace = true }
 
 framework-builder = { workspace = true }
 framework-types = { workspace = true }
@@ -96,3 +98,6 @@ rooch-db = { workspace = true }
 rooch-common = { workspace = true }
 
 framework-release = { workspace = true }
+
+[features]
+execution_tracing = []

crates/rooch/src/commands/move_cli/commands/publish.rs

@@ -11,6 +11,8 @@ use moveos_types::{
     addresses::MOVEOS_STD_ADDRESS, move_types::FunctionId, transaction::MoveAction,
 };
 use moveos_verifier::build::run_verifier;
+#[cfg(feature = "execution_tracing")]
+use moveos_verifier::execution_measurement::compile_with_filter;
 use moveos_verifier::verifier;
 use rooch_key::key_derive::verify_password;
 use rooch_key::keystore::account_keystore::AccountKeystore;
@@ -20,6 +22,7 @@ use rooch_types::error::{RoochError, RoochResult};
 use rooch_types::transaction::rooch::RoochTransaction;
 use rpassword::prompt_password;
 use std::collections::BTreeMap;
+#[cfg(not(feature = "execution_tracing"))]
 use std::io::stderr;
 
 #[derive(Parser)]
@@ -49,6 +52,10 @@ pub struct Publish {
     /// For now, the option is kept for test only.
     #[clap(long)]
     pub by_move_action: bool,
+
+    /// Inject gas profiling codes to measure gas use
+    #[clap(long)]
+    pub gas_profile: bool,
 }
 
 #[async_trait]
@@ -71,7 +78,12 @@ impl CommandAction<ExecuteTransactionResponseView> for Publish {
         let config_cloned = config.clone();
 
         // Compile the package and run the verifier
+        #[cfg(feature = "execution_tracing")]
+        let mut package = compile_with_filter(&package_path, config_cloned.clone())?;
+
+        #[cfg(not(feature = "execution_tracing"))]
         let mut package = config.compile_package_no_exit(&package_path, &mut stderr())?;
+
         run_verifier(package_path, config_cloned, &mut package)?;
 
         // Get the modules from the package

examples/view_function_loop/Move.toml

@@ -7,6 +7,7 @@ MoveosStdlib = { local = "../../frameworks/moveos-stdlib" }
 
 [addresses]
 rooch_examples =  "_"
+moveos_std = "0x2"
 
 [dev-addresses]
 rooch_examples = "0x42"

frameworks/framework-builder/Cargo.toml

@@ -52,4 +52,7 @@ moveos-verifier = { workspace = true }
 moveos-stdlib = { workspace = true }
 moveos-compiler = { workspace = true }
 
-framework-types = { workspace = true }
+framework-types = { workspace = true }
+
+[features]
+execution_tracing = []

frameworks/framework-builder/src/lib.rs

@@ -10,12 +10,16 @@ use move_model::model::GlobalEnv;
 use move_package::{compilation::compiled_package::CompiledPackage, BuildConfig, ModelConfig};
 use moveos_compiler::dependency_order::sort_by_dependency_order;
 use moveos_verifier::build::run_verifier;
+#[cfg(feature = "execution_tracing")]
+use moveos_verifier::execution_measurement::compile_with_filter;
 use serde::{Deserialize, Serialize};
+#[cfg(not(feature = "execution_tracing"))]
+use std::io::stderr;
 use std::{
     collections::{HashMap, HashSet},
     env::current_dir,
     fs::{self, File},
-    io::{stderr, Write},
+    io::Write,
     path::{Path, PathBuf},
 };
 
@@ -90,6 +94,10 @@ impl StdlibBuildConfig {
         let project_path = self.path.clone();
         let project_path = reroot_path(Some(project_path))?;
 
+        #[cfg(feature = "execution_tracing")]
+        let mut compiled_package = compile_with_filter(&self.path, self.build_config.clone())?;
+
+        #[cfg(not(feature = "execution_tracing"))]
         let mut compiled_package = self
             .build_config
             .clone()

frameworks/framework-release/Cargo.toml

@@ -38,4 +38,7 @@ framework-builder = { workspace = true }
 [build-dependencies]
 tracing = { workspace = true }
 tracing-subscriber = { workspace = true }
-framework-builder = { workspace = true }
+framework-builder = { workspace = true }
+
+[features]
+execution_tracing = ["framework-builder/execution_tracing"]

frameworks/moveos-stdlib/Cargo.toml

@@ -59,3 +59,6 @@ moveos-object-runtime = { workspace = true }
 moveos-compiler = { workspace = true }
 
 smt = { workspace = true }
+
+[features]
+execution_tracing = []

frameworks/moveos-stdlib/doc/README.md

@@ -33,6 +33,7 @@ This is the reference documentation of the MoveOS standard library.
 -  [`0x2::hash`](hash.md#0x2_hash)
 -  [`0x2::hex`](hex.md#0x2_hex)
 -  [`0x2::json`](json.md#0x2_json)
+-  [`0x2::measurements`](measurements.md#0x2_measurements)
 -  [`0x2::module_store`](module_store.md#0x2_module_store)
 -  [`0x2::move_module`](move_module.md#0x2_move_module)
 -  [`0x2::object`](object.md#0x2_object)

frameworks/moveos-stdlib/doc/measurements.md

@@ -0,0 +1,22 @@
+
+<a name="0x2_measurements"></a>
+
+# Module `0x2::measurements`
+
+
+
+-  [Function `inject_parameter`](#0x2_measurements_inject_parameter)
+
+
+<pre><code></code></pre>
+
+
+
+<a name="0x2_measurements_inject_parameter"></a>
+
+## Function `inject_parameter`
+
+
+
+<pre><code><b>public</b> <b>fun</b> <a href="measurements.md#0x2_measurements_inject_parameter">inject_parameter</a>(arg1: u64, arg2: u64, arg3: <a href="">vector</a>&lt;u8&gt;): (u64, u64)
+</code></pre>

frameworks/moveos-stdlib/sources/measurements.move

@@ -0,0 +1,3 @@
+module moveos_std::measurements {
+    public native fun inject_parameter(arg1: u64, arg2: u64, arg3: vector<u8>): (u64, u64);
+}

frameworks/moveos-stdlib/src/natives/mod.rs

@@ -1,6 +1,7 @@
 // Copyright (c) RoochNetwork
 // SPDX-License-Identifier: Apache-2.0
 
+use crate::natives::moveos_stdlib::measurement::MeasurementGas;
 use move_core_types::gas_algebra::InternalGas;
 use move_vm_runtime::native_functions::{make_table_from_iter, NativeFunctionTable};
 use moveos_types::addresses::{MOVEOS_STD_ADDRESS, MOVE_STD_ADDRESS};
@@ -129,6 +130,10 @@ pub fn all_natives(gas_params: GasParameters) -> NativeFunctionTable {
         moveos_stdlib::bls12381::make_all(gas_params.bls12381)
     );
     add_natives!("evm", moveos_stdlib::evm::make_all(gas_params.evm));
+    add_natives!(
+        "measurements",
+        moveos_stdlib::measurement::make_all(MeasurementGas::zero())
+    );
 
     let moveos_native_fun_table = make_table_from_iter(MOVEOS_STD_ADDRESS, natives);
     native_fun_table.extend(moveos_native_fun_table);

frameworks/moveos-stdlib/src/natives/moveos_stdlib/measurement.rs

@@ -0,0 +1,134 @@
+// Copyright (c) RoochNetwork
+// SPDX-License-Identifier: Apache-2.0
+
+use crate::natives::helpers::{make_module_natives, make_native};
+use move_binary_format::errors::PartialVMResult;
+use move_core_types::gas_algebra::InternalGas;
+use move_vm_runtime::native_functions::{NativeContext, NativeFunction};
+use move_vm_types::loaded_data::runtime_types::Type;
+use move_vm_types::natives::function::NativeResult;
+use move_vm_types::pop_arg;
+use move_vm_types::values::Value;
+use moveos_verifier::execution_measurement::NativeExecutionTracing;
+use petgraph::matrix_graph::Zero;
+use smallvec::smallvec;
+use std::collections::VecDeque;
+use std::time::UNIX_EPOCH;
+
+#[derive(Debug, Clone)]
+pub struct MeasurementGas {
+    pub base: InternalGas,
+}
+
+impl MeasurementGas {
+    pub fn zero() -> Self {
+        Self { base: 0.into() }
+    }
+}
+
+fn inject_parameter(
+    _gas_params: &MeasurementGas,
+    context: &mut NativeContext,
+    _ty_args: Vec<Type>,
+    mut args: VecDeque<Value>,
+) -> PartialVMResult<NativeResult> {
+    use std::time::SystemTime;
+
+    let current_gas_balance = context.gas_balance();
+    let execution_tracing = context.extensions_mut().get_mut::<NativeExecutionTracing>();
+
+    let generate_print_space = |space_count: u64| -> String {
+        if space_count.is_zero() {
+            "".to_string()
+        } else {
+            "|  ".repeat(space_count as usize)
+        }
+    };
+
+    let start = SystemTime::now();
+    let since_the_epoch = start
+        .duration_since(UNIX_EPOCH)
+        .expect("Time went backwards");
+
+    let full_func_name_bytes = pop_arg!(args, Vec<u8>);
+    let full_func_name = String::from_utf8_lossy(full_func_name_bytes.as_slice()).to_string();
+    let timestamp = pop_arg!(args, u64);
+    let gas_balance = pop_arg!(args, u64);
+
+    let current_timestamp_millis = since_the_epoch.as_millis() as u64;
+    if timestamp > 0 {
+        let gas_used_p1 = InternalGas::from(gas_balance)
+            .checked_sub(current_gas_balance)
+            .unwrap();
+
+        if !gas_used_p1.is_zero() {
+            if gas_used_p1 > InternalGas::new(31892) {
+                if let Some(gas_used_p2) = gas_used_p1.checked_sub(31892.into()) {
+                    let time_used: u64 = current_timestamp_millis.saturating_sub(timestamp);
+                    execution_tracing.log.push(format!(
+                        "{}{}.gas_used: {:}, time_used {:?} -> {}, balance {:}",
+                        generate_print_space(execution_tracing.calling_depth),
+                        execution_tracing.calling_depth,
+                        gas_used_p2,
+                        time_used,
+                        full_func_name,
+                        current_gas_balance
+                    ));
+                }
+            } else {
+                let time_used: u64 = current_timestamp_millis.saturating_sub(timestamp);
+                execution_tracing.log.push(format!(
+                    "{}{}.gas_used: {:}, time_used {:?} -> {}, balance {:}",
+                    generate_print_space(execution_tracing.calling_depth),
+                    execution_tracing.calling_depth,
+                    gas_used_p1,
+                    time_used,
+                    full_func_name,
+                    current_gas_balance
+                ));
+            }
+        } else {
+            execution_tracing.log.push(format!(
+                "{}{}.gas_used: {:}, time_used {:?} -> {}, balance {:}",
+                generate_print_space(execution_tracing.calling_depth),
+                execution_tracing.calling_depth,
+                0,
+                timestamp,
+                full_func_name,
+                current_gas_balance
+            ));
+        }
+
+        execution_tracing.calling_depth -= 1;
+
+        Ok(NativeResult::Success {
+            cost: InternalGas::zero(),
+            ret_vals: smallvec![Value::u64(0), Value::u64(0)],
+        })
+    } else {
+        execution_tracing.calling_depth += 1;
+        execution_tracing.log.push(format!(
+            "{}{}.call {:} balance {:}",
+            generate_print_space(execution_tracing.calling_depth),
+            execution_tracing.calling_depth,
+            full_func_name,
+            current_gas_balance
+        ));
+        Ok(NativeResult::Success {
+            cost: InternalGas::zero(),
+            ret_vals: smallvec![
+                Value::u64(current_gas_balance.into()),
+                Value::u64(current_timestamp_millis)
+            ],
+        })
+    }
+}
+
+pub fn make_all(gas_params: MeasurementGas) -> impl Iterator<Item = (String, NativeFunction)> {
+    let natives = [(
+        "inject_parameter",
+        make_native(gas_params, inject_parameter),
+    )];
+
+    make_module_natives(natives)
+}

frameworks/moveos-stdlib/src/natives/moveos_stdlib/mod.rs

@@ -11,6 +11,7 @@ pub mod event;
 pub mod evm;
 pub mod hash;
 pub mod json;
+pub mod measurement;
 pub mod move_module;
 pub mod object;
 pub mod rlp;

frameworks/moveos-stdlib/src/natives/moveos_stdlib/wasm.rs

@@ -863,7 +863,7 @@ pub fn make_all(gas_params: GasParameters) -> impl Iterator<Item = (String, Nati
         (
             "native_release_wasm_instance",
             make_native(
-                gas_params.release_wasm_instance,
+                gas_params.release_wasm_instance.clone(),
                 native_release_wasm_instance,
             ),
         ),

moveos/moveos-verifier/Cargo.toml

@@ -21,6 +21,7 @@ termcolor = { workspace = true }
 bcs = { workspace = true }
 thiserror = { workspace = true }
 itertools = { workspace = true }
+better_any = { workspace = true }
 
 move-core-types = { workspace = true }
 move-model = { workspace = true }