From cb97d81b7cbface9c308e1e4eb220fd599e56a91 Mon Sep 17 00:00:00 2001 From: Nikolay Kurtov Date: Wed, 14 Sep 2022 15:18:47 +0200 Subject: [PATCH 1/3] Metrics for success of function calls and breakdown of the errors. --- Cargo.lock | 1 + runtime/near-vm-errors/Cargo.toml | 7 +- runtime/near-vm-errors/src/lib.rs | 50 +++++++++++-- runtime/runtime/src/actions.rs | 118 ++++++++++++++++++++---------- runtime/runtime/src/metrics.rs | 56 ++++++++++++++ 5 files changed, 184 insertions(+), 48 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 990424e62da..c3e07025502 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -3497,6 +3497,7 @@ dependencies = [ "near-account-id", "near-rpc-error-macro", "serde", + "strum", ] [[package]] diff --git a/runtime/near-vm-errors/Cargo.toml b/runtime/near-vm-errors/Cargo.toml index 3a8058073df..971a9cc5537 100644 --- a/runtime/near-vm-errors/Cargo.toml +++ b/runtime/near-vm-errors/Cargo.toml @@ -15,12 +15,13 @@ Error that can occur inside Near Runtime encapsulated in a separate crate. Might """ [dependencies] -serde = { version = "1", features = ["derive"] } +near-account-id = { path = "../../core/account-id" } +near-rpc-error-macro = { path = "../../tools/rpctypegen/macro" } borsh = "0.9" deepsize = { version = "0.2.0", optional = true } -near-account-id = { path = "../../core/account-id" } -near-rpc-error-macro = { path = "../../tools/rpctypegen/macro" } +serde = { version = "1", features = ["derive"] } +strum = { version = "0.24", features = ["derive"] } [features] dump_errors_schema = ["near-rpc-error-macro/dump_errors_schema"] diff --git a/runtime/near-vm-errors/src/lib.rs b/runtime/near-vm-errors/src/lib.rs index 76814b4c24f..6b7cb44c26b 100644 --- a/runtime/near-vm-errors/src/lib.rs +++ b/runtime/near-vm-errors/src/lib.rs @@ -7,7 +7,7 @@ use serde::{Deserialize, Serialize}; use std::any::Any; use std::fmt::{self, Error, Formatter}; -#[derive(Debug, PartialEq, Eq)] +#[derive(Debug, PartialEq, Eq, strum::IntoStaticStr)] pub enum VMError { FunctionCallError(FunctionCallError), /// Type erased error from `External` trait implementation. @@ -19,7 +19,7 @@ pub enum VMError { CacheError(CacheError), } -#[derive(Debug, PartialEq, Eq)] +#[derive(Debug, PartialEq, Eq, strum::IntoStaticStr)] pub enum FunctionCallError { /// Wasm compilation error CompilationError(CompilationError), @@ -67,7 +67,7 @@ pub enum FunctionCallErrorSer { ExecutionError(String), } -#[derive(Debug, PartialEq, Eq)] +#[derive(Debug, PartialEq, Eq, strum::IntoStaticStr)] pub enum CacheError { ReadError, WriteError, @@ -77,7 +77,16 @@ pub enum CacheError { /// A kind of a trap happened during execution of a binary #[cfg_attr(feature = "deepsize_feature", derive(deepsize::DeepSizeOf))] #[derive( - Debug, Clone, PartialEq, Eq, BorshDeserialize, BorshSerialize, Deserialize, Serialize, RpcError, + Debug, + Clone, + PartialEq, + Eq, + BorshDeserialize, + BorshSerialize, + Deserialize, + Serialize, + RpcError, + strum::IntoStaticStr, )] pub enum WasmTrap { /// An `unreachable` opcode was executed. @@ -102,7 +111,16 @@ pub enum WasmTrap { #[cfg_attr(feature = "deepsize_feature", derive(deepsize::DeepSizeOf))] #[derive( - Debug, Clone, PartialEq, Eq, BorshDeserialize, BorshSerialize, Deserialize, Serialize, RpcError, + Debug, + Clone, + PartialEq, + Eq, + BorshDeserialize, + BorshSerialize, + Deserialize, + Serialize, + RpcError, + strum::IntoStaticStr, )] pub enum MethodResolveError { MethodEmptyName, @@ -112,7 +130,16 @@ pub enum MethodResolveError { #[cfg_attr(feature = "deepsize_feature", derive(deepsize::DeepSizeOf))] #[derive( - Debug, Clone, PartialEq, Eq, BorshDeserialize, BorshSerialize, Deserialize, Serialize, RpcError, + Debug, + Clone, + PartialEq, + Eq, + BorshDeserialize, + BorshSerialize, + Deserialize, + Serialize, + RpcError, + strum::IntoStaticStr, )] pub enum CompilationError { CodeDoesNotExist { account_id: AccountId }, @@ -156,7 +183,16 @@ pub enum PrepareError { #[cfg_attr(feature = "deepsize_feature", derive(deepsize::DeepSizeOf))] #[derive( - Debug, Clone, PartialEq, Eq, BorshDeserialize, BorshSerialize, Deserialize, Serialize, RpcError, + Debug, + Clone, + PartialEq, + Eq, + BorshDeserialize, + BorshSerialize, + Deserialize, + Serialize, + RpcError, + strum::IntoStaticStr, )] pub enum HostError { /// String encoding is bad UTF-16 sequence diff --git a/runtime/runtime/src/actions.rs b/runtime/runtime/src/actions.rs index 85b23fef6b8..1d6ab244551 100644 --- a/runtime/runtime/src/actions.rs +++ b/runtime/runtime/src/actions.rs @@ -1,6 +1,6 @@ use crate::config::{safe_add_gas, RuntimeConfig}; use crate::ext::{ExternalError, RuntimeExt}; -use crate::{ActionResult, ApplyState}; +use crate::{metrics, ActionResult, ApplyState}; use borsh::{BorshDeserialize, BorshSerialize}; use near_crypto::PublicKey; use near_primitives::account::{AccessKey, AccessKeyPermission, Account}; @@ -168,45 +168,85 @@ pub(crate) fn action_function_call( None, ) .outcome_error(); + + match &err { + None => { + metrics::FUNCTION_CALL_PROCESSED.with_label_values(&["ok"]).inc(); + } + Some(err) => { + let err_type: &'static str = err.into(); + metrics::FUNCTION_CALL_PROCESSED.with_label_values(&[err_type]).inc(); + } + } + let execution_succeeded = match err { - Some(VMError::FunctionCallError(err)) => match err { - FunctionCallError::Nondeterministic(msg) => { - panic!("Contract runner returned non-deterministic error '{}', aborting", msg) - } - FunctionCallError::WasmUnknownError { debug_message } => { - panic!("Wasmer returned unknown message: {}", debug_message) - } - FunctionCallError::CompilationError(err) => { - result.result = Err(ActionErrorKind::FunctionCallError( - ContractCallError::CompilationError(err).into(), - ) - .into()); - false - } - FunctionCallError::LinkError { msg } => { - result.result = Err(ActionErrorKind::FunctionCallError( - ContractCallError::ExecutionError { msg: format!("Link Error: {}", msg) } - .into(), - ) - .into()); - false - } - FunctionCallError::MethodResolveError(err) => { - result.result = Err(ActionErrorKind::FunctionCallError( - ContractCallError::MethodResolveError(err).into(), - ) - .into()); - false - } - FunctionCallError::WasmTrap(_) | FunctionCallError::HostError(_) => { - result.result = Err(ActionErrorKind::FunctionCallError( - ContractCallError::ExecutionError { msg: err.to_string() }.into(), - ) - .into()); - false + Some(VMError::FunctionCallError(err)) => { + let err_type: &'static str = (&err).into(); + metrics::FUNCTION_CALL_PROCESSED_FUNCTION_CALL_ERRORS + .with_label_values(&[err_type]) + .inc(); + match err { + FunctionCallError::Nondeterministic(msg) => { + panic!("Contract runner returned non-deterministic error '{}', aborting", msg) + } + FunctionCallError::WasmUnknownError { debug_message } => { + panic!("Wasmer returned unknown message: {}", debug_message) + } + FunctionCallError::CompilationError(err) => { + let err_type: &'static str = (&err).into(); + metrics::FUNCTION_CALL_PROCESSED_COMPILATION_ERRORS + .with_label_values(&[err_type]) + .inc(); + result.result = Err(ActionErrorKind::FunctionCallError( + ContractCallError::CompilationError(err).into(), + ) + .into()); + false + } + FunctionCallError::LinkError { msg } => { + result.result = Err(ActionErrorKind::FunctionCallError( + ContractCallError::ExecutionError { msg: format!("Link Error: {}", msg) } + .into(), + ) + .into()); + false + } + FunctionCallError::MethodResolveError(err) => { + let err_type: &'static str = (&err).into(); + metrics::FUNCTION_CALL_PROCESSED_METHOD_RESOLVE_ERRORS + .with_label_values(&[err_type]) + .inc(); + result.result = Err(ActionErrorKind::FunctionCallError( + ContractCallError::MethodResolveError(err).into(), + ) + .into()); + false + } + FunctionCallError::WasmTrap(err) => { + let err_type: &'static str = (&err).into(); + metrics::FUNCTION_CALL_PROCESSED_WASM_TRAP_ERRORS + .with_label_values(&[err_type]) + .inc(); + result.result = Err(ActionErrorKind::FunctionCallError( + ContractCallError::ExecutionError { msg: err.to_string() }.into(), + ) + .into()); + false + } + FunctionCallError::HostError(err) => { + let err_type: &'static str = (&err).into(); + metrics::FUNCTION_CALL_PROCESSED_HOST_ERRORS + .with_label_values(&[err_type]) + .inc(); + result.result = Err(ActionErrorKind::FunctionCallError( + ContractCallError::ExecutionError { msg: err.to_string() }.into(), + ) + .into()); + false + } + FunctionCallError::_EVMError => unreachable!(), } - FunctionCallError::_EVMError => unreachable!(), - }, + } Some(VMError::ExternalError(any_err)) => { let err: ExternalError = any_err.downcast().expect("Downcasting AnyError should not fail"); @@ -219,6 +259,8 @@ pub(crate) fn action_function_call( return Err(StorageError::StorageInconsistentState(err.to_string()).into()); } Some(VMError::CacheError(err)) => { + let err_type: &'static str = (&err).into(); + metrics::FUNCTION_CALL_PROCESSED_CACHE_ERRORS.with_label_values(&[err_type]).inc(); let message = match err { CacheError::DeserializationError => "Cache deserialization error", CacheError::SerializationError { hash: _hash } => "Cache serialization error", diff --git a/runtime/runtime/src/metrics.rs b/runtime/runtime/src/metrics.rs index 506187b56b0..555a0b2f3f5 100644 --- a/runtime/runtime/src/metrics.rs +++ b/runtime/runtime/src/metrics.rs @@ -33,3 +33,59 @@ pub static TRANSACTION_PROCESSED_FAILED_TOTAL: Lazy = Lazy::new(|| { ) .unwrap() }); +pub static FUNCTION_CALL_PROCESSED: Lazy = Lazy::new(|| { + try_create_int_counter_vec( + "near_function_call_processed", + "The number of function calls processed since starting this node", + &["result"], + ) + .unwrap() +}); +pub static FUNCTION_CALL_PROCESSED_FUNCTION_CALL_ERRORS: Lazy = Lazy::new(|| { + try_create_int_counter_vec( + "near_function_call_processed_function_call_errors", + "The number of function calls resulting in function call errors, since starting this node", + &["error_type"], + ) + .unwrap() +}); +pub static FUNCTION_CALL_PROCESSED_COMPILATION_ERRORS: Lazy = Lazy::new(|| { + try_create_int_counter_vec( + "near_function_call_processed_compilation_errors", + "The number of function calls resulting in compilation errors, since starting this node", + &["error_type"], + ) + .unwrap() +}); +pub static FUNCTION_CALL_PROCESSED_METHOD_RESOLVE_ERRORS: Lazy = Lazy::new(|| { + try_create_int_counter_vec( + "near_function_call_processed_method_resolve_errors", + "The number of function calls resulting in method resolve errors, since starting this node", + &["error_type"], + ) + .unwrap() +}); +pub static FUNCTION_CALL_PROCESSED_WASM_TRAP_ERRORS: Lazy = Lazy::new(|| { + try_create_int_counter_vec( + "near_function_call_processed_wasm_trap_errors", + "The number of function calls resulting in wasm trap errors, since starting this node", + &["error_type"], + ) + .unwrap() +}); +pub static FUNCTION_CALL_PROCESSED_HOST_ERRORS: Lazy = Lazy::new(|| { + try_create_int_counter_vec( + "near_function_call_processed_host_errors", + "The number of function calls resulting in host errors, since starting this node", + &["error_type"], + ) + .unwrap() +}); +pub static FUNCTION_CALL_PROCESSED_CACHE_ERRORS: Lazy = Lazy::new(|| { + try_create_int_counter_vec( + "near_function_call_processed_cache_errors", + "The number of function calls resulting in vm cache errors, since starting this node", + &["error_type"], + ) + .unwrap() +}); From 7b719d2ff54ba843f4920cefb8edf0b8f7054280 Mon Sep 17 00:00:00 2001 From: Nikolay Kurtov Date: Wed, 14 Sep 2022 15:30:40 +0200 Subject: [PATCH 2/3] . --- runtime/runtime/src/actions.rs | 25 +++++++++---------------- 1 file changed, 9 insertions(+), 16 deletions(-) diff --git a/runtime/runtime/src/actions.rs b/runtime/runtime/src/actions.rs index 1d6ab244551..01bf5123f85 100644 --- a/runtime/runtime/src/actions.rs +++ b/runtime/runtime/src/actions.rs @@ -174,16 +174,14 @@ pub(crate) fn action_function_call( metrics::FUNCTION_CALL_PROCESSED.with_label_values(&["ok"]).inc(); } Some(err) => { - let err_type: &'static str = err.into(); - metrics::FUNCTION_CALL_PROCESSED.with_label_values(&[err_type]).inc(); + metrics::FUNCTION_CALL_PROCESSED.with_label_values(&[err.into()]).inc(); } } let execution_succeeded = match err { Some(VMError::FunctionCallError(err)) => { - let err_type: &'static str = (&err).into(); metrics::FUNCTION_CALL_PROCESSED_FUNCTION_CALL_ERRORS - .with_label_values(&[err_type]) + .with_label_values(&[(&err).into()]) .inc(); match err { FunctionCallError::Nondeterministic(msg) => { @@ -193,9 +191,8 @@ pub(crate) fn action_function_call( panic!("Wasmer returned unknown message: {}", debug_message) } FunctionCallError::CompilationError(err) => { - let err_type: &'static str = (&err).into(); metrics::FUNCTION_CALL_PROCESSED_COMPILATION_ERRORS - .with_label_values(&[err_type]) + .with_label_values(&[(&err).into()]) .inc(); result.result = Err(ActionErrorKind::FunctionCallError( ContractCallError::CompilationError(err).into(), @@ -212,9 +209,8 @@ pub(crate) fn action_function_call( false } FunctionCallError::MethodResolveError(err) => { - let err_type: &'static str = (&err).into(); metrics::FUNCTION_CALL_PROCESSED_METHOD_RESOLVE_ERRORS - .with_label_values(&[err_type]) + .with_label_values(&[(&err).into()]) .inc(); result.result = Err(ActionErrorKind::FunctionCallError( ContractCallError::MethodResolveError(err).into(), @@ -222,10 +218,9 @@ pub(crate) fn action_function_call( .into()); false } - FunctionCallError::WasmTrap(err) => { - let err_type: &'static str = (&err).into(); + FunctionCallError::WasmTrap(ref inner_err) => { metrics::FUNCTION_CALL_PROCESSED_WASM_TRAP_ERRORS - .with_label_values(&[err_type]) + .with_label_values(&[inner_err.into()]) .inc(); result.result = Err(ActionErrorKind::FunctionCallError( ContractCallError::ExecutionError { msg: err.to_string() }.into(), @@ -233,10 +228,9 @@ pub(crate) fn action_function_call( .into()); false } - FunctionCallError::HostError(err) => { - let err_type: &'static str = (&err).into(); + FunctionCallError::HostError(ref inner_err) => { metrics::FUNCTION_CALL_PROCESSED_HOST_ERRORS - .with_label_values(&[err_type]) + .with_label_values(&[inner_err.into()]) .inc(); result.result = Err(ActionErrorKind::FunctionCallError( ContractCallError::ExecutionError { msg: err.to_string() }.into(), @@ -259,8 +253,7 @@ pub(crate) fn action_function_call( return Err(StorageError::StorageInconsistentState(err.to_string()).into()); } Some(VMError::CacheError(err)) => { - let err_type: &'static str = (&err).into(); - metrics::FUNCTION_CALL_PROCESSED_CACHE_ERRORS.with_label_values(&[err_type]).inc(); + metrics::FUNCTION_CALL_PROCESSED_CACHE_ERRORS.with_label_values(&[(&err).into()]).inc(); let message = match err { CacheError::DeserializationError => "Cache deserialization error", CacheError::SerializationError { hash: _hash } => "Cache serialization error", From 23c7ac1409964544ad650c8cd2a22de55051987c Mon Sep 17 00:00:00 2001 From: Nikolay Kurtov Date: Thu, 15 Sep 2022 13:22:54 +0200 Subject: [PATCH 3/3] . --- runtime/runtime/src/metrics.rs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/runtime/runtime/src/metrics.rs b/runtime/runtime/src/metrics.rs index 555a0b2f3f5..854e558b47b 100644 --- a/runtime/runtime/src/metrics.rs +++ b/runtime/runtime/src/metrics.rs @@ -84,7 +84,7 @@ pub static FUNCTION_CALL_PROCESSED_HOST_ERRORS: Lazy = Lazy::new( pub static FUNCTION_CALL_PROCESSED_CACHE_ERRORS: Lazy = Lazy::new(|| { try_create_int_counter_vec( "near_function_call_processed_cache_errors", - "The number of function calls resulting in vm cache errors, since starting this node", + "The number of function calls resulting in VM cache errors, since starting this node", &["error_type"], ) .unwrap()