From d7ec1f3f3ad0986fe7718198e599149fcf5cc9f4 Mon Sep 17 00:00:00 2001 From: Bowen Wang Date: Fri, 22 Oct 2021 05:46:10 -0700 Subject: [PATCH] Revert "feat(runtime): debug print in host function call (#5018)" (#5062) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit This reverts commit f6fb5651088154c7b5e22ada51c72faf0c24299f. #5018 caused too many logs on entering `gas` host function due to how our gas metering works and it slows down neard significantly ``` Oct 21 22:48:11 mainnet-canary0 sh[748906]: Oct 21 22:48:11.557 DEBUG Process block{#50773946}:process_state_update:Runtime::apply:Runtime::process_receipt:run_vm{vm_kind=Wasmer0}:run_wasmer:run_method:run_method/call:gas: host-function: close time.busy=5.97µs time.idle=631ns Oct 21 22:48:11 mainnet-canary0 sh[748906]: Oct 21 22:48:11.557 DEBUG Process block{#50773946}:process_state_update:Runtime::apply:Runtime::process_receipt:run_vm{vm_kind=Wasmer0}:run_wasmer:run_method:run_method/call:gas: host-function: enter Oct 21 22:48:11 mainnet-canary0 sh[748906]: Oct 21 22:48:11.557 DEBUG Process block{#50773946}:process_state_update:Runtime::apply:Runtime::process_receipt:run_vm{vm_kind=Wasmer0}:run_wasmer:run_method:run_method/call:gas: host-function: close time.busy=6.36µs time.idle=593ns Oct 21 22:48:11 mainnet-canary0 sh[748906]: Oct 21 22:48:11.557 DEBUG Process block{#50773946}:process_state_update:Runtime::apply:Runtime::process_receipt:run_vm{vm_kind=Wasmer0}:run_wasmer:run_method:run_method/call:gas: host-function: enter Oct 21 22:48:11 mainnet-canary0 sh[748906]: Oct 21 22:48:11.557 DEBUG Process block{#50773946}:process_state_update:Runtime::apply:Runtime::process_receipt:run_vm{vm_kind=Wasmer0}:run_wasmer:run_method:run_method/call:gas: host-function: close time.busy=5.29µs time.idle=507ns Oct 21 22:48:11 mainnet-canary0 sh[748906]: Oct 21 22:48:11.561 DEBUG Process block{#50773946}:process_state_update:Runtime::apply:Runtime::process_receipt:run_vm{vm_kind=Wasmer0}:run_wasmer:run_method:run_method/call:gas: host-function: enter Oct 21 22:48:11 mainnet-canary0 sh[748906]: Oct 21 22:48:11.561 DEBUG Process block{#50773946}:process_state_update:Runtime::apply:Runtime::process_receipt:run_vm{vm_kind=Wasmer0}:run_wasmer:run_method:run_method/call:gas: host-function: close time.busy=101µs time.idle=1.70µs Oct 21 22:48:11 mainnet-canary0 sh[748906]: Oct 21 22:48:11.561 DEBUG Process block{#50773946}:process_state_update:Runtime::apply:Runtime::process_receipt:run_vm{vm_kind=Wasmer0}:run_wasmer:run_method:run_method/call:gas: host-function: enter Oct 21 22:48:11 mainnet-canary0 sh[748906]: Oct 21 22:48:11.561 DEBUG Process block{#50773946}:process_state_update:Runtime::apply:Runtime::process_receipt:run_vm{vm_kind=Wasmer0}:run_wasmer:run_method:run_method/call:gas: host-function: close time.busy=6.33µs time.idle=735ns Oct 21 22:48:11 mainnet-canary0 sh[748906]: Oct 21 22:48:11.561 DEBUG Process block{#50773946}:process_state_update:Runtime::apply:Runtime::process_receipt:run_vm{vm_kind=Wasmer0}:run_wasmer:run_method:run_method/call:gas: host-function: enter ``` even when there is very little load ``` Oct 21 22:48:41 mainnet-canary0 sh[748906]: Oct 21 22:48:41.724 INFO stats: #50773947 Downloading blocks 99.99% (3248) 13/13/40 peers ⬇ 62.0kiB/s ⬆ 10.6kiB/s 0.05 bps 1.26 Tgas/s CPU: 32%, Mem: 808.2 MiB Oct 21 22:48:56 mainnet-canary0 sh[748906]: Oct 21 22:48:56.188 INFO stats: #50773948 Downloading blocks 99.99% (3290) 13/13/40 peers ⬇ 65.8kiB/s ⬆ 11.0kiB/s 0.07 bps 859.43 Ggas/s CPU: 32%, Mem: 811.6 MiB ``` This caused canary nodes to be broken --- runtime/near-vm-runner/src/imports.rs | 3 --- 1 file changed, 3 deletions(-) diff --git a/runtime/near-vm-runner/src/imports.rs b/runtime/near-vm-runner/src/imports.rs index d6ecc9c3bc0..2afc3600189 100644 --- a/runtime/near-vm-runner/src/imports.rs +++ b/runtime/near-vm-runner/src/imports.rs @@ -46,7 +46,6 @@ macro_rules! wrapped_imports { #[allow(unused_parens)] $(#[cfg(feature = $feature_name)])* pub fn $func( ctx: &mut Ctx, $( $arg_name: $arg_type ),* ) -> VMResult<($( $returns ),*)> { - let _span = tracing::debug_span!(target: "host-function", stringify!($func)).entered(); let logic: &mut VMLogic<'_> = unsafe { &mut *(ctx.data as *mut VMLogic<'_>) }; logic.$func( $( $arg_name, )* ) } @@ -63,7 +62,6 @@ macro_rules! wrapped_imports { #[allow(unused_parens)] $(#[cfg(feature = $feature_name)])* pub fn $func(env: &NearWasmerEnv, $( $arg_name: $arg_type ),* ) -> VMResult<($( $returns ),*)> { - let _span = tracing::debug_span!(target: "host-function", stringify!($func)).entered(); let logic: &mut VMLogic = unsafe { &mut *(env.logic.0 as *mut VMLogic<'_>) }; logic.$func( $( $arg_name, )* ) } @@ -87,7 +85,6 @@ macro_rules! wrapped_imports { #[allow(unused_parens)] #[cfg(all(feature = "wasmtime_vm" $(, feature = $feature_name)*))] pub fn $func( $( $arg_name: rust2wasm!($arg_type) ),* ) -> VMResult<($( rust2wasm!($returns)),*)> { - let _span = tracing::debug_span!(target: "host-function", stringify!($func)).entered(); let data = CALLER_CONTEXT.with(|caller_context| { unsafe { *caller_context.get()